diff options
author | GitLab Bot <gitlab-bot@gitlab.com> | 2020-01-11 03:08:28 +0300 |
---|---|---|
committer | GitLab Bot <gitlab-bot@gitlab.com> | 2020-01-11 03:08:28 +0300 |
commit | 7873bb3c1a2870761c243ea4ebe96f249ad5a319 (patch) | |
tree | 89ddef4a2e4b9cb47d41f6ff8ff68bda8777c938 /spec/lib/gitlab/sidekiq_logging | |
parent | 667f6fbc8df6c23f69bc6adba15204f8559bcc3a (diff) |
Add latest changes from gitlab-org/gitlab@master
Diffstat (limited to 'spec/lib/gitlab/sidekiq_logging')
-rw-r--r-- | spec/lib/gitlab/sidekiq_logging/json_formatter_spec.rb | 53 | ||||
-rw-r--r-- | spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb | 18 |
2 files changed, 48 insertions, 23 deletions
diff --git a/spec/lib/gitlab/sidekiq_logging/json_formatter_spec.rb b/spec/lib/gitlab/sidekiq_logging/json_formatter_spec.rb index a2cb38ec5b1..f2092334117 100644 --- a/spec/lib/gitlab/sidekiq_logging/json_formatter_spec.rb +++ b/spec/lib/gitlab/sidekiq_logging/json_formatter_spec.rb @@ -3,28 +3,53 @@ require 'spec_helper' describe Gitlab::SidekiqLogging::JSONFormatter do - let(:hash_input) { { foo: 1, bar: 'test' } } let(:message) { 'This is a test' } - let(:timestamp) { Time.now } - - it 'wraps a Hash' do - result = subject.call('INFO', timestamp, 'my program', hash_input) - - data = JSON.parse(result) - expected_output = hash_input.stringify_keys - expected_output['severity'] = 'INFO' - expected_output['time'] = timestamp.utc.iso8601(3) - - expect(data).to eq(expected_output) + let(:now) { Time.now } + let(:timestamp) { now.utc.to_f } + let(:timestamp_iso8601) { now.iso8601(3) } + + describe 'with a Hash' do + let(:hash_input) do + { + foo: 1, + 'bar' => 'test', + 'created_at' => timestamp, + 'enqueued_at' => timestamp, + 'started_at' => timestamp, + 'retried_at' => timestamp, + 'failed_at' => timestamp, + 'completed_at' => timestamp_iso8601 + } + end + + it 'properly formats timestamps into ISO 8601 form' do + result = subject.call('INFO', now, 'my program', hash_input) + + data = JSON.parse(result) + expected_output = hash_input.stringify_keys.merge!( + { + 'severity' => 'INFO', + 'time' => timestamp_iso8601, + 'created_at' => timestamp_iso8601, + 'enqueued_at' => timestamp_iso8601, + 'started_at' => timestamp_iso8601, + 'retried_at' => timestamp_iso8601, + 'failed_at' => timestamp_iso8601, + 'completed_at' => timestamp_iso8601 + } + ) + + expect(data).to eq(expected_output) + end end it 'wraps a String' do - result = subject.call('DEBUG', timestamp, 'my string', message) + result = subject.call('DEBUG', now, 'my string', message) data = JSON.parse(result) expected_output = { severity: 'DEBUG', - time: timestamp.utc.iso8601(3), + time: timestamp_iso8601, message: message } diff --git a/spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb b/spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb index 20adfe7091c..43cdb998091 100644 --- a/spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb +++ b/spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb @@ -30,8 +30,8 @@ describe Gitlab::SidekiqLogging::StructuredLogger do 'message' => 'TestWorker JID-da883554ee4fe414012f5f42: start', 'job_status' => 'start', 'pid' => Process.pid, - 'created_at' => created_at.iso8601(3), - 'enqueued_at' => created_at.iso8601(3), + 'created_at' => created_at.to_f, + 'enqueued_at' => created_at.to_f, 'scheduling_latency_s' => scheduling_latency_s ) end @@ -40,7 +40,7 @@ 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.to_f, 'cpu_s' => 1.111112, 'db_duration' => 0, 'db_duration_s' => 0 @@ -227,17 +227,17 @@ describe Gitlab::SidekiqLogging::StructuredLogger do describe '#add_time_keys!' do let(:time) { { duration: 0.1231234, cputime: 1.2342345 } } let(:payload) { { 'class' => 'my-class', 'message' => 'my-message', 'job_status' => 'my-job-status' } } - let(:current_utc_time) { '2019-09-23 10:00:58 UTC' } - let(:payload_with_time_keys) { { 'class' => 'my-class', 'message' => 'my-message', 'job_status' => 'my-job-status', 'duration' => 0.123123, 'cpu_s' => 1.234235, 'completed_at' => current_utc_time } } + let(:current_utc_time) { Time.now.utc } + let(:payload_with_time_keys) { { 'class' => 'my-class', 'message' => 'my-message', 'job_status' => 'my-job-status', 'duration' => 0.123123, 'cpu_s' => 1.234235, 'completed_at' => current_utc_time.to_f } } subject { described_class.new } it 'update payload correctly' do - expect(Time).to receive_message_chain(:now, :utc).and_return(current_utc_time) + Timecop.freeze(current_utc_time) do + subject.send(:add_time_keys!, time, payload) - subject.send(:add_time_keys!, time, payload) - - expect(payload).to eq(payload_with_time_keys) + expect(payload).to eq(payload_with_time_keys) + end end end end |