add a request id to the search and find request headers (#301)

add a request id to the search and find request headers

app/services/qa/linked_data/request_header_service.rb

@@ -2,7 +2,7 @@
 module Qa
   module LinkedData
     class RequestHeaderService
-      attr_reader :request, :params
+      attr_reader :request, :params, :request_id
 
       # @param request [HttpRequest] request from controller
       # @param params [Hash] attribute-value pairs holding the request parameters
@@ -16,13 +16,16 @@ class RequestHeaderService
       def initialize(request:, params:)
         @request = request
         @params = params
+        @request_id = assign_request_id
       end
 
       # Construct request parameters to pass to search_query (linked data module).
       # @returns [Hash] parsed out attribute-value pairs that are required for the search query
       # @see Qa::Authorities::LinkedData::SearchQuery
       def search_header
         header = {}
+        header[:request] = request
+        header[:request_id] = request_id
         header[:subauthority] = params.fetch(:subauthority, nil)
         header[:user_language] = user_language
         header[:performance_data] = performance_data?
@@ -37,6 +40,8 @@ def search_header
       # @see Qa::Authorities::LinkedData::FindTerm
       def fetch_header
         header = {}
+        header[:request] = request
+        header[:request_id] = request_id
         header[:subauthority] = params.fetch(:subauthority, nil)
         header[:user_language] = user_language
         header[:performance_data] = performance_data?
@@ -62,6 +67,11 @@ def content_type_for_format
 
       private
 
+        # assign request id
+        def assign_request_id
+          SecureRandom.uuid
+        end
+
         # filter literals in results to this language
         def user_language
           request_language = request.env['HTTP_ACCEPT_LANGUAGE']

lib/qa/authorities/linked_data/find_term.rb

@@ -15,8 +15,8 @@ def initialize(term_config)
         @term_config = term_config
       end
 
-      attr_reader :term_config, :full_graph, :filtered_graph, :language, :id, :uri, :access_time_s, :normalize_time_s, :subauthority, :request_header
-      private :full_graph, :filtered_graph, :language, :id, :uri, :access_time_s, :normalize_time_s, :subauthority, :request_header
+      attr_reader :term_config, :full_graph, :filtered_graph, :language, :id, :uri, :access_time_s, :normalize_time_s, :subauthority, :request_header, :request_id, :request
+      private :full_graph, :filtered_graph, :language, :id, :uri, :access_time_s, :normalize_time_s, :subauthority, :request_header, :request_id, :request
 
       delegate :term_subauthority?, :prefixes, :authority_name, to: :term_config
 
@@ -46,10 +46,10 @@ def initialize(term_config)
       def find(id, request_header: {}, language: nil, replacements: {}, subauth: nil, format: 'json', performance_data: false) # rubocop:disable Metrics/ParameterLists
         request_header = build_request_header(language: language, replacements: replacements, subauth: subauth, format: format, performance_data: performance_data) if request_header.empty?
         unpack_request_header(request_header)
-        raise Qa::InvalidLinkedDataAuthority, "Unable to initialize linked data term sub-authority #{subauthority}" unless subauthority.nil? || term_subauthority?(subauthority)
+        raise Qa::InvalidLinkedDataAuthority, "#{request_id} - Unable to initialize linked data term sub-authority #{subauthority}" unless subauthority.nil? || term_subauthority?(subauthority)
         @id = id
         url = authority_service.build_url(action_config: term_config, action: :term, action_request: normalize_id, request_header: request_header)
-        Rails.logger.info "QA Linked Data term url: #{url}"
+        Rails.logger.info "#{request_id} - QA Linked Data term url: #{url}"
         load_graph(url: url)
         normalize_results
       end
@@ -63,7 +63,7 @@ def load_graph(url:)
 
           access_end_dt = Time.now.utc
           @access_time_s = access_end_dt - access_start_dt
-          Rails.logger.info("Time to receive data from authority: #{access_time_s}s")
+          Rails.logger.info("#{request_id} - Time to receive data from authority: #{access_time_s}s")
         end
 
         def normalize_results
@@ -73,7 +73,7 @@ def normalize_results
 
           normalize_end_dt = Time.now.utc
           @normalize_time_s = normalize_end_dt - normalize_start_dt
-          Rails.logger.info("Time to normalize data: #{normalize_time_s}s")
+          Rails.logger.info("#{request_id} - Time to normalize data: #{normalize_time_s}s")
           results = append_data_outside_results(results)
           results
         end
@@ -92,6 +92,8 @@ def perform_normalization
 
         def unpack_request_header(request_header)
           @request_header = request_header
+          @request = request_header.fetch(:request, nil)
+          @request_id = request_header.fetch(:request_id, 'UNASSIGNED')
           @subauthority = request_header.fetch(:subauthority, nil)
           @format = request_header.fetch(:format, 'json')
           @performance_data = request_header.fetch(:performance_data, false)
@@ -314,6 +316,7 @@ def build_request_header(language:, replacements:, subauth:, format:, performanc
             )
           end
           request_header = {}
+          request_header[:request_id] = SecureRandom.uuid
           request_header[:replacements] = replacements || {}
           request_header[:subauthority] = subauth || nil
           request_header[:language] = language || nil

lib/qa/authorities/linked_data/search_query.rb

@@ -15,8 +15,8 @@ def initialize(search_config)
         @search_config = search_config
       end
 
-      attr_reader :search_config, :full_graph, :filtered_graph, :language, :access_time_s, :normalize_time_s, :subauthority, :request_header
-      private :full_graph, :filtered_graph, :language, :access_time_s, :normalize_time_s, :subauthority, :request_header
+      attr_reader :search_config, :full_graph, :filtered_graph, :language, :access_time_s, :normalize_time_s, :subauthority, :request_header, :request_id, :request
+      private :full_graph, :filtered_graph, :language, :access_time_s, :normalize_time_s, :subauthority, :request_header, :request_id, :request
 
       delegate :subauthority?, :supports_sort?, :prefixes, :authority_name, to: :search_config
 
@@ -37,9 +37,9 @@ def initialize(search_config)
       def search(query, request_header: {}, language: nil, replacements: {}, subauth: nil, context: false, performance_data: false) # rubocop:disable Metrics/ParameterLists
         request_header = build_request_header(language: language, replacements: replacements, subauth: subauth, context: context, performance_data: performance_data) if request_header.empty?
         unpack_request_header(request_header)
-        raise Qa::InvalidLinkedDataAuthority, "Unable to initialize linked data search sub-authority #{subauthority}" unless subauthority.nil? || subauthority?(subauthority)
+        raise Qa::InvalidLinkedDataAuthority, "#{request_id} - Unable to initialize linked data search sub-authority #{subauthority}" unless subauthority.nil? || subauthority?(subauthority)
         url = authority_service.build_url(action_config: search_config, action: :search, action_request: query, request_header: request_header)
-        Rails.logger.info "QA Linked Data search url: #{url}"
+        Rails.logger.info "#{request_id} - QA Linked Data search url: #{url}"
         load_graph(url: url)
         normalize_results
       end
@@ -53,7 +53,7 @@ def load_graph(url:)
 
           access_end_dt = Time.now.utc
           @access_time_s = access_end_dt - access_start_dt
-          Rails.logger.info("Time to receive data from authority: #{access_time_s}s")
+          Rails.logger.info("#{request_id} - Time to receive data from authority: #{access_time_s}s")
         end
 
         def normalize_results
@@ -65,7 +65,7 @@ def normalize_results
 
           normalize_end_dt = Time.now.utc
           @normalize_time_s = normalize_end_dt - normalize_start_dt
-          Rails.logger.info("Time to normalize data: #{normalize_time_s}s")
+          Rails.logger.info("#{request_id} - Time to normalize data: #{normalize_time_s}s")
           json = append_data_outside_results(json)
           json
         end
@@ -91,6 +91,8 @@ def map_results
 
         def unpack_request_header(request_header)
           @request_header = request_header
+          @request = request_header.fetch(:request, nil)
+          @request_id = request_header.fetch(:request_id, 'UNASSIGNED')
           @subauthority = request_header.fetch(:subauthority, nil)
           @context = request_header.fetch(:context, false)
           @performance_data = request_header.fetch(:performance_data, false)
@@ -211,6 +213,7 @@ def build_request_header(language:, replacements:, subauth:, context:, performan
             )
           end
           request_header = {}
+          request_header[:request_id] = SecureRandom.uuid
           request_header[:replacements] = replacements || {}
           request_header[:subauthority] = subauth || nil
           request_header[:language] = language || nil

spec/services/linked_data/request_header_service_spec.rb

@@ -2,8 +2,11 @@
 
 RSpec.describe Qa::LinkedData::RequestHeaderService do
   let(:request) { double }
+  before { allow(SecureRandom).to receive(:uuid).and_return(request_id) }
 
   describe '#search_header' do
+    let(:request_id) { 's1' }
+
     context 'when optional params are defined' do
       let(:search_params) do
         {
@@ -20,6 +23,8 @@
       it 'uses passed in params' do
         expected_results =
           {
+            request: request,
+            request_id: request_id,
             context: true,
             performance_data: true,
             replacements: { 'maxRecords' => '4' },
@@ -37,6 +42,8 @@
         it 'returns defaults' do
           expected_results =
             {
+              request: request,
+              request_id: request_id,
               context: false,
               performance_data: false,
               replacements: {},
@@ -53,6 +60,8 @@
         it 'returns defaults with language set to request language' do
           expected_results =
             {
+              request: request,
+              request_id: request_id,
               context: false,
               performance_data: false,
               replacements: {},
@@ -67,6 +76,7 @@
   end
 
   describe '#fetch_header' do
+    let(:request_id) { 'f1' }
     context 'when optional params are defined' do
       let(:fetch_params) do
         {
@@ -84,6 +94,8 @@
       it 'uses passed in params' do
         expected_results =
           {
+            request: request,
+            request_id: request_id,
             format: 'n3',
             performance_data: true,
             replacements: { 'extra' => 'data', 'even' => 'more data' },
@@ -101,6 +113,8 @@
         it 'returns defaults' do
           expected_results =
             {
+              request: request,
+              request_id: request_id,
               format: 'json',
               performance_data: false,
               replacements: {},
@@ -117,6 +131,8 @@
         it 'returns defaults with language set to request language' do
           expected_results =
             {
+              request: request,
+              request_id: request_id,
               format: 'json',
               performance_data: false,
               replacements: {},