diff options
author | GitLab Bot <gitlab-bot@gitlab.com> | 2019-10-28 18:05:58 +0300 |
---|---|---|
committer | GitLab Bot <gitlab-bot@gitlab.com> | 2019-10-28 18:05:58 +0300 |
commit | a77db6bc47d8cdd9edae2ec22f640821d0794404 (patch) | |
tree | 15861a5f1ec29e07c2012102e463402bb7dc8c2d /spec/lib | |
parent | 6cf6996f183bdff46e73431c07bfb723066a8222 (diff) |
Add latest changes from gitlab-org/gitlab@master
Diffstat (limited to 'spec/lib')
-rw-r--r-- | spec/lib/gitlab/instrumentation_helper_spec.rb | 37 | ||||
-rw-r--r-- | spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb | 2 | ||||
-rw-r--r-- | spec/lib/gitlab/sidekiq_middleware/metrics_spec.rb | 83 |
3 files changed, 87 insertions, 35 deletions
diff --git a/spec/lib/gitlab/instrumentation_helper_spec.rb b/spec/lib/gitlab/instrumentation_helper_spec.rb new file mode 100644 index 00000000000..c2674638743 --- /dev/null +++ b/spec/lib/gitlab/instrumentation_helper_spec.rb @@ -0,0 +1,37 @@ +# frozen_string_literal: true + +require 'fast_spec_helper' +require 'rspec-parameterized' + +describe Gitlab::InstrumentationHelper do + using RSpec::Parameterized::TableSyntax + + describe '.queue_duration_for_job' do + where(:enqueued_at, :created_at, :time_now, :expected_duration) do + "2019-06-01T00:00:00.000+0000" | nil | "2019-06-01T02:00:00.000+0000" | 2.hours.to_f + "2019-06-01T02:00:00.000+0000" | nil | "2019-06-01T02:00:00.001+0000" | 0.001 + "2019-06-01T02:00:00.000+0000" | "2019-05-01T02:00:00.000+0000" | "2019-06-01T02:00:01.000+0000" | 1 + nil | "2019-06-01T02:00:00.000+0000" | "2019-06-01T02:00:00.001+0000" | 0.001 + nil | nil | "2019-06-01T02:00:00.001+0000" | nil + "2019-06-01T02:00:00.000+0200" | nil | "2019-06-01T02:00:00.000-0200" | 4.hours.to_f + 1571825569.998168 | nil | "2019-10-23T12:13:16.000+0200" | 26.001832 + 1571825569 | nil | "2019-10-23T12:13:16.000+0200" | 27 + "invalid_date" | nil | "2019-10-23T12:13:16.000+0200" | nil + "" | nil | "2019-10-23T12:13:16.000+0200" | nil + 0 | nil | "2019-10-23T12:13:16.000+0200" | nil + -1 | nil | "2019-10-23T12:13:16.000+0200" | nil + "2019-06-01T02:00:00.000+0000" | nil | "2019-06-01T00:00:00.000+0000" | 0 + Time.at(1571999233) | nil | "2019-10-25T12:29:16.000+0200" | 123 + end + + with_them do + let(:job) { { 'enqueued_at' => enqueued_at, 'created_at' => created_at } } + + it "returns the correct duration" do + Timecop.freeze(Time.iso8601(time_now)) do + expect(described_class.queue_duration_for_job(job)).to eq(expected_duration) + end + end + end + end +end diff --git a/spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb b/spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb index 46fbc069efb..cb870cc996b 100644 --- a/spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb +++ b/spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb @@ -1,6 +1,6 @@ # frozen_string_literal: true -require 'spec_helper' +require 'fast_spec_helper' describe Gitlab::SidekiqLogging::StructuredLogger do describe '#call' do diff --git a/spec/lib/gitlab/sidekiq_middleware/metrics_spec.rb b/spec/lib/gitlab/sidekiq_middleware/metrics_spec.rb index df16b9d073c..0d8cff3a295 100644 --- a/spec/lib/gitlab/sidekiq_middleware/metrics_spec.rb +++ b/spec/lib/gitlab/sidekiq_middleware/metrics_spec.rb @@ -1,11 +1,12 @@ # frozen_string_literal: true -require 'spec_helper' +require 'fast_spec_helper' describe Gitlab::SidekiqMiddleware::Metrics do let(:middleware) { described_class.new } - let(:concurrency_metric) { double('concurrency metric') } + + let(:queue_duration_seconds) { double('queue duration seconds metric') } let(:completion_seconds_metric) { double('completion seconds metric') } let(:user_execution_seconds_metric) { double('user execution seconds metric') } let(:failed_total_metric) { double('failed total metric') } @@ -13,6 +14,7 @@ describe Gitlab::SidekiqMiddleware::Metrics do let(:running_jobs_metric) { double('running jobs metric') } before do + allow(Gitlab::Metrics).to receive(:histogram).with(:sidekiq_jobs_queue_duration_seconds, anything, anything, anything).and_return(queue_duration_seconds) allow(Gitlab::Metrics).to receive(:histogram).with(:sidekiq_jobs_completion_seconds, anything, anything, anything).and_return(completion_seconds_metric) allow(Gitlab::Metrics).to receive(:histogram).with(:sidekiq_jobs_cpu_seconds, anything, anything, anything).and_return(user_execution_seconds_metric) allow(Gitlab::Metrics).to receive(:counter).with(:sidekiq_jobs_failed_total, anything).and_return(failed_total_metric) @@ -20,7 +22,6 @@ describe Gitlab::SidekiqMiddleware::Metrics do allow(Gitlab::Metrics).to receive(:gauge).with(:sidekiq_running_jobs, anything, {}, :all).and_return(running_jobs_metric) allow(Gitlab::Metrics).to receive(:gauge).with(:sidekiq_concurrency, anything, {}, :all).and_return(concurrency_metric) - allow(running_jobs_metric).to receive(:increment) allow(concurrency_metric).to receive(:set) end @@ -32,62 +33,76 @@ describe Gitlab::SidekiqMiddleware::Metrics do end end + it 'ignore user execution when measured 0' do + allow(completion_seconds_metric).to receive(:observe) + + expect(user_execution_seconds_metric).not_to receive(:observe) + end + describe '#call' do let(:worker) { double(:worker) } - it 'yields block' do - allow(completion_seconds_metric).to receive(:observe) - allow(user_execution_seconds_metric).to receive(:observe) + let(:job) { {} } + let(:job_status) { :done } + let(:labels) { { queue: :test } } + let(:labels_with_job_status) { { queue: :test, job_status: job_status } } - expect { |b| middleware.call(worker, {}, :test, &b) }.to yield_control.once - end + let(:thread_cputime_before) { 1 } + let(:thread_cputime_after) { 2 } + let(:thread_cputime_duration) { thread_cputime_after - thread_cputime_before } - it 'sets queue specific metrics' do - labels = { queue: :test } - labels_with_job_status = { queue: :test, job_status: :done } - allow(middleware).to receive(:get_thread_cputime).and_return(1, 3) - allow(Gitlab::Metrics::System).to receive(:monotonic_time).and_return(2, 3) + let(:monotonic_time_before) { 11 } + let(:monotonic_time_after) { 20 } + let(:monotonic_time_duration) { monotonic_time_after - monotonic_time_before } + + let(:queue_duration_for_job) { 0.01 } + + before do + allow(middleware).to receive(:get_thread_cputime).and_return(thread_cputime_before, thread_cputime_after) + allow(Gitlab::Metrics::System).to receive(:monotonic_time).and_return(monotonic_time_before, monotonic_time_after) + allow(Gitlab::InstrumentationHelper).to receive(:queue_duration_for_job).with(job).and_return(queue_duration_for_job) expect(running_jobs_metric).to receive(:increment).with(labels, 1) expect(running_jobs_metric).to receive(:increment).with(labels, -1) - expect(user_execution_seconds_metric).to receive(:observe).with(labels_with_job_status, 2) - expect(completion_seconds_metric).to receive(:observe).with(labels_with_job_status, 1) - middleware.call(worker, {}, :test) { nil } + expect(queue_duration_seconds).to receive(:observe).with(labels, queue_duration_for_job) if queue_duration_for_job + expect(user_execution_seconds_metric).to receive(:observe).with(labels_with_job_status, thread_cputime_duration) + expect(completion_seconds_metric).to receive(:observe).with(labels_with_job_status, monotonic_time_duration) end - it 'ignore user execution when measured 0' do - allow(completion_seconds_metric).to receive(:observe) - allow(middleware).to receive(:get_thread_cputime).and_return(0, 0) + it 'yields block' do + expect { |b| middleware.call(worker, job, :test, &b) }.to yield_control.once + end + + it 'sets queue specific metrics' do + middleware.call(worker, job, :test) { nil } + end + + context 'when job_duration is not available' do + let(:queue_duration_for_job) { nil } - expect(user_execution_seconds_metric).not_to receive(:observe) + it 'does not set the queue_duration_seconds histogram' do + middleware.call(worker, job, :test) { nil } + end end context 'when job is retried' do - it 'sets sidekiq_jobs_retried_total metric' do - allow(completion_seconds_metric).to receive(:observe) - expect(user_execution_seconds_metric).to receive(:observe) + let(:job) { { 'retry_count' => 1 } } + it 'sets sidekiq_jobs_retried_total metric' do expect(retried_total_metric).to receive(:increment) - middleware.call(worker, { 'retry_count' => 1 }, :test) { nil } + middleware.call(worker, job, :test) { nil } end end context 'when error is raised' do - it 'sets sidekiq_jobs_failed_total and reraises' do - labels = { queue: :test } - labels_with_job_status = { queue: :test, job_status: :fail } - allow(middleware).to receive(:get_thread_cputime).and_return(1, 4) - allow(Gitlab::Metrics::System).to receive(:monotonic_time).and_return(2, 6) + let(:job_status) { :fail } - expect(running_jobs_metric).to receive(:increment).with(labels, 1) - expect(running_jobs_metric).to receive(:increment).with(labels, -1) + it 'sets sidekiq_jobs_failed_total and reraises' do expect(failed_total_metric).to receive(:increment).with(labels, 1) - expect(user_execution_seconds_metric).to receive(:observe).with(labels_with_job_status, 3) - expect(completion_seconds_metric).to receive(:observe).with(labels_with_job_status, 4) - expect { middleware.call(worker, {}, :test) { raise StandardError, "Failed" } }.to raise_error(StandardError, "Failed") + expect { middleware.call(worker, job, :test) { raise StandardError, "Failed" } }.to raise_error(StandardError, "Failed") end end end |