Log queue duration for Grape API callssh-tag-queue-duration-api-calls

This mimics the same thing the RailsQueueDuration does for Rails controller
requests and will help diagnose issues with API delays.

Closes #46601

2 files changed, 28 insertions, 1 deletions

diff --git a/lib/api/api.rb b/lib/api/api.rb
index de20b2b8e67..206fabe5c43 100644
--- a/lib/api/api.rb
+++ b/lib/api/api.rb
@@ -15,7 +15,8 @@ module API
                   include: [
                     GrapeLogging::Loggers::FilterParameters.new,
                     GrapeLogging::Loggers::ClientEnv.new,
-                    Gitlab::GrapeLogging::Loggers::UserLogger.new
+                    Gitlab::GrapeLogging::Loggers::UserLogger.new,
+                    Gitlab::GrapeLogging::Loggers::QueueDurationLogger.new
                   ]
 
     allow_access_with_scope :api
diff --git a/lib/gitlab/grape_logging/loggers/queue_duration_logger.rb b/lib/gitlab/grape_logging/loggers/queue_duration_logger.rb
new file mode 100644
index 00000000000..0adac79f25a
--- /dev/null
+++ b/lib/gitlab/grape_logging/loggers/queue_duration_logger.rb
@@ -0,0 +1,26 @@
+# This grape_logging module (https://github.com/aserafin/grape_logging) makes it
+# possible to log how much time an API request was queued by Workhorse.
+module Gitlab
+  module GrapeLogging
+    module Loggers
+      class QueueDurationLogger < ::GrapeLogging::Loggers::Base
+        attr_accessor :start_time
+
+        def before
+          @start_time = Time.now
+        end
+
+        def parameters(request, _)
+          proxy_start = request.env['HTTP_GITLAB_WORKHORSE_PROXY_START'].presence
+
+          return {} unless proxy_start && start_time
+
+          # Time in milliseconds since gitlab-workhorse started the request
+          duration = (start_time.to_f * 1_000 - proxy_start.to_f / 1_000_000).round(2)
+
+          { 'queue_duration': duration }
+        end
+      end
+    end
+  end
+end