diff options
author | Balakumar <sribalakumar@gmail.com> | 2019-08-22 17:31:57 +0300 |
---|---|---|
committer | Kamil TrzciĆski <ayufan@ayufan.eu> | 2019-08-22 17:31:57 +0300 |
commit | a47db86e909ec237332b6836dd830d1a0d54fd39 (patch) | |
tree | 61553b10a80822f607fd25ec3e9bebe2ed92c8ab /spec/lib/gitlab/sidekiq_logging | |
parent | 4e4f8534fd5154c35c182379a31201c3a5fe9c20 (diff) |
Log time spent on CPU to sidekiq.log
Diffstat (limited to 'spec/lib/gitlab/sidekiq_logging')
-rw-r--r-- | spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb | 37 |
1 files changed, 36 insertions, 1 deletions
diff --git a/spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb b/spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb index 5621d3d17d1..c09db4af8d8 100644 --- a/spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb +++ b/spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb @@ -36,7 +36,9 @@ describe Gitlab::SidekiqLogging::StructuredLogger do 'message' => 'TestWorker JID-da883554ee4fe414012f5f42: done: 0.0 sec', 'job_status' => 'done', 'duration' => 0.0, - "completed_at" => timestamp.iso8601(3) + "completed_at" => timestamp.iso8601(3), + "system_s" => 0.0, + "user_s" => 0.0 ) end let(:exception_payload) do @@ -52,6 +54,13 @@ describe Gitlab::SidekiqLogging::StructuredLogger do allow(Sidekiq).to receive(:logger).and_return(logger) allow(subject).to receive(:current_time).and_return(timestamp.to_f) + + allow(Process).to receive(:times).and_return( + stime: 0.0, + utime: 0.0, + cutime: 0.0, + cstime: 0.0 + ) end subject { described_class.new } @@ -177,5 +186,31 @@ describe Gitlab::SidekiqLogging::StructuredLogger do end end end + + def ctime(times) + times[:cstime] + times[:cutime] + end + + context 'with ctime value greater than 0' do + let(:times_start) { { stime: 0.04999, utime: 0.0483, cstime: 0.0188, cutime: 0.0188 } } + let(:times_end) { { stime: 0.0699, utime: 0.0699, cstime: 0.0399, cutime: 0.0399 } } + + before do + end_payload['system_s'] = 0.02 + end_payload['user_s'] = 0.022 + end_payload['child_s'] = 0.042 + + allow(Process).to receive(:times).and_return(times_start, times_end) + end + + it 'logs with ctime data and other cpu 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 |