Commit 7ccbb562 authored by Stan Hu's avatar Stan Hu

Fix Sidekiq scheduling_latency_s

This number was reporting a negative number because `current_time` was
a monotonic counter, not an absolute time.

Closes https://gitlab.com/gitlab-org/gitlab-ce/issues/65748
parent 44aa23b9
...@@ -35,7 +35,7 @@ module Gitlab ...@@ -35,7 +35,7 @@ module Gitlab
# Old gitlab-shell messages don't provide enqueued_at/created_at attributes # Old gitlab-shell messages don't provide enqueued_at/created_at attributes
enqueued_at = payload['enqueued_at'] || payload['created_at'] enqueued_at = payload['enqueued_at'] || payload['created_at']
if enqueued_at if enqueued_at
payload['scheduling_latency_s'] = elapsed(Time.iso8601(enqueued_at).to_f) payload['scheduling_latency_s'] = elapsed_by_absolute_time(Time.iso8601(enqueued_at))
end end
payload payload
...@@ -84,6 +84,10 @@ module Gitlab ...@@ -84,6 +84,10 @@ module Gitlab
end end
end end
def elapsed_by_absolute_time(start)
(Time.now.utc - start).to_f.round(3)
end
def elapsed(start) def elapsed(start)
(current_time - start).round(3) (current_time - start).round(3)
end end
......
...@@ -3,8 +3,8 @@ require 'spec_helper' ...@@ -3,8 +3,8 @@ require 'spec_helper'
describe Gitlab::SidekiqLogging::StructuredLogger do describe Gitlab::SidekiqLogging::StructuredLogger do
describe '#call' do describe '#call' do
let(:timestamp) { Time.iso8601('2018-01-01T12:00:00Z') } let(:timestamp) { Time.iso8601('2018-01-01T12:00:00Z') }
let(:created_at) { timestamp } let(:created_at) { timestamp - 1.second }
let(:scheduling_latency_s) { 0.0 } let(:scheduling_latency_s) { 1.0 }
let(:job) do let(:job) do
{ {
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment