diff --git a/lib/gitlab/sidekiq_logging/structured_logger.rb b/lib/gitlab/sidekiq_logging/structured_logger.rb index b17135922f6..60782306ade 100644 --- a/lib/gitlab/sidekiq_logging/structured_logger.rb +++ b/lib/gitlab/sidekiq_logging/structured_logger.rb @@ -39,7 +39,7 @@ module Gitlab # Old gitlab-shell messages don't provide enqueued_at/created_at attributes enqueued_at = payload['enqueued_at'] || payload['created_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 payload @@ -89,6 +89,10 @@ module Gitlab end end + def elapsed_by_absolute_time(start) + (Time.now.utc - start).to_f.round(3) + end + def elapsed(start) (current_time - start).round(3) end diff --git a/spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb b/spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb index b118d3f7017..5621d3d17d1 100644 --- a/spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb +++ b/spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb @@ -3,8 +3,8 @@ require 'spec_helper' describe Gitlab::SidekiqLogging::StructuredLogger do describe '#call' do let(:timestamp) { Time.iso8601('2018-01-01T12:00:00Z') } - let(:created_at) { timestamp } - let(:scheduling_latency_s) { 0.0 } + let(:created_at) { timestamp - 1.second } + let(:scheduling_latency_s) { 1.0 } let(:job) do {