Add Gitaly and Rugged call timing in Sidekiq logs

This will help identify Sidekiq jobs that invoke excessive number of
filesystem access.

The timing data is stored in `RequestStore`, but this is only active
within the middleware and is not directly accessible to the Sidekiq
logger. However, it is possible for the middleware to modify the job
hash to pass this data along to the logger.

1 files changed, 21 insertions, 0 deletions

diff --git a/lib/gitlab/sidekiq_middleware/instrumentation_logger.rb b/lib/gitlab/sidekiq_middleware/instrumentation_logger.rb
new file mode 100644
index 00000000000..979a3fce7e6
--- /dev/null
+++ b/lib/gitlab/sidekiq_middleware/instrumentation_logger.rb
@@ -0,0 +1,21 @@
+# frozen_string_literal: true
+
+module Gitlab
+  module SidekiqMiddleware
+    class InstrumentationLogger
+      def call(worker, job, queue)
+        yield
+
+        # The Sidekiq logger is called outside the middleware block, so
+        # we need to modify the job hash to pass along this information
+        # since RequestStore is only active in the Sidekiq middleware.
+        #
+        # Modifying the job hash in a middleware is permitted by Sidekiq
+        # because Sidekiq keeps a pristine copy of the original hash
+        # before sending it to the middleware:
+        # https://github.com/mperham/sidekiq/blob/53bd529a0c3f901879925b8390353129c465b1f2/lib/sidekiq/processor.rb#L115-L118
+        ::Gitlab::InstrumentationHelper.add_instrumentation_data(job)
+      end
+    end
+  end
+end