Merge branch 'sh-add-gitaly-duration-logs' into 'master'

Log Gitaly RPC duration to api_json.log and production_json.log

See merge request gitlab-org/gitlab-ce!26652

2 files changed, 16 insertions, 7 deletions

diff --git a/lib/gitlab/gitaly_client.rb b/lib/gitlab/gitaly_client.rb
index e3b9a7a1a89..49cff7517e9 100644
--- a/lib/gitlab/gitaly_client.rb
+++ b/lib/gitlab/gitaly_client.rb
@@ -33,12 +33,6 @@ module Gitlab
 
     MUTEX = Mutex.new
 
-    class << self
-      attr_accessor :query_time
-    end
-
-    self.query_time = 0
-
     define_histogram :gitaly_controller_action_duration_seconds do
       docstring "Gitaly endpoint histogram by controller and action combination"
       base_labels Gitlab::Metrics::Transaction::BASE_LABELS.merge(gitaly_service: nil, rpc: nil)
@@ -174,6 +168,18 @@ module Gitlab
       add_call_details(feature: "#{service}##{rpc}", duration: duration, request: request_hash, rpc: rpc)
     end
 
+    def self.query_time
+      SafeRequestStore[:gitaly_query_time] ||= 0
+    end
+
+    def self.query_time=(duration)
+      SafeRequestStore[:gitaly_query_time] = duration
+    end
+
+    def self.query_time_ms
+      (self.query_time * 1000).round(2)
+    end
+
     def self.current_transaction_labels
       Gitlab::Metrics::Transaction.current&.labels || {}
     end
diff --git a/lib/gitlab/grape_logging/loggers/perf_logger.rb b/lib/gitlab/grape_logging/loggers/perf_logger.rb
index e3b9c59bd6e..18ea3a8d2f3 100644
--- a/lib/gitlab/grape_logging/loggers/perf_logger.rb
+++ b/lib/gitlab/grape_logging/loggers/perf_logger.rb
@@ -6,7 +6,10 @@ module Gitlab
     module Loggers
       class PerfLogger < ::GrapeLogging::Loggers::Base
         def parameters(_, _)
-          { gitaly_calls: Gitlab::GitalyClient.get_request_count }
+          {
+            gitaly_calls: Gitlab::GitalyClient.get_request_count,
+            gitaly_duration: Gitlab::GitalyClient.query_time_ms
+          }
         end
       end
     end