Add response time in a parsable formation `

lib/logcache/client.rb

@@ -44,13 +44,14 @@ def container_metrics(source_guid:, start_time:, end_time:, envelope_limit: DEFA
 
     private
 
-    def with_request_error_handling(_source_guid)
+    def with_request_error_handling(source_guid)
       tries ||= 3
       start_time = Time.now
-
-      # convert to milliseconds to get more precise information
-      time_taken = (Time.now - start_time) * 1000
-      logger.info("Response time: #{time_taken.round(2)} ms")
+      time_taken = (Time.now - start_time) * 1000 # convert to milliseconds to get more precise information
+      logger.info("Response time: #{time_taken.round(2)} ms",
+                  { source_id: source_guid,
+                    event: 'log_cache_request',
+                    time_taken_in_ms: time_taken.round(2) })
       yield
     rescue StandardError => e
       raise CloudController::Errors::ApiError.new_from_details('ServiceUnavailable', 'Connection to Log Cache timed out') if e.is_a?(GRPC::DeadlineExceeded)

spec/logcache/client_spec.rb

@@ -26,6 +26,7 @@ module Logcache
       let(:client_ca) { File.read(client_ca_path) }
       let(:client_key) { File.read(client_key_path) }
       let(:client_cert) { File.read(client_cert_path) }
+      let(:mock_logger) { double(Steno::Logger, info: nil) }
 
       describe '#container_metrics' do
         let(:instance_count) { 2 }
@@ -39,6 +40,7 @@ module Logcache
             with("#{host}:#{port}", credentials, channel_args: channel_arg_hash, timeout: 10).
             and_return(logcache_service)
           allow(Logcache::V1::ReadRequest).to receive(:new).and_return(logcache_request)
+          allow_any_instance_of(Client).to receive(:logger).and_return(mock_logger)
         end
 
         it 'calls Logcache with the correct parameters and returns envelopes' do
@@ -56,6 +58,18 @@ module Logcache
           )
           expect(logcache_service).to have_received(:read).with(logcache_request)
         end
+
+        it 'logs the response time and metadata' do
+          client.container_metrics(source_guid: process.guid, envelope_limit: 1000, start_time: 100, end_time: 101)
+          expect(mock_logger).to have_received(:info).with(
+            a_string_matching(/Response time: \d+\.\d+ ms/),
+            hash_including(
+              source_id: process.guid,
+              event: 'log_cache_request',
+              time_taken_in_ms: be_a(Float)
+            )
+          )
+        end
       end
 
       describe 'when logcache is unavailable' do