From ebe29d4496bc84e600b89934f6b368b7e4192555 Mon Sep 17 00:00:00 2001 From: Peter Solnica Date: Tue, 13 Oct 2026 10:03:48 +0000 Subject: [PATCH 1/4] refactor: share queue consumer instrumentation --- sentry-rails/lib/sentry/rails/active_job.rb | 175 +++------ .../tracing/trace_propagation.rb | 16 + sentry-ruby/lib/sentry/job_extensions.rb | 2 + .../lib/sentry/job_extensions/consumer.rb | 125 +++++++ .../sentry/job_extensions/instrumentation.rb | 39 ++ .../sentry/job_extensions/consumer_spec.rb | 332 ++++++++++++++++++ .../lib/sentry/sidekiq/error_handler.rb | 12 +- .../sidekiq/sentry_context_middleware.rb | 81 ++--- .../sidekiq/sentry_context_middleware_spec.rb | 32 ++ sentry-sidekiq/spec/sentry/sidekiq_spec.rb | 12 + 10 files changed, 644 insertions(+), 182 deletions(-) create mode 100644 sentry-ruby/lib/sentry/job_extensions/consumer.rb create mode 100644 sentry-ruby/lib/sentry/job_extensions/instrumentation.rb create mode 100644 sentry-ruby/spec/sentry/job_extensions/consumer_spec.rb diff --git a/sentry-rails/lib/sentry/rails/active_job.rb b/sentry-rails/lib/sentry/rails/active_job.rb index 49fd6433c..eb3786b0d 100644 --- a/sentry-rails/lib/sentry/rails/active_job.rb +++ b/sentry-rails/lib/sentry/rails/active_job.rb @@ -76,7 +76,6 @@ def already_supported_by_sentry_integration? end class SentryReporter - OP_NAME = "queue.process" SPAN_ORIGIN = "auto.queue.active_job" # Emitted as messaging.system when the configured queue adapter's @@ -99,6 +98,10 @@ class SentryReporter class << self include ErrorReporterContext + def consumer + @consumer ||= Sentry::JobExtensions::Consumer.new(integration: Sentry::Rails, origin: SPAN_ORIGIN) + end + def job_extensions @job_extensions ||= Sentry.job_extensions end @@ -157,6 +160,20 @@ def record_producer_span(job, &enqueue) end end + def retry_count(job) + if (info = call_hook(job, :retry_info)) + info[:count] + elsif job.respond_to?(:executions) + job.executions.to_i + end + end + + def set_extension_messaging_data(span, job) + call_hook(job, :messaging_data).each do |key, value| + span.set_data(MESSAGING_DATA_ATTRIBUTES.fetch(key), value) + end + end + def log_producer_span_error(e) Sentry.sdk_logger&.error("sentry-rails: failed to record producer span: #{e.class}: #{e.message}\n #{Array(e.backtrace).first(5).join("\n ")}") end @@ -169,9 +186,9 @@ def record(job, trace_headers: nil, user: nil, payload: nil, &block) begin scope.set_user(user.transform_keys(&:to_sym)) if user && !user.empty? - apply_extension_scope_data(scope, job) + consumer.apply_scope_data(scope, job) - scope.set_transaction_name(call_hook(job, :transaction_name) || job.class.name, source: :task) + scope.set_transaction_name(consumer.transaction_name(job) || job.class.name, source: :task) scope.set_tags(queue: job.queue_name) scope.set_contexts(active_job: { @@ -181,42 +198,28 @@ def record(job, trace_headers: nil, user: nil, payload: nil, &block) provider_job_id: job.provider_job_id }) - transaction_options = { - name: scope.transaction_name, - source: scope.transaction_source, - op: OP_NAME, - origin: call_hook(job, :span_origin) || SPAN_ORIGIN - } - - extracted_trace = false - if (trace_headers.nil? || trace_headers.empty?) && payload - extracted_headers = call_hook(job, :extract_trace_headers, payload: payload) - unless extracted_headers.nil? - trace_headers = extracted_headers - extracted_trace = true - end - end - - transaction = if extracted_trace || (trace_headers && !trace_headers.empty?) - continued = Sentry.continue_trace(trace_headers, **transaction_options) - Sentry.start_transaction(transaction: continued, **transaction_options) - else - Sentry.start_transaction(**transaction_options) - end - - if transaction - set_messaging_data(transaction, job) - set_extension_messaging_data(transaction, job) - scope.set_span(transaction) - end + transaction = consumer.start_transaction( + scope, job, + trace_headers: trace_headers, + payload: payload, + messaging_data: -> { + { + system: messaging_system(job), + message_id: job.job_id, + destination: job.queue_name, + receive_latency: compute_latency(job) + } + }, + default_retry_count: executions(job) + ) yield.tap do - finish_sentry_transaction(transaction, 200) + consumer.finish_transaction(transaction, 200) end rescue Exception => e # rubocop:disable Lint/RescueException - finish_sentry_transaction(transaction, 500) + consumer.finish_transaction(transaction, 500) - capture_exception(job, e) if report_exception?(job, e) + capture_exception(job, e) if consumer.report_exception?(job, e) raise end @@ -225,33 +228,6 @@ def record(job, trace_headers: nil, user: nil, payload: nil, &block) Sentry.set_current_hub_internal(original_hub) end - def set_messaging_data(transaction, job) - transaction.set_data(Sentry::Span::DataConventions::MESSAGING_SYSTEM, messaging_system(job)) - transaction.set_data(Sentry::Span::DataConventions::MESSAGING_MESSAGE_ID, job.job_id) - transaction.set_data(Sentry::Span::DataConventions::MESSAGING_DESTINATION_NAME, job.queue_name) - if (count = retry_count(job)) - transaction.set_data(Sentry::Span::DataConventions::MESSAGING_MESSAGE_RETRY_COUNT, count) - end - - if (latency = compute_latency(job)) - transaction.set_data(Sentry::Span::DataConventions::MESSAGING_MESSAGE_RECEIVE_LATENCY, latency) - end - end - - def apply_extension_scope_data(scope, job) - data = call_hook(job, :scope_data) - scope.set_contexts(data[:contexts]) if data[:contexts] - scope.set_tags(data[:tags]) if data[:tags] - scope.set_extras(data[:extra]) if data[:extra] - scope.set_user(data[:user]) if data[:user] - end - - def set_extension_messaging_data(span, job) - call_hook(job, :messaging_data).each do |key, value| - span.set_data(MESSAGING_DATA_ATTRIBUTES.fetch(key), value) - end - end - def messaging_system(job) name = job.class.queue_adapter_name if job.class.respond_to?(:queue_adapter_name) name = name.to_s @@ -264,27 +240,8 @@ def messaging_system(job) # its first retry reads 1, and so on. On the producer the retry enqueue # runs after the failed attempt bumped +executions+, so it observes the # same progression. - def retry_count(job) - if (info = call_hook(job, :retry_info)) - info[:count] - elsif job.respond_to?(:executions) - job.executions.to_i - end - end - - def backend_will_retry?(job) - info = call_hook(job, :retry_info) - info ? info[:will_retry] : false - end - - def report_exception?(job, exception) - decision = call_hook(job, :report_exception?, exception: exception) - decision.nil? ? !backend_will_retry?(job) : decision - end - - def report_retried_exception?(job, exception) - decision = call_hook(job, :report_retried_exception?, exception: exception) - decision.nil? ? Sentry.configuration.rails.active_job_report_on_retry_error : decision + def executions(job) + job.executions.to_i if job.respond_to?(:executions) end def compute_latency(job) @@ -295,49 +252,14 @@ def compute_latency(job) end def capture_exception(job, e) - error_data = additive_error_data( - call_hook(job, :error_data, exception: e) + consumer.capture_exception( + job, e, + contexts: Sentry.configuration.data_collection.queues ? execution_context : {}, + tags: { job_id: job.job_id, provider_job_id: job.provider_job_id }, + extra: sentry_context(job) ) - - options = { - extra: error_data[:extra].merge(sentry_context(job)), - tags: error_data[:tags].merge( - job_id: job.job_id, - provider_job_id: job.provider_job_id - ), - # Send synchronously: a worker process may exit before the async - # background worker flushes its queue, which would drop the event. - hint: { background: false } - } - - contexts = error_data[:contexts] - contexts = contexts.merge(matching_keys(execution_context, contexts)) if Sentry.configuration.data_collection.queues - options[:contexts] = contexts if Sentry.configuration.data_collection.queues || !contexts.empty? - - integration = call_hook(job, :integration) || Sentry::Rails - integration.capture_exception(e, **options) end - def additive_error_data(data) - scope = Sentry.get_current_scope - - { - contexts: matching_keys(data.fetch(:contexts, {}), scope.contexts).to_h do |name, context| - scope_context = scope.contexts.fetch(name, {}) - context = matching_keys(context, scope_context) - [name, context.merge(scope_context)] - end, - tags: matching_keys(data.fetch(:tags, {}), scope.tags).reject { |key, _value| scope.tags.key?(key) }, - extra: matching_keys(data.fetch(:extra, {}), scope.extra).reject { |key, _value| scope.extra.key?(key) } - } - end - - def matching_keys(data, reference) - keys = reference.keys.to_h { |key| [key.to_s, key] } - data.transform_keys { |key| keys.fetch(key.to_s, key) } - end - - def register_event_handlers EVENT_HANDLERS.each do |name, handler| subscribers << ActiveSupport::Notifications.subscribe(name) do |*args| @@ -358,7 +280,7 @@ def retry_handler(*args) handle_error_event(*args) do |job, error| return if error.nil? return if !Sentry.initialized? || job.already_supported_by_sentry_integration? - return unless report_retried_exception?(job, error) + return unless consumer.report_retried_exception?(job, error, default: Sentry.configuration.rails.active_job_report_on_retry_error) capture_exception(job, error) end @@ -369,13 +291,6 @@ def handle_error_event(*args) yield(event.payload[:job], event.payload[:error]) end - def finish_sentry_transaction(transaction, status) - return unless transaction - - transaction.set_http_status(status) - transaction.finish - end - def sentry_context(job) context = { active_job: job.class.name, diff --git a/sentry-rails/spec/active_job/shared_examples/tracing/trace_propagation.rb b/sentry-rails/spec/active_job/shared_examples/tracing/trace_propagation.rb index 570ae87ac..1a3891af1 100644 --- a/sentry-rails/spec/active_job/shared_examples/tracing/trace_propagation.rb +++ b/sentry-rails/spec/active_job/shared_examples/tracing/trace_propagation.rb @@ -98,4 +98,20 @@ expect(publish_span[:origin]).to eq("auto.queue.active_job") end end + + context "when tracing is disabled and the job carries no trace headers" do + let(:configure_sentry) { proc { |config| config.rails.active_job_propagate_traces = false } } + + it "keeps the worker's trace on the captured error event" do + worker_trace_id = Sentry.get_main_hub.current_scope.propagation_context.trace_id + + expect do + failing_job.perform_later + drain + end.to raise_error(RuntimeError, /boom from failing_job spec/) + + error_event = sentry_events.find { |e| e.is_a?(Sentry::ErrorEvent) } + expect(error_event.contexts.dig(:trace, :trace_id)).to eq(worker_trace_id) + end + end end diff --git a/sentry-ruby/lib/sentry/job_extensions.rb b/sentry-ruby/lib/sentry/job_extensions.rb index de3b1bfcc..e20ba7b36 100644 --- a/sentry-ruby/lib/sentry/job_extensions.rb +++ b/sentry-ruby/lib/sentry/job_extensions.rb @@ -4,3 +4,5 @@ require "sentry/job_extensions/hooks" require "sentry/job_extensions/extension" require "sentry/job_extensions/registry" +require "sentry/job_extensions/instrumentation" +require "sentry/job_extensions/consumer" diff --git a/sentry-ruby/lib/sentry/job_extensions/consumer.rb b/sentry-ruby/lib/sentry/job_extensions/consumer.rb new file mode 100644 index 000000000..802372264 --- /dev/null +++ b/sentry-ruby/lib/sentry/job_extensions/consumer.rb @@ -0,0 +1,125 @@ +# frozen_string_literal: true + +module Sentry + module JobExtensions + # @api private + class Consumer < Instrumentation + OP_NAME = "queue.process" + + attr_reader :integration, :origin + + def initialize(integration:, origin:, registry: Sentry.job_extensions) + super(registry: registry) + @integration = integration + @origin = origin + end + + def apply_scope_data(scope, job) + data = registry.call(registry.for(job), :scope_data, job: job) + scope.set_contexts(data[:contexts]) if data[:contexts] + scope.set_tags(data[:tags]) if data[:tags] + scope.set_extras(data[:extra]) if data[:extra] + scope.set_user(data[:user]) if data[:user] + end + + def transaction_name(job) + registry.call(registry.for(job), :transaction_name, job: job) + end + + def start_transaction(scope, job, trace_headers: nil, payload: nil, always_continue_trace: false, messaging_data: {}, default_retry_count: nil) + extension = registry.for(job) + options = { + name: scope.transaction_name, + source: scope.transaction_source, + op: OP_NAME, + origin: registry.call(extension, :span_origin, job: job) || origin + } + + if (trace_headers.nil? || trace_headers.empty?) && payload + extracted_headers = registry.call(extension, :extract_trace_headers, job: job, payload: payload) + + unless extracted_headers.nil? + trace_headers = extracted_headers + always_continue_trace = true + end + end + + transaction = if always_continue_trace || (trace_headers && !trace_headers.empty?) + continued = Sentry.continue_trace(trace_headers, **options) + Sentry.start_transaction(transaction: continued, **options) + else + Sentry.start_transaction(**options) + end + return unless transaction + + set_messaging_data(transaction, resolve(messaging_data).reject { |_key, value| value.nil? }) + set_messaging_data(transaction, registry.call(extension, :messaging_data, job: job)) + set_retry_count(transaction, extension, job, default: default_retry_count) + + scope.set_span(transaction) + transaction + end + + def finish_transaction(transaction, status) + return unless transaction + + transaction.set_http_status(status) + transaction.finish + end + + def will_retry?(job) + info = registry.call(registry.for(job), :retry_info, job: job) + info ? info[:will_retry] : false + end + + def report_exception?(job, exception) + decision = registry.call(registry.for(job), :report_exception?, job: job, exception: exception) + decision.nil? ? !will_retry?(job) : decision + end + + def report_retried_exception?(job, exception, default:) + decision = registry.call(registry.for(job), :report_retried_exception?, job: job, exception: exception) + decision.nil? ? default : decision + end + + def capture_exception(job, exception, contexts: {}, tags: {}, extra: {}) + extension = registry.for(job) + error_data = additive_error_data( + registry.call(extension, :error_data, job: job, exception: exception) + ) + + options = { + extra: error_data[:extra].merge(extra), + tags: error_data[:tags].merge(tags), + hint: { background: false } + } + contexts = error_data[:contexts].merge(matching_keys(contexts, error_data[:contexts])) + options[:contexts] = contexts unless contexts.empty? + + capturing_integration = registry.call(extension, :integration, job: job) || integration + capturing_integration.capture_exception(exception, **options) + end + + private + + def additive_error_data(data) + scope = Sentry.get_current_scope + + { + contexts: matching_keys(data.fetch(:contexts, {}), scope.contexts).to_h do |name, context| + scope_context = scope.contexts.fetch(name, {}) + context = matching_keys(context, scope_context) + [name, context.merge(scope_context)] + end, + tags: matching_keys(data.fetch(:tags, {}), scope.tags).reject { |key, _value| scope.tags.key?(key) }, + extra: matching_keys(data.fetch(:extra, {}), scope.extra).reject { |key, _value| scope.extra.key?(key) } + } + end + + def matching_keys(data, reference) + keys = reference.keys.to_h { |key| [key.to_s, key] } + data.transform_keys { |key| keys.fetch(key.to_s, key) } + end + end + end +end diff --git a/sentry-ruby/lib/sentry/job_extensions/instrumentation.rb b/sentry-ruby/lib/sentry/job_extensions/instrumentation.rb new file mode 100644 index 000000000..736fb1f67 --- /dev/null +++ b/sentry-ruby/lib/sentry/job_extensions/instrumentation.rb @@ -0,0 +1,39 @@ +# frozen_string_literal: true + +module Sentry + module JobExtensions + # @api private + class Instrumentation + MESSAGING_DATA_ATTRIBUTES = { + system: Span::DataConventions::MESSAGING_SYSTEM, + message_id: Span::DataConventions::MESSAGING_MESSAGE_ID, + destination: Span::DataConventions::MESSAGING_DESTINATION_NAME, + receive_latency: Span::DataConventions::MESSAGING_MESSAGE_RECEIVE_LATENCY + }.freeze + + attr_reader :registry + + def initialize(registry: Sentry.job_extensions) + @registry = registry + end + + private + + def set_messaging_data(span, data) + data.each do |key, value| + span.set_data(MESSAGING_DATA_ATTRIBUTES.fetch(key), value) + end + end + + def set_retry_count(span, extension, job, default: nil) + info = registry.call(extension, :retry_info, job: job) + count = info ? info[:count] : default + span.set_data(Span::DataConventions::MESSAGING_MESSAGE_RETRY_COUNT, count) if count + end + + def resolve(value) + value.respond_to?(:call) ? value.call : value + end + end + end +end diff --git a/sentry-ruby/spec/sentry/job_extensions/consumer_spec.rb b/sentry-ruby/spec/sentry/job_extensions/consumer_spec.rb new file mode 100644 index 000000000..d2c20ab4a --- /dev/null +++ b/sentry-ruby/spec/sentry/job_extensions/consumer_spec.rb @@ -0,0 +1,332 @@ +# frozen_string_literal: true + +require "sentry/integrable" + +module Sentry + module TestJobsIntegration + extend Sentry::Integrable + + register_integration name: "test_jobs", version: "1.0" + end +end + +RSpec.describe Sentry::JobExtensions::Consumer do + let(:job) { Struct.new(:id, :queue).new("job-1", "critical") } + let(:integration) { Sentry::TestJobsIntegration } + let(:string_io) { StringIO.new } + + def consumer(**hooks) + registry = Sentry::JobExtensions::Registry.new + registry.register( + Class.new(Sentry::JobExtensions::Extension) do + define_method(:handles?) { |_job| true } + hooks.each { |hook, body| define_method(hook, &body) } + end.new(name: "test_backend") + ) + described_class.new(integration: integration, origin: "auto.queue.test", registry: registry) + end + + def scope + Sentry.get_current_scope + end + + def start_transaction(consumer, **options) + scope.set_transaction_name("TestJob", source: :task) + consumer.start_transaction(scope, job, **options) + end + + def finished_transaction(consumer, **options) + transaction = start_transaction(consumer, **options) + consumer.finish_transaction(transaction, 200) + sentry_events.last + end + + def capture(consumer, exception = RuntimeError.new("boom"), **options) + consumer.capture_exception(job, exception, **options) + sentry_events.last + end + + def enriching_consumer + consumer( + messaging_data: ->(job:) { { system: "backend", message_id: job.id, destination: job.queue, receive_latency: 42.5 } }, + retry_info: ->(job:) { { count: 3, will_retry: true } }, + scope_data: ->(job:) { { contexts: { backend: { "jid" => "backend-jid" } }, tags: { "backend.queue" => "low" }, extra: { size: 12 } } } + ) + end + + let(:foreign_trace_id) { "a" * 32 } + let(:foreign_trace_headers) { { "sentry-trace" => "#{foreign_trace_id}-#{"b" * 16}-1" } } + + before do + perform_basic_setup do |config| + config.traces_sample_rate = 1.0 + config.sdk_logger = Logger.new(string_io) + end + setup_sentry_test + end + + after do + teardown_sentry_test + end + + describe "#start_transaction" do + it "starts a queue.process transaction on the scope named after the scope's transaction" do + transaction = start_transaction(consumer) + + expect(scope.get_span).to eq(transaction) + expect(transaction.op).to eq("queue.process") + expect(transaction.origin).to eq("auto.queue.test") + expect(transaction.name).to eq("TestJob") + expect(transaction.source).to eq(:task) + end + + it "records the extension's messaging data and retry count as span data" do + event = finished_transaction(enriching_consumer) + + expect(event.contexts.dig(:trace, :data)).to include( + "messaging.system" => "backend", + "messaging.message.id" => "job-1", + "messaging.destination.name" => "critical", + "messaging.message.receive.latency" => 42.5, + "messaging.message.retry.count" => 3 + ) + end + + it "lets the extension's messaging data win over the caller's and fills the rest from non-nil caller values" do + partial_consumer = consumer(messaging_data: ->(job:) { { system: "backend", message_id: job.id } }) + + event = finished_transaction( + partial_consumer, + messaging_data: { system: "caller", message_id: "caller-id", destination: "caller-queue", receive_latency: nil } + ) + + data = event.contexts.dig(:trace, :data) + expect(data).to include( + "messaging.system" => "backend", + "messaging.message.id" => "job-1", + "messaging.destination.name" => "caller-queue" + ) + expect(data).not_to have_key("messaging.message.receive.latency") + end + + it "uses the caller's default retry count when the extension reports no retry state" do + expect(finished_transaction(consumer, default_retry_count: 7).contexts.dig(:trace, :data)) + .to include("messaging.message.retry.count" => 7) + end + + it "prefers the extension's retry count over the caller's default" do + expect(finished_transaction(enriching_consumer, default_retry_count: 7).contexts.dig(:trace, :data)) + .to include("messaging.message.retry.count" => 3) + end + + it "records only the caller's data when no registered extension handles the job" do + unhandled = described_class.new(integration: integration, origin: "auto.queue.test", registry: Sentry::JobExtensions::Registry.new) + + event = finished_transaction(unhandled, default_retry_count: 7) + + expect(event.contexts.dig(:trace, :data)).to include("messaging.message.retry.count" => 7) + expect(event.contexts.dig(:trace, :data)).not_to include("messaging.system") + end + + it "continues the trace from the caller's trace headers" do + transaction = start_transaction(consumer, trace_headers: foreign_trace_headers) + + expect(transaction.trace_id).to eq(foreign_trace_id) + end + + it "continues the trace the extension extracts from the payload when the caller has no trace headers" do + transaction = start_transaction(consumer(extract_trace_headers: ->(job:, payload:) { payload["headers"] }), trace_headers: {}, payload: { "headers" => foreign_trace_headers }) + + expect(transaction.trace_id).to eq(foreign_trace_id) + end + + it "prefers the caller's trace headers over the ones the extension extracts" do + transaction = start_transaction(consumer(extract_trace_headers: ->(job:, payload:) { { "sentry-trace" => "#{"c" * 32}-#{"d" * 16}-1" } }), trace_headers: foreign_trace_headers, payload: {}) + + expect(transaction.trace_id).to eq(foreign_trace_id) + end + + it "keeps the scope's trace when there are no trace headers" do + scope_trace_id = scope.propagation_context.trace_id + + start_transaction(consumer) + + expect(scope.propagation_context.trace_id).to eq(scope_trace_id) + end + + it "starts a new trace on the scope without trace headers when told to always continue the trace" do + scope_trace_id = scope.propagation_context.trace_id + + start_transaction(consumer, always_continue_trace: true) + + expect(scope.propagation_context.trace_id).not_to eq(scope_trace_id) + end + + it "starts a new trace on the scope when the extension extracts no trace headers from the payload" do + scope_trace_id = scope.propagation_context.trace_id + + start_transaction(consumer(extract_trace_headers: ->(job:, payload:) { {} }), payload: {}) + + expect(scope.propagation_context.trace_id).not_to eq(scope_trace_id) + end + + it "returns nil when tracing is disabled" do + Sentry.configuration.traces_sample_rate = nil + + expect(start_transaction(enriching_consumer)).to be_nil + end + + { + "raise" => ->(**) { raise "hook exploded" }, + "return malformed data" => ->(**) { "malformed" } + }.each do |behavior, body| + it "starts the transaction without extension data when the hooks #{behavior}" do + event = finished_transaction(consumer(messaging_data: body, retry_info: body, extract_trace_headers: body), payload: {}) + + expect(event.contexts.dig(:trace, :status)).to eq("ok") + expect(event.contexts.dig(:trace, :data).keys.grep(/\Amessaging\./)).to be_empty + expect(string_io.string).to include("test_backend") + end + end + end + + describe "#finish_transaction" do + it "finishes the transaction with the status for the given HTTP status code" do + started = consumer + transaction = start_transaction(started) + + started.finish_transaction(transaction, 500) + + expect(sentry_events.last.contexts.dig(:trace, :status)).to eq("internal_error") + end + + it "ignores a missing transaction" do + expect { consumer.finish_transaction(nil, 200) }.not_to raise_error + end + end + + describe "#apply_scope_data" do + it "adds the extension's contexts, tags and extra to the scope" do + enriching_consumer.apply_scope_data(scope, job) + + expect(scope.contexts[:backend]).to eq("jid" => "backend-jid") + expect(scope.tags).to include("backend.queue" => "low") + expect(scope.extra).to include(size: 12) + end + + it "sets the user the extension supplies on the scope" do + consumer(scope_data: ->(job:) { { user: { "id" => "42", "segment" => "beta" } } }).apply_scope_data(scope, job) + + expect(scope.user).to eq("id" => "42", "segment" => "beta") + end + + it "leaves the scope unchanged when the hook fails" do + consumer(scope_data: ->(job:) { raise "boom" }).apply_scope_data(scope, job) + + expect(scope.tags).to be_empty + expect(scope.extra).to be_empty + end + end + + describe "#will_retry?" do + it "reports whether the extension says the backend will retry the job" do + expect(enriching_consumer.will_retry?(job)).to be(true) + expect(consumer(retry_info: ->(job:) { { count: 3, will_retry: false } }).will_retry?(job)).to be(false) + end + + it "reports no retry when the backend's retry state is unknown" do + expect(consumer.will_retry?(job)).to be(false) + expect(consumer(retry_info: ->(job:) { "malformed" }).will_retry?(job)).to be(false) + end + end + + describe "#report_exception?" do + let(:exception) { RuntimeError.new("boom") } + + it "follows the extension's decision whether the backend will retry the job or not" do + reporting = consumer(report_exception?: ->(job:, exception:) { true }, retry_info: ->(job:) { { count: 0, will_retry: true } }) + silent = consumer(report_exception?: ->(job:, exception:) { false }, retry_info: ->(job:) { { count: 0, will_retry: false } }) + + expect(reporting.report_exception?(job, exception)).to be(true) + expect(silent.report_exception?(job, exception)).to be(false) + end + + it "reports only failures the backend will not retry when the extension does not decide" do + expect(consumer.report_exception?(job, exception)).to be(true) + expect(enriching_consumer.report_exception?(job, exception)).to be(false) + end + + { + "raises" => ->(**) { raise "hook exploded" }, + "returns malformed data" => ->(**) { "yes" } + }.each do |behavior, body| + it "falls back to the backend's retry state when the hook #{behavior}" do + expect(consumer(report_exception?: body, retry_info: ->(job:) { { count: 0, will_retry: true } }).report_exception?(job, exception)).to be(false) + expect(string_io.string).to include("test_backend") + end + end + end + + describe "#capture_exception" do + def error_consumer + consumer( + error_data: lambda do |job:, exception:| + { + contexts: { backend_error: { "retried" => true }, job: { "id" => "backend", "attempt" => 2 } }, + tags: { "backend.error" => "yes", queue: "backend-queue", job_id: "backend" }, + extra: { attempts: 2, size: 99 } + } + end + ) + end + + it "captures the exception through the integration" do + event = capture(consumer) + + expect(event.exception.values.last.type).to eq("RuntimeError") + expect(event.exception.values.last.mechanism.type).to eq("test_jobs") + expect(event.sdk[:name]).to eq("sentry.ruby.test_jobs") + end + + it "adds the extension's error data without replacing values already on the scope" do + scope.set_contexts(job: { "id" => "scope" }) + scope.set_tags(queue: "default") + scope.set_extras(size: 12) + + event = capture(error_consumer) + + expect(event.contexts[:backend_error]).to eq("retried" => true) + expect(event.contexts[:job]).to eq("id" => "scope", "attempt" => 2) + expect(event.tags).to include("backend.error" => "yes", queue: "default") + expect(event.extra).to include(attempts: 2, size: 12) + end + + it "keeps existing extension and user context values while adding error-specific fields" do + refining_consumer = consumer( + scope_data: ->(job:) { { contexts: { job: { "id" => "backend", "args" => ["raw"] } } } }, + error_data: ->(job:, exception:) { { contexts: { job: { "args" => ["filtered"], "id" => "error", "attempt" => 2 } } } } + ) + refining_consumer.apply_scope_data(scope, job) + scope.set_contexts(job: { "id" => "user" }) + + event = capture(refining_consumer) + + expect(event.contexts[:job]).to eq("id" => "user", "args" => ["raw"], "attempt" => 2) + end + + it "lets the caller's contexts, tags and extra win over the extension's error data" do + event = capture(error_consumer, contexts: { job: { "id" => "caller" } }, tags: { job_id: "caller" }, extra: { attempts: 5 }) + + expect(event.contexts[:job]).to eq("id" => "caller") + expect(event.tags).to include(job_id: "caller", "backend.error" => "yes") + expect(event.extra).to include(attempts: 5) + end + + it "captures the exception with the caller's data when the hook fails" do + event = capture(consumer(error_data: ->(**) { raise "hook exploded" }), tags: { job_id: "caller" }) + + expect(event.exception.values.last.type).to eq("RuntimeError") + expect(event.tags).to eq(job_id: "caller") + end + end +end diff --git a/sentry-sidekiq/lib/sentry/sidekiq/error_handler.rb b/sentry-sidekiq/lib/sentry/sidekiq/error_handler.rb index 0e945cbce..cb24d6789 100644 --- a/sentry-sidekiq/lib/sentry/sidekiq/error_handler.rb +++ b/sentry-sidekiq/lib/sentry/sidekiq/error_handler.rb @@ -2,12 +2,15 @@ require "sentry/sidekiq/context_filter" require "sentry/sidekiq/failure_reporting" +require "sentry/sidekiq/sentry_context_middleware" module Sentry module Sidekiq class ErrorHandler - def initialize(failure_reporting: FailureReporting.new) + def initialize(failure_reporting: FailureReporting.new, consumer: SentryContextServerMiddleware.consumer, job_extension: Sentry::Sidekiq.job_extension) @failure_reporting = failure_reporting + @consumer = consumer + @job_extension = job_extension end # @param ex [Exception] the exception / error that occured @@ -20,14 +23,13 @@ def call(ex, context, sidekiq_config = nil) return unless Sentry.initialized? scope = Sentry.get_current_scope - scope.set_transaction_name(ContextFilter.new(context).transaction_name, source: :task) unless scope.transaction_name + scope.set_transaction_name(@job_extension.error_context_transaction_name(context), source: :task) unless scope.transaction_name job = context[:job] return unless @failure_reporting.report?(job, sidekiq_config) - Sentry::Sidekiq.capture_exception( - ex, - hint: { background: false }, + @consumer.capture_exception( + job, ex, contexts: { sidekiq: ContextFilter.new(context).filtered } ) ensure diff --git a/sentry-sidekiq/lib/sentry/sidekiq/sentry_context_middleware.rb b/sentry-sidekiq/lib/sentry/sidekiq/sentry_context_middleware.rb index 19b40a5e0..8fa3aad7f 100644 --- a/sentry-sidekiq/lib/sentry/sidekiq/sentry_context_middleware.rb +++ b/sentry-sidekiq/lib/sentry/sidekiq/sentry_context_middleware.rb @@ -1,6 +1,6 @@ # frozen_string_literal: true -require "sentry/sidekiq/context_filter" +require "sentry/sidekiq/job_extension" module Sentry module Sidekiq @@ -13,78 +13,65 @@ def set_span_data(span, id:, queue:, latency: nil, retry_count: nil) span.set_data(Span::DataConventions::MESSAGING_MESSAGE_RECEIVE_LATENCY, latency) if latency span.set_data(Span::DataConventions::MESSAGING_MESSAGE_RETRY_COUNT, retry_count) if retry_count end + + if ::Gem::Version.new(::Sidekiq::VERSION) >= ::Gem::Version.new("8.0.0") + def calculate_latency(job) + now_in_ms - job["enqueued_at"] if job["enqueued_at"] + end + else + def calculate_latency(job) + ((Time.now.to_f - job["enqueued_at"]) * 1000).round if job["enqueued_at"] + end + end + + def now_in_ms + ::Process.clock_gettime(::Process::CLOCK_REALTIME, :millisecond) + end end class SentryContextServerMiddleware - include Sentry::Sidekiq::Helpers - - OP_NAME = "queue.process" SPAN_ORIGIN = "auto.queue.sidekiq" + def self.consumer + @consumer ||= Sentry::JobExtensions::Consumer.new(integration: Sentry::Sidekiq, origin: SPAN_ORIGIN) + end + def call(worker, job, queue) return yield unless Sentry.initialized? - context_filter = Sentry::Sidekiq::ContextFilter.new(job) + sidekiq_job = job.merge("queue" => queue) Sentry.clone_hub_to_current_thread scope = Sentry.get_current_scope - if (user = job["sentry_user"]) - scope.set_user(user) - end - scope.set_tags(queue: queue, jid: job["jid"]) - scope.set_tags(build_tags(job["tags"])) - scope.set_contexts(sidekiq: job.merge("queue" => queue)) - scope.set_transaction_name(context_filter.transaction_name, source: :task) - transaction = start_transaction(scope, job["trace_propagation_headers"]) - - if transaction - scope.set_span(transaction) - - latency = Sentry::Sidekiq.job_extension.messaging_data(job: job)[:receive_latency] - - set_span_data( - transaction, - id: job["jid"], - queue: queue, - latency: latency, - retry_count: job["retry_count"] || 0 - ) - end + consumer.apply_scope_data(scope, sidekiq_job) + scope.set_transaction_name(job_extension.transaction_name(job: job), source: :task) + transaction = consumer.start_transaction( + scope, sidekiq_job, + payload: sidekiq_job, + always_continue_trace: true + ) begin yield rescue - finish_transaction(transaction, 500) + consumer.finish_transaction(transaction, 500) raise end - finish_transaction(transaction, 200) + consumer.finish_transaction(transaction, 200) # don't need to use ensure here # if the job failed, we need to keep the scope for error handler. and the scope will be cleared there scope.clear end - def build_tags(tags) - Array(tags).each_with_object({}) { |name, tags_hash| tags_hash[:"sidekiq.#{name}"] = true } - end - - def start_transaction(scope, env) - options = { - name: scope.transaction_name, - source: scope.transaction_source, - op: OP_NAME, - origin: SPAN_ORIGIN - } + private - transaction = Sentry.continue_trace(env, **options) - Sentry.start_transaction(transaction: transaction, **options) + def consumer + self.class.consumer end - def finish_transaction(transaction, status) - return unless transaction - - transaction.set_http_status(status) - transaction.finish + def job_extension + Sentry::Sidekiq.job_extension end end diff --git a/sentry-sidekiq/spec/sentry/sidekiq/sentry_context_middleware_spec.rb b/sentry-sidekiq/spec/sentry/sidekiq/sentry_context_middleware_spec.rb index c1b1a4b62..54e58e463 100644 --- a/sentry-sidekiq/spec/sentry/sidekiq/sentry_context_middleware_spec.rb +++ b/sentry-sidekiq/spec/sentry/sidekiq/sentry_context_middleware_spec.rb @@ -30,6 +30,26 @@ expect(event.user).to eq(user) end + it "starts a new trace for a job without trace propagation headers" do + perform_basic_setup + worker_trace_id = Sentry.get_main_hub.current_scope.propagation_context.trace_id + + execute_worker(processor, SadWorker) + + event = transport.events.last + expect(event.contexts.dig(:trace, :trace_id)).to be_a(String) + expect(event.contexts.dig(:trace, :trace_id)).not_to eq(worker_trace_id) + end + + it "continues the trace from trace propagation headers when tracing is disabled" do + perform_basic_setup + trace_id = "a" * 32 + + execute_worker(processor, SadWorker, trace_propagation_headers: { "sentry-trace" => "#{trace_id}-#{"b" * 16}-1" }) + + expect(transport.events.last.contexts.dig(:trace, :trace_id)).to eq(trace_id) + end + context "with tracing enabled" do before do perform_basic_setup { |config| config.traces_sample_rate = 1.0 } @@ -93,6 +113,18 @@ def timecop_delay expect(trace[:data]['messaging.message.receive.latency']).to be_within(20).of(expected_latency) end + it "does not set messaging.system on the queue.process transaction" do + execute_worker(processor, HappyWorker) + + expect(transport.events[0].contexts.dig(:trace, :data)).not_to have_key('messaging.system') + end + + it "reports the job's retry count on the queue.process transaction" do + execute_worker(processor, HappyWorker, retry_count: 3) + + expect(transport.events[0].contexts.dig(:trace, :data)['messaging.message.retry.count']).to eq(3) + end + if MIN_SIDEKIQ_6 it "does not fail for latency when performed inline" do HappyWorker.perform_inline diff --git a/sentry-sidekiq/spec/sentry/sidekiq_spec.rb b/sentry-sidekiq/spec/sentry/sidekiq_spec.rb index a7b727eb3..54fbf93b6 100644 --- a/sentry-sidekiq/spec/sentry/sidekiq_spec.rb +++ b/sentry-sidekiq/spec/sentry/sidekiq_spec.rb @@ -320,6 +320,18 @@ def retry_last_failed_job expect(event.contexts.dig(:trace, :trace_id)).to eq(transaction.contexts.dig(:trace, :trace_id)) end + it "does not log Sidekiq deprecation warnings while processing a job" do + log = StringIO.new + logger = Logger.new(log) + WITH_SIDEKIQ_7 ? Sidekiq.instance_variable_get(:@config).logger = logger : Sidekiq.logger = logger + + execute_worker(processor, HappyWorker) + + expect(log.string).not_to include("deprecated") + ensure + silence_sidekiq + end + context "with instrumenter :otel" do before do perform_basic_setup do |config| From 7b515f6047d4c0a1fd3ae53f72a593d77e939258 Mon Sep 17 00:00:00 2001 From: Peter Solnica Date: Tue, 13 Oct 2026 10:04:48 +0000 Subject: [PATCH 2/4] refactor: share queue producer instrumentation --- sentry-rails/lib/sentry/rails/active_job.rb | 83 +++------ .../shared_examples/tracing/producer_span.rb | 20 ++ sentry-ruby/lib/sentry/job_extensions.rb | 1 + .../lib/sentry/job_extensions/producer.rb | 66 +++++++ .../sentry/job_extensions/producer_spec.rb | 173 ++++++++++++++++++ .../sidekiq/sentry_context_middleware.rb | 47 ++--- .../sidekiq/sentry_context_middleware_spec.rb | 73 ++++++++ 7 files changed, 371 insertions(+), 92 deletions(-) create mode 100644 sentry-ruby/lib/sentry/job_extensions/producer.rb create mode 100644 sentry-ruby/spec/sentry/job_extensions/producer_spec.rb diff --git a/sentry-rails/lib/sentry/rails/active_job.rb b/sentry-rails/lib/sentry/rails/active_job.rb index eb3786b0d..ef6c0d7b9 100644 --- a/sentry-rails/lib/sentry/rails/active_job.rb +++ b/sentry-rails/lib/sentry/rails/active_job.rb @@ -33,7 +33,7 @@ def perform_now def serialize payload = super return payload if !Sentry.initialized? || already_supported_by_sentry_integration? - return payload if SentryReporter.instrumented_by_extension?(self) + return payload if SentryReporter.producer.instrumented_by_extension?(self) begin sentry_data = {} @@ -41,7 +41,7 @@ def serialize headers = Sentry.get_trace_propagation_headers if headers && !headers.empty? sentry_data["trace_propagation_headers"] = headers - payload = SentryReporter.call_hook(self, :inject_trace_headers, payload: payload, headers: headers) + payload = SentryReporter.producer.inject_trace_headers(self, payload, headers) end end @@ -84,13 +84,6 @@ class SentryReporter # normally derived from the adapter itself; this is only the last resort. MESSAGING_SYSTEM_FALLBACK = "activejob" - MESSAGING_DATA_ATTRIBUTES = { - system: Sentry::Span::DataConventions::MESSAGING_SYSTEM, - message_id: Sentry::Span::DataConventions::MESSAGING_MESSAGE_ID, - destination: Sentry::Span::DataConventions::MESSAGING_DESTINATION_NAME, - receive_latency: Sentry::Span::DataConventions::MESSAGING_MESSAGE_RECEIVE_LATENCY - }.freeze - EVENT_HANDLERS = { "enqueue_retry.active_job" => :retry_handler } @@ -102,6 +95,10 @@ def consumer @consumer ||= Sentry::JobExtensions::Consumer.new(integration: Sentry::Rails, origin: SPAN_ORIGIN) end + def producer + @producer ||= Sentry::JobExtensions::Producer.new(origin: SPAN_ORIGIN) + end + def job_extensions @job_extensions ||= Sentry.job_extensions end @@ -118,60 +115,24 @@ def producer_callback_registered! @producer_callback_registered = true end - def instrumented_by_extension?(job) - call_hook(job, :instruments_enqueue?) == true - end - def record_producer_span(job, &enqueue) return yield if !Sentry.initialized? || job.already_supported_by_sentry_integration? - - return yield if instrumented_by_extension?(job) - - enqueued = false - - run_enqueue = lambda do - enqueued = true - enqueue.call - end - - begin - description = call_hook(job, :publish_description) || job.class.name - Sentry.with_child_span(op: "queue.publish", description: description) do |span| - if span - span.set_origin(call_hook(job, :span_origin) || SPAN_ORIGIN) - set_extension_messaging_data(span, job) - span.set_data(Sentry::Span::DataConventions::MESSAGING_SYSTEM, messaging_system(job)) - span.set_data(Sentry::Span::DataConventions::MESSAGING_MESSAGE_ID, job.job_id) - span.set_data(Sentry::Span::DataConventions::MESSAGING_DESTINATION_NAME, job.queue_name) - - if (count = retry_count(job)) - span.set_data(Sentry::Span::DataConventions::MESSAGING_MESSAGE_RETRY_COUNT, count) - end - end - - run_enqueue.call - end - rescue StandardError => e - raise if enqueued - - log_producer_span_error(e) - - run_enqueue.call - end - end - - def retry_count(job) - if (info = call_hook(job, :retry_info)) - info[:count] - elsif job.respond_to?(:executions) - job.executions.to_i - end - end - - def set_extension_messaging_data(span, job) - call_hook(job, :messaging_data).each do |key, value| - span.set_data(MESSAGING_DATA_ATTRIBUTES.fetch(key), value) - end + return yield if producer.instrumented_by_extension?(job) + + producer.record_span( + job, + description: job.class.name, + messaging_data: -> { + { + system: messaging_system(job), + message_id: job.job_id, + destination: job.queue_name + }.compact + }, + default_retry_count: -> { executions(job) }, + on_instrumentation_error: method(:log_producer_span_error), + &enqueue + ) end def log_producer_span_error(e) diff --git a/sentry-rails/spec/active_job/shared_examples/tracing/producer_span.rb b/sentry-rails/spec/active_job/shared_examples/tracing/producer_span.rb index 102093ab1..278de41a9 100644 --- a/sentry-rails/spec/active_job/shared_examples/tracing/producer_span.rb +++ b/sentry-rails/spec/active_job/shared_examples/tracing/producer_span.rb @@ -62,6 +62,26 @@ end end + context "when tracing is disabled" do + let(:routed_job) do + job_fixture do + attr_accessor :routed_queue + + queue_as { routed_queue || "unrouted" } + + before_enqueue { |job| job.routed_queue = "routed" } + + def perform; end + end + end + + it "resolves a queue_as block after the job's own enqueue callbacks" do + routed_job.perform_later + + expect(last_enqueued_payload["queue_name"]).to eq("routed") + end + end + context "when producer-span instrumentation raises" do let(:configure_sentry) { proc { |config| config.traces_sample_rate = 1.0 } } diff --git a/sentry-ruby/lib/sentry/job_extensions.rb b/sentry-ruby/lib/sentry/job_extensions.rb index e20ba7b36..e47d53ff7 100644 --- a/sentry-ruby/lib/sentry/job_extensions.rb +++ b/sentry-ruby/lib/sentry/job_extensions.rb @@ -6,3 +6,4 @@ require "sentry/job_extensions/registry" require "sentry/job_extensions/instrumentation" require "sentry/job_extensions/consumer" +require "sentry/job_extensions/producer" diff --git a/sentry-ruby/lib/sentry/job_extensions/producer.rb b/sentry-ruby/lib/sentry/job_extensions/producer.rb new file mode 100644 index 000000000..d5ea9ed16 --- /dev/null +++ b/sentry-ruby/lib/sentry/job_extensions/producer.rb @@ -0,0 +1,66 @@ +# frozen_string_literal: true + +module Sentry + module JobExtensions + # @api private + class Producer < Instrumentation + OP_NAME = "queue.publish" + + attr_reader :origin + + def initialize(origin: nil, registry: Sentry.job_extensions) + super(registry: registry) + @origin = origin + end + + def record_span(job, on_instrumentation_error: nil, **span_options, &enqueue) + return with_span(job, **span_options, &enqueue) unless on_instrumentation_error + + enqueued = false + run_enqueue = lambda do + enqueued = true + enqueue.call + end + + begin + with_span(job, **span_options, &run_enqueue) + rescue StandardError => e + raise if enqueued + + on_instrumentation_error.call(e) + run_enqueue.call + end + end + + def instrumented_by_extension?(job) + registry.call(registry.for(job), :instruments_enqueue?, job: job) == true + end + + def inject_trace_headers(job, payload, headers) + registry.call(registry.for(job), :inject_trace_headers, job: job, payload: payload, headers: headers) + end + + private + + def with_span(job, description:, messaging_data: {}, extension_messaging_keys: nil, retry_count: true, default_retry_count: nil) + extension = registry.for(job) + span_description = registry.call(extension, :publish_description, job: job) || description + + Sentry.with_child_span(op: OP_NAME, description: span_description) do |span| + if span + span_origin = registry.call(extension, :span_origin, job: job) || origin + span.set_origin(span_origin) if span_origin + + extension_data = registry.call(extension, :messaging_data, job: job) + extension_data = extension_data.slice(*extension_messaging_keys) if extension_messaging_keys + set_messaging_data(span, extension_data) + set_messaging_data(span, resolve(messaging_data)) + set_retry_count(span, extension, job, default: resolve(default_retry_count)) if retry_count + end + + yield + end + end + end + end +end diff --git a/sentry-ruby/spec/sentry/job_extensions/producer_spec.rb b/sentry-ruby/spec/sentry/job_extensions/producer_spec.rb new file mode 100644 index 000000000..a858d627e --- /dev/null +++ b/sentry-ruby/spec/sentry/job_extensions/producer_spec.rb @@ -0,0 +1,173 @@ +# frozen_string_literal: true + +RSpec.describe Sentry::JobExtensions::Producer do + let(:job) { Struct.new(:id, :queue).new("job-1", "critical") } + let(:string_io) { StringIO.new } + + def producer(origin: nil, **hooks) + registry = Sentry::JobExtensions::Registry.new + registry.register( + Class.new(Sentry::JobExtensions::Extension) do + define_method(:handles?) { |_job| true } + hooks.each { |hook, body| define_method(hook, &body) } + end.new(name: "test_backend") + ) + described_class.new(origin: origin, registry: registry) + end + + def enriching_producer(origin: nil) + producer( + origin: origin, + messaging_data: ->(job:) { { system: "backend", message_id: job.id, destination: job.queue, receive_latency: 42.5 } }, + retry_info: ->(job:) { { count: 3, will_retry: true } } + ) + end + + def within_transaction + transaction = Sentry.start_transaction(name: "parent", op: "test") + Sentry.get_current_scope.set_span(transaction) + yield + ensure + transaction.finish + end + + def publish_span + sentry_events.last.spans.find { |span| span[:op] == "queue.publish" } + end + + def record_span(producer, **options, &enqueue) + producer.record_span(job, description: "TestJob", **options, &(enqueue || -> { :enqueued })) + end + + before do + perform_basic_setup do |config| + config.traces_sample_rate = 1.0 + config.sdk_logger = Logger.new(string_io) + end + setup_sentry_test + end + + after do + teardown_sentry_test + end + + describe "#record_span" do + it "records a queue.publish span with the extension's messaging data and retry count around the enqueue" do + result = within_transaction { record_span(enriching_producer(origin: "auto.queue.test")) } + + expect(result).to eq(:enqueued) + expect(publish_span).to include(description: "TestJob", origin: "auto.queue.test") + expect(publish_span[:data]).to include( + "messaging.system" => "backend", + "messaging.message.id" => "job-1", + "messaging.destination.name" => "critical", + "messaging.message.receive.latency" => 42.5, + "messaging.message.retry.count" => 3 + ) + end + + it "lets the caller's messaging data win over the extension's" do + within_transaction do + record_span(enriching_producer, messaging_data: { system: "caller", message_id: "caller-id" }) + end + + expect(publish_span[:data]).to include( + "messaging.system" => "caller", + "messaging.message.id" => "caller-id", + "messaging.destination.name" => "critical" + ) + end + + it "applies only the requested keys of the extension's messaging data" do + within_transaction do + record_span(enriching_producer, extension_messaging_keys: %i[message_id destination]) + end + + expect(publish_span[:data]).to include("messaging.message.id" => "job-1", "messaging.destination.name" => "critical") + expect(publish_span[:data]).not_to include("messaging.system", "messaging.message.receive.latency") + end + + it "falls back to the caller's retry count when the extension has no retry info" do + within_transaction { record_span(producer, default_retry_count: 2) } + + expect(publish_span[:data]).to include("messaging.message.retry.count" => 2) + end + + it "records no retry count when the caller opts out" do + within_transaction { record_span(enriching_producer, retry_count: false) } + + expect(publish_span[:data]).not_to include("messaging.message.retry.count") + end + + it "degrades a failing extension hook to its neutral result" do + within_transaction { record_span(producer(messaging_data: ->(job:) { raise "boom" }, retry_info: ->(job:) { :malformed }), default_retry_count: 1) } + + expect(publish_span[:data]).to include("messaging.message.retry.count" => 1) + expect(publish_span[:data]).not_to include("messaging.message.id") + end + + it "enqueues without a span when no transaction is active" do + expect(record_span(enriching_producer)).to eq(:enqueued) + expect(sentry_events).to be_empty + end + + context "when recording the span raises" do + before do + allow(Sentry).to receive(:with_child_span).and_raise(StandardError, "boom from instrumentation") + end + + it "propagates the failure without enqueueing when the caller wants no isolation" do + enqueued = 0 + + expect do + within_transaction { record_span(enriching_producer) { enqueued += 1 } } + end.to raise_error(StandardError, /boom from instrumentation/) + expect(enqueued).to eq(0) + end + + it "reports the failure to the caller and enqueues once when the caller wants isolation" do + errors = [] + enqueued = 0 + + result = within_transaction do + record_span(enriching_producer, on_instrumentation_error: ->(e) { errors << e }) { enqueued += 1 } + end + + expect(result).to eq(1) + expect(enqueued).to eq(1) + expect(errors.map(&:message)).to eq(["boom from instrumentation"]) + end + end + + it "re-raises a failing enqueue without reporting it as an instrumentation failure" do + errors = [] + + expect do + within_transaction do + record_span(enriching_producer, on_instrumentation_error: ->(e) { errors << e }) { raise "boom from enqueue" } + end + end.to raise_error(RuntimeError, /boom from enqueue/) + expect(errors).to be_empty + end + end + + describe "#inject_trace_headers" do + let(:payload) { { "job_class" => "TestJob" } } + let(:headers) { { "sentry-trace" => "trace" } } + + it "returns the payload the extension built with the headers" do + extension_producer = producer(inject_trace_headers: ->(job:, payload:, headers:) { payload.merge("trace" => headers) }) + + expect(extension_producer.inject_trace_headers(job, payload, headers)).to eq( + "job_class" => "TestJob", "trace" => headers + ) + end + + it "returns the payload unchanged when the extension fails" do + failing_producer = producer(inject_trace_headers: ->(job:, payload:, headers:) { raise "boom" }) + + expect(failing_producer.inject_trace_headers(job, payload, headers)).to equal(payload) + expect(string_io.string).to include("failed in inject_trace_headers") + end + end +end diff --git a/sentry-sidekiq/lib/sentry/sidekiq/sentry_context_middleware.rb b/sentry-sidekiq/lib/sentry/sidekiq/sentry_context_middleware.rb index 8fa3aad7f..b09b782bd 100644 --- a/sentry-sidekiq/lib/sentry/sidekiq/sentry_context_middleware.rb +++ b/sentry-sidekiq/lib/sentry/sidekiq/sentry_context_middleware.rb @@ -4,31 +4,6 @@ module Sentry module Sidekiq - module Helpers - def set_span_data(span, id:, queue:, latency: nil, retry_count: nil) - return unless span - - span.set_data(Span::DataConventions::MESSAGING_MESSAGE_ID, id) - span.set_data(Span::DataConventions::MESSAGING_DESTINATION_NAME, queue) - span.set_data(Span::DataConventions::MESSAGING_MESSAGE_RECEIVE_LATENCY, latency) if latency - span.set_data(Span::DataConventions::MESSAGING_MESSAGE_RETRY_COUNT, retry_count) if retry_count - end - - if ::Gem::Version.new(::Sidekiq::VERSION) >= ::Gem::Version.new("8.0.0") - def calculate_latency(job) - now_in_ms - job["enqueued_at"] if job["enqueued_at"] - end - else - def calculate_latency(job) - ((Time.now.to_f - job["enqueued_at"]) * 1000).round if job["enqueued_at"] - end - end - - def now_in_ms - ::Process.clock_gettime(::Process::CLOCK_REALTIME, :millisecond) - end - end - class SentryContextServerMiddleware SPAN_ORIGIN = "auto.queue.sidekiq" @@ -76,7 +51,9 @@ def job_extension end class SentryContextClientMiddleware - include Sentry::Sidekiq::Helpers + def self.producer + @producer ||= Sentry::JobExtensions::Producer.new + end def call(worker_class, job, queue, _redis_pool) return yield unless Sentry.initialized? @@ -87,14 +64,22 @@ def call(worker_class, job, queue, _redis_pool) end if Sentry.configuration.sidekiq.propagate_traces - job["trace_propagation_headers"] ||= Sentry.get_trace_propagation_headers + job.replace(producer.inject_trace_headers(job, job, Sentry.get_trace_propagation_headers)) end - Sentry.with_child_span(op: "queue.publish", description: worker_class.to_s) do |span| - set_span_data(span, id: job["jid"], queue: queue) + producer.record_span( + job, + description: worker_class.to_s, + extension_messaging_keys: %i[message_id], + messaging_data: { destination: queue }, + retry_count: false + ) { yield } + end - yield - end + private + + def producer + self.class.producer end end end diff --git a/sentry-sidekiq/spec/sentry/sidekiq/sentry_context_middleware_spec.rb b/sentry-sidekiq/spec/sentry/sidekiq/sentry_context_middleware_spec.rb index 54e58e463..2e9066011 100644 --- a/sentry-sidekiq/spec/sentry/sidekiq/sentry_context_middleware_spec.rb +++ b/sentry-sidekiq/spec/sentry/sidekiq/sentry_context_middleware_spec.rb @@ -213,6 +213,18 @@ def ensure_queue_empty(queue, timeout: 0.1) expect(queue.first["sentry_user"]).to eq(user) end + context "when the scope user has fields beyond id, email and username" do + let(:user) { { "id" => 1, "ip_address" => "1.2.3.4", "segment" => "vip" } } + + it "propagates the whole user" do + Sentry.configuration.data_collection.user_info = true + + client.push('queue' => 'default', 'class' => HappyWorker, 'args' => []) + + expect(queue.first["sentry_user"]).to eq(user) + end + end + it "does not propagate user information when user_info is disabled" do Sentry.configuration.data_collection.user_info = false @@ -271,6 +283,67 @@ def ensure_queue_empty(queue, timeout: 0.1) expect(span[:data]['messaging.destination.name']).to eq('default') end + context "when an earlier client middleware reroutes the job" do + let(:rerouted_queue) { Sidekiq::Queue.new("rerouted") } + + let(:rerouting_middleware) do + Class.new do + def call(_worker_class, job, _queue, _redis_pool) + job["queue"] = "rerouted" + yield + end + end + end + + let(:client) do + Sidekiq::Client.new.tap do |client| + client.middleware do |chain| + chain.add rerouting_middleware + chain.add described_class + end + end + end + + after do + client.middleware { |chain| chain.remove(rerouting_middleware) } + ensure_queue_empty(rerouted_queue) + end + + it "reports the queue the push was made to as the destination" do + client.push('queue' => 'default', 'class' => HappyWorker, 'args' => []) + + transaction.finish + + span = transport.events.last.spans.detect { |span| span[:op] == "queue.publish" } + expect(span[:data]['messaging.destination.name']).to eq('default') + end + end + + it "names the queue.publish span after the worker without an origin, messaging system or retry count" do + client.push('queue' => 'default', 'class' => HappyWorker, 'args' => [], 'retry_count' => 2) + + transaction.finish + + span = transport.events.last.spans.detect { |span| span[:op] == "queue.publish" } + expect(span[:description]).to eq("HappyWorker") + expect(span[:origin]).to eq("manual") + expect(span[:data]).not_to have_key('messaging.system') + expect(span[:data]).not_to have_key('messaging.message.retry.count') + end + + it "does not enqueue the job when recording the queue.publish span raises" do + allow(Sentry).to receive(:with_child_span).and_call_original + allow(Sentry).to receive(:with_child_span) + .with(hash_including(op: "queue.publish")) + .and_raise(StandardError, "boom from instrumentation") + + expect do + client.push('queue' => 'default', 'class' => HappyWorker, 'args' => []) + end.to raise_error(StandardError, /boom from instrumentation/) + + expect(queue.size).to be(0) + end + it "does not propagate headers with propagate_traces = false" do perform_basic_setup do |config| config.traces_sample_rate = 1.0 From 73c10ddace621dbef50a738288e683bd5e119dff Mon Sep 17 00:00:00 2001 From: Peter Solnica Date: Tue, 13 Oct 2026 11:19:46 +0000 Subject: [PATCH 3/4] fix(sidekiq): retain native extension defaults --- .../lib/sentry/job_extensions/consumer.rb | 15 ++++-- .../lib/sentry/job_extensions/producer.rb | 3 +- .../sidekiq/sentry_context_middleware.rb | 10 +++- .../spec/isolated/native_extension_spec.rb | 52 +++++++++++++++++++ 4 files changed, 72 insertions(+), 8 deletions(-) create mode 100644 sentry-sidekiq/spec/isolated/native_extension_spec.rb diff --git a/sentry-ruby/lib/sentry/job_extensions/consumer.rb b/sentry-ruby/lib/sentry/job_extensions/consumer.rb index 802372264..7f5419354 100644 --- a/sentry-ruby/lib/sentry/job_extensions/consumer.rb +++ b/sentry-ruby/lib/sentry/job_extensions/consumer.rb @@ -14,12 +14,10 @@ def initialize(integration:, origin:, registry: Sentry.job_extensions) @origin = origin end - def apply_scope_data(scope, job) + def apply_scope_data(scope, job, default_scope_data: {}) + apply_scope_values(scope, default_scope_data) data = registry.call(registry.for(job), :scope_data, job: job) - scope.set_contexts(data[:contexts]) if data[:contexts] - scope.set_tags(data[:tags]) if data[:tags] - scope.set_extras(data[:extra]) if data[:extra] - scope.set_user(data[:user]) if data[:user] + apply_scope_values(scope, data) end def transaction_name(job) @@ -102,6 +100,13 @@ def capture_exception(job, exception, contexts: {}, tags: {}, extra: {}) private + def apply_scope_values(scope, data) + scope.set_contexts(data[:contexts]) if data[:contexts] + scope.set_tags(data[:tags]) if data[:tags] + scope.set_extras(data[:extra]) if data[:extra] + scope.set_user(data[:user]) if data[:user] + end + def additive_error_data(data) scope = Sentry.get_current_scope diff --git a/sentry-ruby/lib/sentry/job_extensions/producer.rb b/sentry-ruby/lib/sentry/job_extensions/producer.rb index d5ea9ed16..bd332985c 100644 --- a/sentry-ruby/lib/sentry/job_extensions/producer.rb +++ b/sentry-ruby/lib/sentry/job_extensions/producer.rb @@ -42,7 +42,7 @@ def inject_trace_headers(job, payload, headers) private - def with_span(job, description:, messaging_data: {}, extension_messaging_keys: nil, retry_count: true, default_retry_count: nil) + def with_span(job, description:, messaging_data: {}, default_messaging_data: {}, extension_messaging_keys: nil, retry_count: true, default_retry_count: nil) extension = registry.for(job) span_description = registry.call(extension, :publish_description, job: job) || description @@ -51,6 +51,7 @@ def with_span(job, description:, messaging_data: {}, extension_messaging_keys: n span_origin = registry.call(extension, :span_origin, job: job) || origin span.set_origin(span_origin) if span_origin + set_messaging_data(span, resolve(default_messaging_data)) extension_data = registry.call(extension, :messaging_data, job: job) extension_data = extension_data.slice(*extension_messaging_keys) if extension_messaging_keys set_messaging_data(span, extension_data) diff --git a/sentry-sidekiq/lib/sentry/sidekiq/sentry_context_middleware.rb b/sentry-sidekiq/lib/sentry/sidekiq/sentry_context_middleware.rb index b09b782bd..a9f9d3848 100644 --- a/sentry-sidekiq/lib/sentry/sidekiq/sentry_context_middleware.rb +++ b/sentry-sidekiq/lib/sentry/sidekiq/sentry_context_middleware.rb @@ -18,11 +18,14 @@ def call(worker, job, queue) Sentry.clone_hub_to_current_thread scope = Sentry.get_current_scope - consumer.apply_scope_data(scope, sidekiq_job) + consumer.apply_scope_data(scope, sidekiq_job, default_scope_data: job_extension.scope_data(job: sidekiq_job)) scope.set_transaction_name(job_extension.transaction_name(job: job), source: :task) transaction = consumer.start_transaction( scope, sidekiq_job, payload: sidekiq_job, + trace_headers: job_extension.extract_trace_headers(job: sidekiq_job, payload: sidekiq_job), + messaging_data: -> { job_extension.messaging_data(job: sidekiq_job) }, + default_retry_count: job_extension.retry_info(job: sidekiq_job)[:count], always_continue_trace: true ) @@ -64,13 +67,16 @@ def call(worker_class, job, queue, _redis_pool) end if Sentry.configuration.sidekiq.propagate_traces - job.replace(producer.inject_trace_headers(job, job, Sentry.get_trace_propagation_headers)) + headers = Sentry.get_trace_propagation_headers + payload = Sentry::Sidekiq.job_extension.inject_trace_headers(job: job, payload: job, headers: headers) + job.replace(producer.inject_trace_headers(job, payload, headers)) end producer.record_span( job, description: worker_class.to_s, extension_messaging_keys: %i[message_id], + default_messaging_data: { message_id: job["jid"] }, messaging_data: { destination: queue }, retry_count: false ) { yield } diff --git a/sentry-sidekiq/spec/isolated/native_extension_spec.rb b/sentry-sidekiq/spec/isolated/native_extension_spec.rb new file mode 100644 index 000000000..3966819e2 --- /dev/null +++ b/sentry-sidekiq/spec/isolated/native_extension_spec.rb @@ -0,0 +1,52 @@ +# frozen_string_literal: true + +require "sentry-ruby" + +class NativeEnrichmentExtension < Sentry::JobExtensions::Extension + def handles?(job) + job.is_a?(Hash) && job["class"] == "SadWorker" + end + + def scope_data(job:) + { tags: { enrichment: "present" } } + end +end + +Sentry.register_job_extension(NativeEnrichmentExtension.new(name: "native_enrichment")) + +require "spec_helper" +require "sidekiq/api" + +RSpec.describe "Native Sidekiq with an earlier enrichment extension" do + [nil, 0.0, 1.0].each do |sample_rate| + it "preserves propagation and native metadata at sample rate #{sample_rate.inspect}" do + perform_basic_setup { |config| config.traces_sample_rate = sample_rate } + parent = Sentry.start_transaction(name: "enqueue", op: "test") + Sentry.get_current_scope.set_span(parent) if parent + headers = Sentry.get_trace_propagation_headers + client = Sidekiq::Client.new + client.middleware { |chain| chain.add Sentry::Sidekiq::SentryContextClientMiddleware } + jid = client.push("class" => SadWorker, "queue" => "extension", "args" => [], "retry" => false) + message = Sidekiq.redis { |redis| redis.lpop("queue:extension") } + job = Sidekiq.load_json(message) + transport = Sentry.get_current_client.transport + + expect(job["trace_propagation_headers"]).to eq(headers) + expect(headers.keys).to include("sentry-trace", "baggage") + parent.finish if parent + process_work(new_processor, Sidekiq::BasicFetch::UnitOfWork.new("queue:extension", message)) + + event = transport.events.find { |entry| entry.is_a?(Sentry::ErrorEvent) } + expect(event.contexts.dig(:trace, :trace_id)).to eq(headers["sentry-trace"].split("-").first) + expect(event.tags).to include(queue: "extension", jid: jid, enrichment: "present") + expect(event.contexts[:sidekiq]).to include("jid" => jid, "queue" => "extension") + + if sample_rate == 1.0 + consumer = transport.events.find { |entry| entry.is_a?(Sentry::TransactionEvent) && entry.transaction == "Sidekiq/SadWorker" } + expect(consumer.contexts.dig(:trace, :data)).to include("messaging.message.id" => jid, "messaging.destination.name" => "extension") + producer = transport.events.find { |entry| entry.is_a?(Sentry::TransactionEvent) && entry.transaction == "enqueue" } + expect(producer.spans.first[:data]).to include("messaging.message.id" => jid, "messaging.destination.name" => "extension") + end + end + end +end From dffd7ecb6ba32792499d7f5ed1ca18a51287f1e0 Mon Sep 17 00:00:00 2001 From: Peter Solnica Date: Wed, 14 Oct 2026 06:11:11 +0000 Subject: [PATCH 4/4] test(sidekiq): run isolated specs in separate processes --- sentry-sidekiq/Rakefile | 29 +++++++++++++++++++++-------- 1 file changed, 21 insertions(+), 8 deletions(-) diff --git a/sentry-sidekiq/Rakefile b/sentry-sidekiq/Rakefile index 9207ea5fe..648ec9fe3 100644 --- a/sentry-sidekiq/Rakefile +++ b/sentry-sidekiq/Rakefile @@ -1,13 +1,26 @@ # frozen_string_literal: true require "bundler/gem_tasks" -require_relative "../lib/sentry/test/rake_tasks" - -Sentry::Test::RakeTasks.define_spec_tasks( - spec_pattern: "spec/sentry/**/*_spec.rb", - spec_rspec_opts: "--order rand --format progress", - isolated_specs_pattern: "spec/isolated/**/*_spec.rb", - isolated_rspec_opts: "--format progress" -) +require "rspec/core/rake_task" + +RSpec::Core::RakeTask.new(:spec) do |task| + task.pattern = "spec/sentry/**/*_spec.rb" + task.rspec_opts = "--order rand --format progress" +end + +namespace :spec do + isolated_tasks = Dir["spec/isolated/**/*_spec.rb"].sort.map do |file| + task_name = "isolated:#{file.delete_prefix("spec/isolated/").delete_suffix("_spec.rb")}" + + RSpec::Core::RakeTask.new(task_name) do |task| + task.pattern = file + task.rspec_opts = "--format progress" + end + + task_name + end + + task isolated: isolated_tasks +end task default: [:spec, :"spec:isolated"]