Merge branch 'measure-proxy-timing' into 'master'

Measure proxy flight time

See merge request !4278

3 files changed, 56 insertions, 0 deletions

diff --git a/config/initializers/metrics.rb b/config/initializers/metrics.rb
index 2338916e9da..0c788714714 100644
--- a/config/initializers/metrics.rb
+++ b/config/initializers/metrics.rb
@@ -12,6 +12,7 @@ if Gitlab::Metrics.enabled?
 
   Gitlab::Application.configure do |config|
     config.middleware.use(Gitlab::Metrics::RackMiddleware)
+    config.middleware.use(Gitlab::Middleware::RailsQueueDuration)
   end
 
   Sidekiq.configure_server do |config|
diff --git a/lib/gitlab/middleware/rails_queue_duration.rb b/lib/gitlab/middleware/rails_queue_duration.rb
new file mode 100644
index 00000000000..56608b1b276
--- /dev/null
+++ b/lib/gitlab/middleware/rails_queue_duration.rb
@@ -0,0 +1,24 @@
+# This Rack middleware is intended to measure the latency between
+# gitlab-workhorse forwarding a request to the Rails application and the
+# time this middleware is reached.
+
+module Gitlab
+  module Middleware
+    class RailsQueueDuration
+      def initialize(app)
+        @app = app
+      end
+      
+      def call(env)
+        trans = Gitlab::Metrics.current_transaction
+        proxy_start = env['HTTP_GITLAB_WORHORSE_PROXY_START'].presence
+        if trans && proxy_start
+          # Time in milliseconds since gitlab-workhorse started the request
+          trans.set(:rails_queue_duration, Time.now.to_f * 1_000 - proxy_start.to_f / 1_000_000)
+        end
+
+        @app.call(env)
+      end
+    end
+  end
+end
diff --git a/spec/lib/gitlab/middleware/rails_queue_duration_spec.rb b/spec/lib/gitlab/middleware/rails_queue_duration_spec.rb
new file mode 100644
index 00000000000..fd6f684db0c
--- /dev/null
+++ b/spec/lib/gitlab/middleware/rails_queue_duration_spec.rb
@@ -0,0 +1,31 @@
+require 'spec_helper'
+
+describe Gitlab::Middleware::RailsQueueDuration do
+  let(:app) { double(:app) }
+  let(:middleware) { described_class.new(app) }
+  let(:env) { {} }
+  let(:transaction) { double(:transaction) }
+
+  before { expect(app).to receive(:call).with(env).and_return('yay') }
+
+  describe '#call' do
+    it 'calls the app when metrics are disabled' do
+      expect(Gitlab::Metrics).to receive(:current_transaction).and_return(nil)
+      expect(middleware.call(env)).to eq('yay')
+    end
+
+    context 'when metrics are enabled' do
+      before { allow(Gitlab::Metrics).to receive(:current_transaction).and_return(transaction) }
+
+      it 'calls the app when metrics are enabled but no timing header is found' do
+        expect(middleware.call(env)).to eq('yay')
+      end
+
+      it 'sets proxy_flight_time and calls the app when the header is present' do
+        env['HTTP_GITLAB_WORHORSE_PROXY_START'] = '123'
+        expect(transaction).to receive(:set).with(:rails_queue_duration, an_instance_of(Float))
+        expect(middleware.call(env)).to eq('yay')
+      end
+    end
+  end
+end