From ed9cb85711349ffcdd0ecf29320313dcecaba8c1 Mon Sep 17 00:00:00 2001 From: Thong Kuah Date: Fri, 9 Aug 2019 11:59:44 +0000 Subject: Merge branch 'sh-fix-sidekiq-scheduling-latency' into 'master' Fix Sidekiq scheduling_latency_s Closes #65748 See merge request gitlab-org/gitlab-ce!31650 (cherry picked from commit 9e19125f391edd90d74d60720a3a8887d9ce1258) 7ccbb562 Fix Sidekiq scheduling_latency_s --- lib/gitlab/sidekiq_logging/structured_logger.rb | 6 +++++- spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb | 4 ++-- 2 files changed, 7 insertions(+), 3 deletions(-) diff --git a/lib/gitlab/sidekiq_logging/structured_logger.rb b/lib/gitlab/sidekiq_logging/structured_logger.rb index d556d5ef129..3ebc71dcc8b 100644 --- a/lib/gitlab/sidekiq_logging/structured_logger.rb +++ b/lib/gitlab/sidekiq_logging/structured_logger.rb @@ -35,7 +35,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 @@ -84,6 +84,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 98286eb432d..bf26335ef7f 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 { -- cgit v1.2.1