Add Sidekiq job latency to transaction metrics.18663-sidekiq-latency-instrumentation

3 files changed, 19 insertions, 1 deletions

diff --git a/CHANGELOG b/CHANGELOG
index 76d9712ce9f..2ed548ea244 100644
--- a/CHANGELOG
+++ b/CHANGELOG
@@ -2,6 +2,7 @@ Please view this file on the master branch, on stable branches it's out of date.
 
 v 8.10.0 (unreleased)
   - Wrap code blocks on Activies and Todos page. !4783 (winniehell)
+  - Add Sidekiq job latency to transaction metrics.
   - Fix MR-auto-close text added to description. !4836
   - Implement Subresource Integrity for CSS and JavaScript assets. This prevents malicious assets from loading in the case of a CDN compromise.
 
diff --git a/lib/gitlab/metrics/sidekiq_middleware.rb b/lib/gitlab/metrics/sidekiq_middleware.rb
index fd98aa3412e..1bb69e85141 100644
--- a/lib/gitlab/metrics/sidekiq_middleware.rb
+++ b/lib/gitlab/metrics/sidekiq_middleware.rb
@@ -8,6 +8,8 @@ module Gitlab
         trans = Transaction.new("#{worker.class.name}#perform")
 
         begin
+          # Old gitlad-shell messages don't provide enqueued_at/created_at attributes
+          trans.set(:latency, Time.now.to_f - (message['enqueued_at'] || message['created_at'] || 0))
           trans.run { yield }
         ensure
           trans.finish
diff --git a/spec/lib/gitlab/metrics/sidekiq_middleware_spec.rb b/spec/lib/gitlab/metrics/sidekiq_middleware_spec.rb
index e520a968999..d8624f062ad 100644
--- a/spec/lib/gitlab/metrics/sidekiq_middleware_spec.rb
+++ b/spec/lib/gitlab/metrics/sidekiq_middleware_spec.rb
@@ -2,6 +2,7 @@ require 'spec_helper'
 
 describe Gitlab::Metrics::SidekiqMiddleware do
   let(:middleware) { described_class.new }
+  let(:message) { { 'args' => ['test'], 'enqueued_at' => Time.new(2016, 6, 23, 6, 59).to_f } }
 
   describe '#call' do
     it 'tracks the transaction' do
@@ -11,9 +12,23 @@ describe Gitlab::Metrics::SidekiqMiddleware do
         with('TestWorker#perform').
         and_call_original
 
+      expect_any_instance_of(Gitlab::Metrics::Transaction).to receive(:set).with(:latency, instance_of(Float))
       expect_any_instance_of(Gitlab::Metrics::Transaction).to receive(:finish)
 
-      middleware.call(worker, 'test', :test) { nil }
+      middleware.call(worker, message, :test) { nil }
+    end
+
+    it 'tracks the transaction (for messages without `enqueued_at`)' do
+      worker = double(:worker, class: double(:class, name: 'TestWorker'))
+
+      expect(Gitlab::Metrics::Transaction).to receive(:new).
+        with('TestWorker#perform').
+        and_call_original
+
+      expect_any_instance_of(Gitlab::Metrics::Transaction).to receive(:set).with(:latency, instance_of(Float))
+      expect_any_instance_of(Gitlab::Metrics::Transaction).to receive(:finish)
+
+      middleware.call(worker, {}, :test) { nil }
     end
   end
 end