diff options
author | Stan Hu <stanhu@gmail.com> | 2019-08-09 07:33:20 +0300 |
---|---|---|
committer | Stan Hu <stanhu@gmail.com> | 2019-08-09 11:08:32 +0300 |
commit | a74396dcc5e372c0b6a23fd47db22ebbeb8386d7 (patch) | |
tree | 20492308e8d7acd6658fc3c80a6e98fedbd79be1 /spec/lib/gitlab/sidekiq_logging | |
parent | bbf639c43d689bd63a32ef7a60bdf83d3bd329bf (diff) |
Add Gitaly and Rugged call timing in Sidekiq logs
This will help identify Sidekiq jobs that invoke excessive number of
filesystem access.
The timing data is stored in `RequestStore`, but this is only active
within the middleware and is not directly accessible to the Sidekiq
logger. However, it is possible for the middleware to modify the job
hash to pass this data along to the logger.
Diffstat (limited to 'spec/lib/gitlab/sidekiq_logging')
-rw-r--r-- | spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb | 24 |
1 files changed, 24 insertions, 0 deletions
diff --git a/spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb b/spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb index 98286eb432d..b118d3f7017 100644 --- a/spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb +++ b/spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb @@ -153,5 +153,29 @@ describe Gitlab::SidekiqLogging::StructuredLogger do end end end + + context 'with Gitaly and Rugged calls' do + let(:timing_data) do + { + gitaly_calls: 10, + gitaly_duration: 10000, + rugged_calls: 1, + rugged_duration_ms: 5000 + } + end + + before do + job.merge!(timing_data) + end + + it 'logs with Gitaly and Rugged timing data' do + Timecop.freeze(timestamp) do + expect(logger).to receive(:info).with(start_payload.except('args')).ordered + expect(logger).to receive(:info).with(end_payload.except('args')).ordered + + subject.call(job, 'test_queue') { } + end + end + end end end |