diff --git a/README.md b/README.md index add9123..afa3690 100644 --- a/README.md +++ b/README.md @@ -92,7 +92,7 @@ For each queue, the following metrics will be reported: 2. **shared.sidekiq._queue_.latency**: gauge of how long the oldest job has been in the queue For each worker, the following metrics and tags will be reported: -1. **sidekiq.worker_metrics.inqueue.#{key}**: number of jobs "in queue" per worker, uses redis to track increment/decrement +1. **sidekiq.worker_metrics.in_queue.#{key}**: number of jobs "in queue" per worker, uses redis to track increment/decrement ## DogStatsD Keys For each job, the following metrics and tags will be reported: @@ -111,7 +111,7 @@ For each queue, the following metrics and tags will be reported: 2. **sidekiq.queue.latency (tags: {queue: _queue_})**: gauge of how long the oldest job has been in the queue For each worker, the following metrics and tags will be reported: -1. **sidekiq.worker_metrics.inqueue.#{key}**: number of jobs "in queue" per worker, uses redis to track increment/decrement +1. **sidekiq.worker_metrics.in_queue.#{key}**: number of jobs "in queue" per worker, uses redis to track increment/decrement ## Worker There is a worker, `Sidekiq::Instrument::Worker`, that submits gauges diff --git a/lib/sidekiq/instrument/middleware/server.rb b/lib/sidekiq/instrument/middleware/server.rb index 78c953e..3cbb17b 100644 --- a/lib/sidekiq/instrument/middleware/server.rb +++ b/lib/sidekiq/instrument/middleware/server.rb @@ -7,12 +7,11 @@ module Sidekiq::Instrument class ServerMiddleware include Sidekiq::Instrument::MetricNames - def call(worker, job, queue, &block) + def call(worker, _job, _queue, &block) Statter.statsd.increment(metric_name(worker, 'dequeue')) Statter.dogstatsd&.increment('sidekiq.dequeue', worker_dog_options(worker)) start_time = Time.now - WorkerMetrics.trace_workers_decrement_counter(worker.class.to_s.underscore) yield block execution_time_ms = (Time.now - start_time) * 1000 Statter.statsd.measure(metric_name(worker, 'runtime'), execution_time_ms) @@ -22,6 +21,7 @@ def call(worker, job, queue, &block) Statter.dogstatsd&.increment('sidekiq.error', worker_dog_options(worker)) raise e ensure + WorkerMetrics.trace_workers_decrement_counter(worker.class.to_s.underscore) Statter.dogstatsd&.flush(sync: true) end end diff --git a/lib/sidekiq/instrument/version.rb b/lib/sidekiq/instrument/version.rb index db10415..5dac7ab 100644 --- a/lib/sidekiq/instrument/version.rb +++ b/lib/sidekiq/instrument/version.rb @@ -1,5 +1,5 @@ module Sidekiq module Instrument - VERSION = '0.6.1' + VERSION = '0.6.2' end end diff --git a/lib/sidekiq/instrument/worker.rb b/lib/sidekiq/instrument/worker.rb index 89ac64e..b4c4476 100644 --- a/lib/sidekiq/instrument/worker.rb +++ b/lib/sidekiq/instrument/worker.rb @@ -1,3 +1,5 @@ +# frozen_string_literal: true + require 'sidekiq' require 'sidekiq/api' @@ -13,7 +15,7 @@ class Worker workers_size: :workers, enqueued: :pending, failed: nil - } + }.freeze def perform info = Sidekiq::Stats.new @@ -64,8 +66,8 @@ def send_worker_metrics return unless WorkerMetrics.enabled WorkerMetrics.workers_in_queue.each do |key, value| - Statter.statsd.gauge("shared.sidekiq.worker_metrics.inqueue.#{key}", value) - Statter.dogstatsd&.gauge("shared.sidekiq.worker_metrics.inqueue", value, tags: ["worker:#{key}"]) + Statter.statsd.gauge("shared.sidekiq.worker_metrics.in_queue.#{key}", value) + Statter.dogstatsd&.gauge('shared.sidekiq.worker_metrics.in_queue', value, tags: ["worker:#{key}"]) end end end diff --git a/sidekiq-instrument.gemspec b/sidekiq-instrument.gemspec index 7ed246f..e3a9cb0 100644 --- a/sidekiq-instrument.gemspec +++ b/sidekiq-instrument.gemspec @@ -25,6 +25,7 @@ Gem::Specification.new do |spec| spec.add_development_dependency 'bundler', '~> 2.0', '>= 2.0.2' spec.add_development_dependency 'rake', '~> 12.0' spec.add_development_dependency 'rspec', '~> 3.0' + spec.add_development_dependency 'rubocop', '~> 1.0' spec.add_development_dependency 'pry-byebug', '~> 3.4' spec.add_development_dependency 'simplecov' spec.add_development_dependency 'simplecov-cobertura' diff --git a/spec/sidekiq-instrument/client_middleware_spec.rb b/spec/sidekiq-instrument/client_middleware_spec.rb index da8c518..46665b5 100644 --- a/spec/sidekiq-instrument/client_middleware_spec.rb +++ b/spec/sidekiq-instrument/client_middleware_spec.rb @@ -1,7 +1,13 @@ +# frozen_string_literal: true + require 'sidekiq/instrument/middleware/client' RSpec.describe Sidekiq::Instrument::ClientMiddleware do describe '#call' do + let(:worker_metric_name) do + 'sidekiq_instrument_trace_workers::in_queue' + end + before(:all) do Sidekiq.configure_client do |c| c.client_middleware do |chain| @@ -10,6 +16,10 @@ end end + before(:each) do + Redis.new.flushall + end + after(:all) do Sidekiq.configure_client do |c| c.client_middleware do |chain| @@ -20,50 +30,34 @@ context 'without statsd_metric_name' do it 'increments the StatsD enqueue counter' do - expect { + expect do MyWorker.perform_async - }.to trigger_statsd_increment('shared.sidekiq.default.MyWorker.enqueue') + end.to trigger_statsd_increment('shared.sidekiq.default.MyWorker.enqueue') end it 'increments the DogStatsD enqueue counter' do - expect(Sidekiq::Instrument::Statter.dogstatsd).to receive(:increment).with('sidekiq.enqueue', { tags: ['queue:default', 'worker:my_worker'] }).once + expect( + Sidekiq::Instrument::Statter.dogstatsd + ).to receive(:increment).with('sidekiq.enqueue', { tags: ['queue:default', 'worker:my_worker'] }).once MyWorker.perform_async end end context 'with statsd_metric_name' do it 'increments the enqueue counter' do - expect { + expect do MyOtherWorker.perform_async - }.to trigger_statsd_increment('my_other_worker.enqueue') + end.to trigger_statsd_increment('my_other_worker.enqueue') end end context 'with WorkerMetrics.enabled true' do - let(:worker_metric_name) do - "sidekiq_instrument_trace_workers::in_queue" - end - it 'increments the enqueue counter' do - Sidekiq::Instrument::WorkerMetrics.enabled = true - Redis.new.hdel worker_metric_name ,'my_other_worker' - MyOtherWorker.perform_async - expect( - Redis.new.hget worker_metric_name ,'my_other_worker' - ).to eq('1') - end - end - - context 'with WorkerMetrics.enabled true and redis_config not provided' do - let(:worker_metric_name) do - "sidekiq_instrument_trace_workers::in_queue" - end - it 'increments the enqueue counter' do - Sidekiq::Instrument::WorkerMetrics.enabled = true - Redis.new.hdel worker_metric_name ,'my_other_worker' - MyOtherWorker.perform_async - expect( - Redis.new.hget worker_metric_name ,'my_other_worker' - ).to eq('1') + it 'increments the in_queue counter' do + Sidekiq::Instrument::WorkerMetrics.enabled = true + MyOtherWorker.perform_async + expect(Redis.new.hget(worker_metric_name, 'my_other_worker')).to eq('1') + MyOtherWorker.perform_async + expect(Redis.new.hget(worker_metric_name, 'my_other_worker')).to eq('2') end end diff --git a/spec/sidekiq-instrument/server_middleware_spec.rb b/spec/sidekiq-instrument/server_middleware_spec.rb index 9dfc709..8e15680 100644 --- a/spec/sidekiq-instrument/server_middleware_spec.rb +++ b/spec/sidekiq-instrument/server_middleware_spec.rb @@ -1,8 +1,13 @@ +# frozen_string_literal: true + require 'sidekiq/instrument/middleware/server' RSpec.describe Sidekiq::Instrument::ServerMiddleware do describe '#call' do let(:expected_dog_options) { { tags: ['queue:default', 'worker:my_worker'] } } + let(:worker_metric_name) do + 'sidekiq_instrument_trace_workers::in_queue' + end before(:all) do Sidekiq::Testing.server_middleware do |chain| @@ -10,6 +15,10 @@ end end + before(:each) do + Redis.new.flushall + end + after(:all) do Sidekiq::Testing.server_middleware do |chain| chain.remove described_class @@ -18,20 +27,22 @@ context 'when a job succeeds' do it 'increments StatsD dequeue counter' do - expect { + expect do MyWorker.perform_async - }.to trigger_statsd_increment('shared.sidekiq.default.MyWorker.dequeue') + end.to trigger_statsd_increment('shared.sidekiq.default.MyWorker.dequeue') end it 'increments DogStatsD dequeue counter' do - expect(Sidekiq::Instrument::Statter.dogstatsd).to receive(:increment).with('sidekiq.dequeue', expected_dog_options).once + expect( + Sidekiq::Instrument::Statter.dogstatsd + ).to receive(:increment).with('sidekiq.dequeue', expected_dog_options).once MyWorker.perform_async end it 'measures StatsD job runtime' do - expect { + expect do MyWorker.perform_async - }.to trigger_statsd_measure('shared.sidekiq.default.MyWorker.runtime') + end.to trigger_statsd_measure('shared.sidekiq.default.MyWorker.runtime') end it 'measures DogStatsD job runtime' do @@ -40,53 +51,72 @@ end context 'with WorkerMetrics.enabled true' do - let(:worker_metric_name) do - "sidekiq_instrument_trace_workers::in_queue" - end - it 'increments the enqueue counter' do - Sidekiq::Instrument::WorkerMetrics.enabled = true - Redis.new.hdel worker_metric_name ,'my_other_worker' - MyOtherWorker.perform_async - expect( - Redis.new.hget worker_metric_name ,'my_other_worker' - ).to eq('-1') + it 'decrements the in_queue counter' do + Sidekiq::Instrument::WorkerMetrics.enabled = true + Redis.new.hdel(worker_metric_name, 'my_other_worker') + MyOtherWorker.perform_async + expect(Redis.new.hget(worker_metric_name, 'my_other_worker')).to eq('-1') end end - context 'with WorkerMetrics.enabled true, and redis_config not given' do - let(:worker_metric_name) do - "sidekiq_instrument_trace_workers::in_queue" - end - it 'increments the enqueue counter' do - Sidekiq::Instrument::WorkerMetrics.enabled = true - Redis.new.hdel worker_metric_name ,'my_other_worker' + context 'with WorkerMetrics.enabled true and an errored job' do + it 'decrements the in_queue counter' do + Sidekiq::Instrument::WorkerMetrics.enabled = true + MyOtherWorker.perform_async + expect(Redis.new.hget(worker_metric_name, 'my_other_worker')).to eq('-1') + begin MyOtherWorker.perform_async - expect( - Redis.new.hget worker_metric_name ,'my_other_worker' - ).to eq('-1') + rescue StandardError + nil + end + expect(Redis.new.hget(worker_metric_name, 'my_other_worker')).to eq('-2') end end end context 'when a job fails' do - before { allow_any_instance_of(MyWorker).to receive(:perform).and_raise('foo') } + before do + allow_any_instance_of(MyWorker).to receive(:perform).and_raise('foo') + end it 'increments the StatsD failure counter' do - expect { - MyWorker.perform_async rescue nil - }.to trigger_statsd_increment('shared.sidekiq.default.MyWorker.error') + expect do + MyWorker.perform_async + rescue StandardError + nil + end.to trigger_statsd_increment('shared.sidekiq.default.MyWorker.error') end it 'increments the DogStatsD failure counter' do - expect(Sidekiq::Instrument::Statter.dogstatsd).to receive(:increment).with('sidekiq.dequeue', expected_dog_options).once + expect( + Sidekiq::Instrument::Statter.dogstatsd + ).to receive(:increment).with('sidekiq.dequeue', expected_dog_options).once expect(Sidekiq::Instrument::Statter.dogstatsd).not_to receive(:time) - expect(Sidekiq::Instrument::Statter.dogstatsd).to receive(:increment).with('sidekiq.error', expected_dog_options).once - MyWorker.perform_async rescue nil + expect( + Sidekiq::Instrument::Statter.dogstatsd + ).to receive(:increment).with('sidekiq.error', expected_dog_options).once + + begin + MyWorker.perform_async + rescue StandardError + nil + end end it 're-raises the error' do expect { MyWorker.perform_async }.to raise_error 'foo' end + + it 'calls the decrement counter' do + expect( + Sidekiq::Instrument::WorkerMetrics + ).to receive(:trace_workers_decrement_counter).with('my_worker').once + begin + MyWorker.perform_async + rescue StandardError + nil + end + end end context 'without optional DogStatsD client' do diff --git a/spec/sidekiq-instrument/worker_spec.rb b/spec/sidekiq-instrument/worker_spec.rb index 474f822..10ab5ce 100644 --- a/spec/sidekiq-instrument/worker_spec.rb +++ b/spec/sidekiq-instrument/worker_spec.rb @@ -1,15 +1,19 @@ +# frozen_string_literal: true + require 'sidekiq/instrument/worker' RSpec.describe Sidekiq::Instrument::Worker do + let(:worker_metric_name) do + 'sidekiq_instrument_trace_workers::in_queue' + end + describe '#perform' do let(:worker) { described_class.new } - let(:worker_metric_name) do - "sidekiq_instrument_trace_workers::in_queue" - end + before do - Redis.new.hdel worker_metric_name ,'my_other_worker' - Redis.new.hdel worker_metric_name ,'my_worker' + Redis.new.hdel worker_metric_name, 'my_worker' end + shared_examples 'worker behavior' do |expected_stats| it 'triggers the correct default gauges' do expect { worker.perform }.to trigger_statsd_gauge('shared.sidekiq.stats.processed') @@ -33,7 +37,7 @@ allow(dogstatsd).to receive(:gauge).with('sidekiq.queue.size', any_args).at_least(:once) allow(dogstatsd).to receive(:gauge).with('sidekiq.queue.latency', any_args).at_least(:once) expected_stats.each do |ex| - if ex.include?('shared.sidekiq.worker_metrics.inqueue') + if ex.include?('shared.sidekiq.worker_metrics.in_queue') expect(dogstatsd).to receive(:gauge).with(ex, anything, anything) else expect(dogstatsd).to receive(:gauge).with(ex, anything) @@ -76,6 +80,7 @@ end end end + context 'when WorkerMetrics disabled' do before do Sidekiq::Instrument::WorkerMetrics.enabled = false @@ -98,7 +103,7 @@ end end - MyOtherWorker.perform_async + MyWorker.perform_async Sidekiq.configure_client do |c| c.client_middleware do |chain| @@ -108,7 +113,7 @@ end it_behaves_like 'worker behavior', %w[ - shared.sidekiq.worker_metrics.inqueue + shared.sidekiq.worker_metrics.in_queue sidekiq.processed sidekiq.workers sidekiq.pending @@ -117,4 +122,100 @@ ] end end + + describe 'client & server middleware' do + before(:each) do + Redis.new.flushall + Sidekiq.configure_client do |c| + c.client_middleware do |chain| + chain.add Sidekiq::Instrument::ClientMiddleware + end + end + end + + after(:each) do + Sidekiq.configure_client do |c| + c.client_middleware do |chain| + chain.remove Sidekiq::Instrument::ClientMiddleware + end + end + end + + context 'successful increment' do + let(:expected_dog_options) { { tags: ['queue:default', 'worker:my_worker'] } } + + before do + Sidekiq.server_middleware do |chain| + chain.add Sidekiq::Instrument::ServerMiddleware + end + end + + after do + Sidekiq.server_middleware do |chain| + chain.remove Sidekiq::Instrument::ServerMiddleware + end + end + + it 'increments the in_queue counter' do + Sidekiq::Instrument::WorkerMetrics.enabled = true + redis = Redis.new + expect(redis.hget(worker_metric_name, 'my_worker')).to be nil + MyWorker.perform_async + expect(redis.hget(worker_metric_name, 'my_worker')).to eq('1') + MyWorker.perform_async + expect(redis.hget(worker_metric_name, 'my_worker')).to eq('2') + end + + it 'increments the DogStatsD failure counter' do + expect( + Sidekiq::Instrument::Statter.dogstatsd + ).to receive(:increment).with('sidekiq.enqueue', expected_dog_options).once + expect(Sidekiq::Instrument::Statter.dogstatsd).not_to receive(:time) + begin + MyWorker.perform_async + rescue StandardError + nil + end + end + end + + context 'errored decrement' do + before do + allow_any_instance_of(MyWorker).to receive(:perform_async).and_raise(StandardError) + Sidekiq::Testing.server_middleware do |chain| + chain.add Sidekiq::Instrument::ServerMiddleware + end + end + + after do + Sidekiq::Testing.server_middleware do |chain| + chain.remove Sidekiq::Instrument::ServerMiddleware + end + end + + it 'does not increment the in queue counter' do + Sidekiq::Instrument::WorkerMetrics.enabled = true + redis = Redis.new + expect(redis.hget(worker_metric_name, 'my_worker')).to be nil + MyWorker.perform_async + expect(redis.hget(worker_metric_name, 'my_worker')).to eq('0') + MyWorker.perform_async + expect(redis.hget(worker_metric_name, 'my_worker')).to eq('0') + redis.hincrby(worker_metric_name, 'my_worker', 1) + MyWorker.perform_async + expect(redis.hget(worker_metric_name, 'my_worker')).to eq('1') + end + + it 'calls the decrement counter' do + expect( + Sidekiq::Instrument::WorkerMetrics + ).to receive(:trace_workers_decrement_counter).with('my_worker').once + begin + MyWorker.perform_async + rescue StandardError + nil + end + end + end + end end