diff --git a/lib/middleware/request_tracker.rb b/lib/middleware/request_tracker.rb index e7ffb8869a4..0f2a126e664 100644 --- a/lib/middleware/request_tracker.rb +++ b/lib/middleware/request_tracker.rb @@ -129,7 +129,8 @@ class Middleware::RequestTracker is_background: !!(request.path =~ /^\/message-bus\// || request.path =~ /\/topics\/timings/), is_mobile: helper.is_mobile?, track_view: track_view, - timing: timing + timing: timing, + queue_seconds: env['REQUEST_QUEUE_SECONDS'] }.tap do |h| h[:user_agent] = env['HTTP_USER_AGENT'] if h[:is_crawler] end @@ -158,6 +159,15 @@ class Middleware::RequestTracker def call(env) result = nil log_request = true + + # doing this as early as possible so we have an + # accurate counter + if queue_start = env['HTTP_X_REQUEST_START'] + queue_start = queue_start.split("t=")[1].to_f + queue_time = (Time.now.to_f - queue_start) + env['REQUEST_QUEUE_SECONDS'] = queue_time + end + request = Rack::Request.new(env) if rate_limit(request) diff --git a/spec/components/middleware/request_tracker_spec.rb b/spec/components/middleware/request_tracker_spec.rb index 96262e78ed4..a36a3f307bf 100644 --- a/spec/components/middleware/request_tracker_spec.rb +++ b/spec/components/middleware/request_tracker_spec.rb @@ -265,8 +265,15 @@ describe Middleware::RequestTracker do # ensure pg is warmed up with the select 1 query User.where(id: -100).pluck(:id) + freeze_time + start = Time.now.to_f + + freeze_time 1.minute.from_now + tracker = Middleware::RequestTracker.new(app([200, {}, []], sql_calls: 2, redis_calls: 2)) - tracker.call(env) + tracker.call(env("HTTP_X_REQUEST_START" => "t=#{start}")) + + expect(@data[:queue_seconds]).to eq(60) timing = @data[:timing] expect(timing[:total_duration]).to be > 0