From 921ad17b9a3a32d9f78bf61a6049c506f5b8049c Mon Sep 17 00:00:00 2001 From: Rune Philosof Date: Tue, 7 Jul 2026 14:46:54 +0200 Subject: [PATCH 1/4] Fix trace_id mismatch for logs emitted before CaptureExceptions runs Rails::Rack::Logger's "Started ..." line (and anything logged before CaptureExceptions runs) got an unrelated trace_id, since CaptureExceptions runs after ActionDispatch::ShowExceptions. Add Sentry::Rails::CaptureContext, a minimal middleware unshifted to the front of the stack that establishes the propagation context early. CaptureExceptions now consumes and reuses it instead of regenerating a new trace_id/span_id. Co-Authored-By: GitHub Copilot --- .../lib/sentry/rails/capture_context.rb | 23 ++++ .../lib/sentry/rails/capture_exceptions.rb | 6 +- sentry-rails/lib/sentry/rails/railtie.rb | 3 + .../spec/sentry/rails/capture_context_spec.rb | 103 ++++++++++++++++++ sentry-rails/spec/sentry/rails_spec.rb | 1 + sentry-ruby/lib/sentry/hub.rb | 14 ++- sentry-ruby/lib/sentry/propagation_context.rb | 5 + .../lib/sentry/rack/capture_exceptions.rb | 17 ++- .../sentry/rack/capture_exceptions_spec.rb | 64 +++++++++++ sentry-ruby/spec/sentry_spec.rb | 66 +++++++++++ 10 files changed, 290 insertions(+), 12 deletions(-) create mode 100644 sentry-rails/lib/sentry/rails/capture_context.rb create mode 100644 sentry-rails/spec/sentry/rails/capture_context_spec.rb diff --git a/sentry-rails/lib/sentry/rails/capture_context.rb b/sentry-rails/lib/sentry/rails/capture_context.rb new file mode 100644 index 000000000..8f8574276 --- /dev/null +++ b/sentry-rails/lib/sentry/rails/capture_context.rb @@ -0,0 +1,23 @@ +# frozen_string_literal: true + +module Sentry + module Rails + # Establishes the propagation context as early as possible, so anything + # logged before +CaptureExceptions+ runs shares the request's trace_id. + class CaptureContext + def initialize(app) + @app = app + end + + def call(env) + return @app.call(env) unless Sentry.initialized? + + Sentry.clone_hub_to_current_thread + Sentry.get_current_scope.generate_propagation_context(env) + env[Sentry::PropagationContext::ESTABLISHED_ENV_KEY] = true + + @app.call(env) + end + end + end +end diff --git a/sentry-rails/lib/sentry/rails/capture_exceptions.rb b/sentry-rails/lib/sentry/rails/capture_exceptions.rb index ba53e7b13..a881f8b6e 100644 --- a/sentry-rails/lib/sentry/rails/capture_exceptions.rb +++ b/sentry-rails/lib/sentry/rails/capture_exceptions.rb @@ -39,7 +39,7 @@ def capture_exception(exception, env) end end - def start_transaction(env, scope) + def start_transaction(env, scope, established) options = { name: scope.transaction_name, source: scope.transaction_source, @@ -49,8 +49,8 @@ def start_transaction(env, scope) options.merge!(sampled: false) if @assets_regexp && scope.transaction_name.match?(@assets_regexp) - transaction = Sentry.continue_trace(env, **options) - transaction = Sentry.start_transaction(transaction: transaction, custom_sampling_context: { env: env }, **options) + transaction = Sentry.continue_trace(env, established: established, **options) + transaction = Sentry.start_transaction(transaction: transaction, custom_sampling_context: { env: env }, established: established, **options) attach_queue_time(transaction, env) transaction end diff --git a/sentry-rails/lib/sentry/rails/railtie.rb b/sentry-rails/lib/sentry/rails/railtie.rb index a234e95a9..538b481b9 100644 --- a/sentry-rails/lib/sentry/rails/railtie.rb +++ b/sentry-rails/lib/sentry/rails/railtie.rb @@ -1,5 +1,6 @@ # frozen_string_literal: true +require "sentry/rails/capture_context" require "sentry/rails/capture_exceptions" require "sentry/rails/rescued_exception_interceptor" require "sentry/rails/backtrace_cleaner" @@ -8,6 +9,8 @@ module Sentry class Railtie < ::Rails::Railtie # middlewares can't be injected after initialize initializer "sentry.use_rack_middleware" do |app| + # placed first so anything logged before CaptureExceptions shares the same trace context + app.config.middleware.unshift Sentry::Rails::CaptureContext # placed after all the file-sending middlewares so we can avoid unnecessary transactions app.config.middleware.insert_after ActionDispatch::ShowExceptions, Sentry::Rails::CaptureExceptions # need to place as close to DebugExceptions as possible to intercept most of the exceptions, including those raised by middlewares diff --git a/sentry-rails/spec/sentry/rails/capture_context_spec.rb b/sentry-rails/spec/sentry/rails/capture_context_spec.rb new file mode 100644 index 000000000..06b0d1bb4 --- /dev/null +++ b/sentry-rails/spec/sentry/rails/capture_context_spec.rb @@ -0,0 +1,103 @@ +# frozen_string_literal: true + +require "spec_helper" + +RSpec.describe Sentry::Rails::CaptureContext do + # Records the current scope's trace_id every time it's called, so specs can + # compare what a piece of middleware would see at different points in the stack. + class CaptureContextSpecProbe + def self.captured_trace_ids + @captured_trace_ids ||= [] + end + + def initialize(app) + @app = app + end + + def call(env) + self.class.captured_trace_ids << Sentry.get_current_scope.get_trace_context[:trace_id] + @app.call(env) + end + end + + describe "#call" do + before do + make_basic_app + end + + it "establishes a propagation context and flags the env" do + trace_id_in_app = nil + + app = lambda do |env| + trace_id_in_app = Sentry.get_current_scope.get_trace_context[:trace_id] + [200, {}, ["ok"]] + end + + env = Rack::MockRequest.env_for("/test") + described_class.new(app).call(env) + + expect(env[Sentry::PropagationContext::ESTABLISHED_ENV_KEY]).to eq(true) + expect(trace_id_in_app).to be_a(String) + end + + it "is a no-op when Sentry is not initialized" do + allow(Sentry).to receive(:initialized?).and_return(false) + + called = false + app = lambda do |env| + called = true + [200, {}, ["ok"]] + end + + env = Rack::MockRequest.env_for("/test") + described_class.new(app).call(env) + + expect(called).to eq(true) + expect(env[Sentry::PropagationContext::ESTABLISHED_ENV_KEY]).to be_nil + end + end + + context "when composed with CaptureExceptions", type: :request do + before do + CaptureContextSpecProbe.captured_trace_ids.clear + end + + context "without tracing enabled" do + before do + make_basic_app do |config, app| + app.config.middleware.insert_before(Sentry::Rails::CaptureExceptions, CaptureContextSpecProbe) + app.config.middleware.insert_after(Sentry::Rails::CaptureExceptions, CaptureContextSpecProbe) + end + end + + it "keeps the same trace_id before and after CaptureExceptions runs" do + get "/world" + + early_trace_id, late_trace_id = CaptureContextSpecProbe.captured_trace_ids + + expect(early_trace_id).to be_a(String) + expect(late_trace_id).to eq(early_trace_id) + end + end + + context "with tracing enabled" do + before do + make_basic_app do |config, app| + config.traces_sample_rate = 1.0 + app.config.middleware.insert_before(Sentry::Rails::CaptureExceptions, CaptureContextSpecProbe) + app.config.middleware.insert_after(Sentry::Rails::CaptureExceptions, CaptureContextSpecProbe) + end + end + + it "keeps the same trace_id from before CaptureExceptions through the started transaction" do + get "/world" + + early_trace_id, late_trace_id = CaptureContextSpecProbe.captured_trace_ids + + expect(early_trace_id).to be_a(String) + # the "late" trace_id comes from the actual transaction CaptureExceptions started + expect(late_trace_id).to eq(early_trace_id) + end + end + end +end diff --git a/sentry-rails/spec/sentry/rails_spec.rb b/sentry-rails/spec/sentry/rails_spec.rb index 1ad84054a..f0c44cdba 100644 --- a/sentry-rails/spec/sentry/rails_spec.rb +++ b/sentry-rails/spec/sentry/rails_spec.rb @@ -22,6 +22,7 @@ it "inserts middleware to a correct position" do app = Rails.application + expect(app.middleware.first).to eq(Sentry::Rails::CaptureContext) index_of_executor = app.middleware.find_index { |m| m == ActionDispatch::ShowExceptions } expect(app.middleware.find_index(Sentry::Rails::CaptureExceptions)).to eq(index_of_executor + 1) index_of_debug_exceptions = app.middleware.find_index { |m| m == ActionDispatch::DebugExceptions } diff --git a/sentry-ruby/lib/sentry/hub.rb b/sentry-ruby/lib/sentry/hub.rb index 5f99edb71..61558e76d 100644 --- a/sentry-ruby/lib/sentry/hub.rb +++ b/sentry-ruby/lib/sentry/hub.rb @@ -118,10 +118,17 @@ def pop_scope end end - def start_transaction(transaction: nil, custom_sampling_context: {}, instrumenter: :sentry, **options) + def start_transaction(transaction: nil, custom_sampling_context: {}, instrumenter: :sentry, established: false, **options) return unless configuration.tracing_enabled? return unless instrumenter == configuration.instrumenter + if transaction.nil? && !options.key?(:trace_id) && established + # reuse the already-established trace_id instead of generating an unrelated one + propagation_context = current_scope.propagation_context + options[:trace_id] = propagation_context.trace_id + options[:sample_rand] ||= propagation_context.sample_rand + end + transaction ||= Transaction.new(**options) sampling_context = { @@ -373,8 +380,9 @@ def get_trace_propagation_meta end.join("\n") end - def continue_trace(env, **options) - configure_scope { |s| s.generate_propagation_context(env) } + def continue_trace(env, established: false, **options) + # don't clobber context an earlier point in the stack already established + configure_scope { |s| s.generate_propagation_context(env) } unless established return nil unless configuration.tracing_enabled? diff --git a/sentry-ruby/lib/sentry/propagation_context.rb b/sentry-ruby/lib/sentry/propagation_context.rb index 45dbd4d78..fd58f0576 100644 --- a/sentry-ruby/lib/sentry/propagation_context.rb +++ b/sentry-ruby/lib/sentry/propagation_context.rb @@ -13,6 +13,11 @@ class PropagationContext "-?([01])?\\z" # sampled ) + # Rack env key signaling that trace context was already established earlier in + # the middleware stack (e.g. by +Sentry::Rails::CaptureContext+); consumed once by + # +Sentry::Rack::CaptureExceptions+. + ESTABLISHED_ENV_KEY = "sentry.trace_context_established" + # An uuid that can be used to identify a trace. # @return [String] attr_reader :trace_id diff --git a/sentry-ruby/lib/sentry/rack/capture_exceptions.rb b/sentry-ruby/lib/sentry/rack/capture_exceptions.rb index a97f93079..4c1e59604 100644 --- a/sentry-ruby/lib/sentry/rack/capture_exceptions.rb +++ b/sentry-ruby/lib/sentry/rack/capture_exceptions.rb @@ -1,5 +1,7 @@ # frozen_string_literal: true +require "sentry/propagation_context" + module Sentry module Rack class CaptureExceptions @@ -14,8 +16,11 @@ def initialize(app) def call(env) return @app.call(env) unless Sentry.initialized? - # make sure the current thread has a clean hub - Sentry.clone_hub_to_current_thread + # consumed atomically, first, so it can't leak into later reuses of this env + established = env.delete(Sentry::PropagationContext::ESTABLISHED_ENV_KEY) + + # make sure the current thread has a clean hub, unless it was already established + Sentry.clone_hub_to_current_thread unless established Sentry.with_scope do |scope| Sentry.with_session_tracking do @@ -23,7 +28,7 @@ def call(env) scope.set_transaction_name(env["PATH_INFO"], source: :url) if env["PATH_INFO"] scope.set_rack_env(env) - transaction = start_transaction(env, scope) + transaction = start_transaction(env, scope, established) scope.set_span(transaction) if transaction begin @@ -63,7 +68,7 @@ def capture_exception(exception, env) end end - def start_transaction(env, scope) + def start_transaction(env, scope, established) options = { name: scope.transaction_name, source: scope.transaction_source, @@ -71,8 +76,8 @@ def start_transaction(env, scope) origin: SPAN_ORIGIN } - transaction = Sentry.continue_trace(env, **options) - transaction = Sentry.start_transaction(transaction: transaction, custom_sampling_context: { env: env }, **options) + transaction = Sentry.continue_trace(env, established: established, **options) + transaction = Sentry.start_transaction(transaction: transaction, custom_sampling_context: { env: env }, established: established, **options) attach_queue_time(transaction, env) transaction end diff --git a/sentry-ruby/spec/sentry/rack/capture_exceptions_spec.rb b/sentry-ruby/spec/sentry/rack/capture_exceptions_spec.rb index 734952339..9886c54b9 100644 --- a/sentry-ruby/spec/sentry/rack/capture_exceptions_spec.rb +++ b/sentry-ruby/spec/sentry/rack/capture_exceptions_spec.rb @@ -93,6 +93,70 @@ expect(env.key?("sentry.error_event_id")).to eq(false) end + context "when trace context was already established earlier in the stack" do + it "does not re-clone the hub and reuses the existing propagation context" do + Sentry.clone_hub_to_current_thread + Sentry.get_current_scope.generate_propagation_context(env) + env[Sentry::PropagationContext::ESTABLISHED_ENV_KEY] = true + + established_propagation_context = Sentry.get_current_scope.propagation_context + + expect(Sentry).not_to receive(:clone_hub_to_current_thread) + + trace_id_in_app = nil + app = lambda do |e| + trace_id_in_app = Sentry.get_current_scope.get_trace_context[:trace_id] + [200, {}, ['okay']] + end + + stack = Sentry::Rack::CaptureExceptions.new(app) + stack.call(env) + + expect(trace_id_in_app).to eq(established_propagation_context.trace_id) + end + + it "deletes the established flag from env so it doesn't leak into later reuses of the same env" do + Sentry.clone_hub_to_current_thread + Sentry.get_current_scope.generate_propagation_context(env) + env[Sentry::PropagationContext::ESTABLISHED_ENV_KEY] = true + + app = ->(_e) { [200, {}, ['okay']] } + stack = Sentry::Rack::CaptureExceptions.new(app) + stack.call(env) + + expect(env.key?(Sentry::PropagationContext::ESTABLISHED_ENV_KEY)).to eq(false) + end + + it "does not reuse a stale established context on a later, unrelated call with the same env" do + # Simulates a long-lived connection (e.g. Action Cable) that stores the handshake's + # env and reuses it for many separate operations over its lifetime - only the very + # first operation immediately following CaptureContext should honor the flag. + Sentry.clone_hub_to_current_thread + Sentry.get_current_scope.generate_propagation_context(env) + env[Sentry::PropagationContext::ESTABLISHED_ENV_KEY] = true + + app = ->(_e) { [200, {}, ['okay']] } + stack = Sentry::Rack::CaptureExceptions.new(app) + stack.call(env) + + Sentry.clone_hub_to_current_thread + propagation_context_before_second_call = Sentry.get_current_scope.propagation_context + + trace_id_in_second_call = nil + second_app = lambda do |e| + trace_id_in_second_call = Sentry.get_current_scope.get_trace_context[:trace_id] + [200, {}, ['okay']] + end + + expect(Sentry).to receive(:clone_hub_to_current_thread).and_call_original + + second_stack = Sentry::Rack::CaptureExceptions.new(second_app) + second_stack.call(env) + + expect(trace_id_in_second_call).not_to eq(propagation_context_before_second_call.trace_id) + end + end + context "with config.include_local_variables = true" do before do perform_basic_setup do |config| diff --git a/sentry-ruby/spec/sentry_spec.rb b/sentry-ruby/spec/sentry_spec.rb index 9c5751cf1..c8019d512 100644 --- a/sentry-ruby/spec/sentry_spec.rb +++ b/sentry-ruby/spec/sentry_spec.rb @@ -564,6 +564,61 @@ end describe ".start_transaction" do + describe "when not continuing an existing trace" do + before do + perform_basic_setup do |config| + config.traces_sample_rate = 1.0 + end + end + + it "does not adopt the scope's propagation context when it wasn't established for this call" do + propagation_context = Sentry.get_current_scope.propagation_context + + transaction = described_class.start_transaction(name: "test", op: "test.op") + + # each independent call gets its own, unrelated trace_id by default - only + # calls made with established: true (e.g. a Rack request that went through + # Sentry::Rails::CaptureContext) adopt the scope's propagation context + expect(transaction.trace_id).not_to eq(propagation_context.trace_id) + end + + context "when the scope's propagation context was established for this call" do + before do + Sentry.get_current_scope.generate_propagation_context + end + + it "adopts the scope's propagation context trace_id and sample_rand" do + propagation_context = Sentry.get_current_scope.propagation_context + + transaction = described_class.start_transaction( + name: "test", op: "test.op", established: true + ) + + expect(transaction.trace_id).to eq(propagation_context.trace_id) + expect(transaction.sample_rand).to eq(propagation_context.sample_rand) + end + + it "does not override an explicitly provided trace_id" do + transaction = described_class.start_transaction( + name: "test", op: "test.op", trace_id: "a" * 32, established: true + ) + + expect(transaction.trace_id).to eq("a" * 32) + end + + it "does not override an explicitly provided sample_rand" do + propagation_context = Sentry.get_current_scope.propagation_context + + transaction = described_class.start_transaction( + name: "test", op: "test.op", sample_rand: 0.999999, established: true + ) + + expect(transaction.trace_id).to eq(propagation_context.trace_id) + expect(transaction.sample_rand).to eq(0.999999) + end + end + end + describe "sampler example" do before do perform_basic_setup do |config| @@ -1157,6 +1212,17 @@ propagation_context = Sentry.get_current_scope.propagation_context expect(propagation_context.incoming_trace).to eq(false) end + + context "when trace context was already established for this call" do + it "does not regenerate the scope's propagation context" do + existing_propagation_context = Sentry.get_current_scope.propagation_context + + expect(Sentry.get_current_scope).not_to receive(:generate_propagation_context) + described_class.continue_trace(env, established: true) + + expect(Sentry.get_current_scope.propagation_context).to eq(existing_propagation_context) + end + end end context "with incoming sentry trace" do From 87b9ace35c9b2bbcb8f979d2b6cc2f48fc0957c7 Mon Sep 17 00:00:00 2001 From: Peter Solnica Date: Wed, 19 Aug 2026 11:39:53 +0000 Subject: [PATCH 2/4] fix(rails): move CaptureContext in the middleware stack This fixes the issue while ensuring we're not adding Sentry overhead to static file-serving routes, which is why the middleware was moved historically. --- sentry-rails/lib/sentry/rails/railtie.rb | 6 ++++-- sentry-rails/spec/sentry/rails_spec.rb | 15 ++++++++++++++- 2 files changed, 18 insertions(+), 3 deletions(-) diff --git a/sentry-rails/lib/sentry/rails/railtie.rb b/sentry-rails/lib/sentry/rails/railtie.rb index 538b481b9..348f09bc9 100644 --- a/sentry-rails/lib/sentry/rails/railtie.rb +++ b/sentry-rails/lib/sentry/rails/railtie.rb @@ -9,8 +9,10 @@ module Sentry class Railtie < ::Rails::Railtie # middlewares can't be injected after initialize initializer "sentry.use_rack_middleware" do |app| - # placed first so anything logged before CaptureExceptions shares the same trace context - app.config.middleware.unshift Sentry::Rails::CaptureContext + # placed right after the app-request boundary: early enough that anything logged before + # CaptureExceptions shares the same trace context, late enough that file-serving requests, + # which never reach CaptureExceptions, do not pay for a hub clone they never use + app.config.middleware.insert_after ActionDispatch::Executor, Sentry::Rails::CaptureContext # placed after all the file-sending middlewares so we can avoid unnecessary transactions app.config.middleware.insert_after ActionDispatch::ShowExceptions, Sentry::Rails::CaptureExceptions # need to place as close to DebugExceptions as possible to intercept most of the exceptions, including those raised by middlewares diff --git a/sentry-rails/spec/sentry/rails_spec.rb b/sentry-rails/spec/sentry/rails_spec.rb index f0c44cdba..e714274b7 100644 --- a/sentry-rails/spec/sentry/rails_spec.rb +++ b/sentry-rails/spec/sentry/rails_spec.rb @@ -22,13 +22,26 @@ it "inserts middleware to a correct position" do app = Rails.application - expect(app.middleware.first).to eq(Sentry::Rails::CaptureContext) index_of_executor = app.middleware.find_index { |m| m == ActionDispatch::ShowExceptions } expect(app.middleware.find_index(Sentry::Rails::CaptureExceptions)).to eq(index_of_executor + 1) index_of_debug_exceptions = app.middleware.find_index { |m| m == ActionDispatch::DebugExceptions } expect(app.middleware.find_index(Sentry::Rails::RescuedExceptionInterceptor)).to eq(index_of_debug_exceptions + 1) end + it "establishes the trace context before the request is logged" do + middleware = Rails.application.middleware + + expect(middleware.find_index(Sentry::Rails::CaptureContext)) + .to be < middleware.find_index(Rails::Rack::Logger) + end + + it "leaves requests served above the app boundary untouched" do + middleware = Rails.application.middleware + + expect(middleware.find_index(Sentry::Rails::CaptureContext)) + .to be > middleware.find_index(ActionDispatch::Executor) + end + it "propagates timezone to cron config" do # cron.default_timezone is set to nil by default expect(Sentry.configuration.cron.default_timezone).to eq("Etc/UTC") From 3014c49b5e60fa70d3b582aa1d1460e99d1fe680 Mon Sep 17 00:00:00 2001 From: Peter Solnica Date: Wed, 19 Aug 2026 11:43:53 +0000 Subject: [PATCH 3/4] fix: store the propagation context in env instead of a boolean flag The established flag lived in the request-scoped env but certified a thread-local hub, so any middleware doing `@app.call` on another thread lost the incoming trace. The env now carries the context itself, trusted only while it is still the current scope's. --- .../lib/sentry/rails/capture_context.rb | 2 +- .../spec/sentry/rails/capture_context_spec.rb | 40 ++++++++++++++++++- sentry-ruby/lib/sentry/propagation_context.rb | 7 ++-- .../lib/sentry/rack/capture_exceptions.rb | 7 +++- .../sentry/rack/capture_exceptions_spec.rb | 26 ++++++++++-- 5 files changed, 72 insertions(+), 10 deletions(-) diff --git a/sentry-rails/lib/sentry/rails/capture_context.rb b/sentry-rails/lib/sentry/rails/capture_context.rb index 8f8574276..35b0669b7 100644 --- a/sentry-rails/lib/sentry/rails/capture_context.rb +++ b/sentry-rails/lib/sentry/rails/capture_context.rb @@ -14,7 +14,7 @@ def call(env) Sentry.clone_hub_to_current_thread Sentry.get_current_scope.generate_propagation_context(env) - env[Sentry::PropagationContext::ESTABLISHED_ENV_KEY] = true + env[Sentry::PropagationContext::ESTABLISHED_ENV_KEY] = Sentry.get_current_scope.propagation_context @app.call(env) end diff --git a/sentry-rails/spec/sentry/rails/capture_context_spec.rb b/sentry-rails/spec/sentry/rails/capture_context_spec.rb index 06b0d1bb4..0d01697a2 100644 --- a/sentry-rails/spec/sentry/rails/capture_context_spec.rb +++ b/sentry-rails/spec/sentry/rails/capture_context_spec.rb @@ -20,6 +20,20 @@ def call(env) end end + # The shape used by hard-timeout and bulkhead middleware: the downstream stack + # runs on a different thread than the one that entered. Permitting concurrent + # loads around the join is what ActionController::Live does for the same reason. + class ThreadHandoffMiddleware + def initialize(app) + @app = app + end + + def call(env) + thread = Thread.new { @app.call(env) } + ActiveSupport::Dependencies.interlock.permit_concurrent_loads { thread.value } + end + end + describe "#call" do before do make_basic_app @@ -36,7 +50,8 @@ def call(env) env = Rack::MockRequest.env_for("/test") described_class.new(app).call(env) - expect(env[Sentry::PropagationContext::ESTABLISHED_ENV_KEY]).to eq(true) + expect(env[Sentry::PropagationContext::ESTABLISHED_ENV_KEY]) + .to be(Sentry.get_current_scope.propagation_context) expect(trace_id_in_app).to be_a(String) end @@ -57,6 +72,29 @@ def call(env) end end + context "when a middleware hands the request to another thread", type: :request do + let(:transport) { Sentry.get_current_client.transport } + + let(:incoming_transaction) do + Sentry::Transaction.new(op: "pageload", status: "ok", sampled: true, name: "a/path") + end + + before do + make_basic_app do |config, app| + config.traces_sample_rate = 1.0 + app.config.middleware.insert_before(Sentry::Rails::CaptureExceptions, ThreadHandoffMiddleware) + end + end + + it "continues the incoming trace" do + get "/world", headers: { "sentry-trace" => incoming_transaction.to_sentry_trace } + + trace = transport.events.last.contexts[:trace] + expect(trace[:trace_id]).to eq(incoming_transaction.trace_id) + expect(trace[:parent_span_id]).to eq(incoming_transaction.span_id) + end + end + context "when composed with CaptureExceptions", type: :request do before do CaptureContextSpecProbe.captured_trace_ids.clear diff --git a/sentry-ruby/lib/sentry/propagation_context.rb b/sentry-ruby/lib/sentry/propagation_context.rb index fd58f0576..8da7af216 100644 --- a/sentry-ruby/lib/sentry/propagation_context.rb +++ b/sentry-ruby/lib/sentry/propagation_context.rb @@ -13,9 +13,10 @@ class PropagationContext "-?([01])?\\z" # sampled ) - # Rack env key signaling that trace context was already established earlier in - # the middleware stack (e.g. by +Sentry::Rails::CaptureContext+); consumed once by - # +Sentry::Rack::CaptureExceptions+. + # Rack env key carrying the PropagationContext established earlier in the middleware + # stack (e.g. by +Sentry::Rails::CaptureContext+); consumed once by + # +Sentry::Rack::CaptureExceptions+, which only trusts it when it still belongs to the + # current execution context. ESTABLISHED_ENV_KEY = "sentry.trace_context_established" # An uuid that can be used to identify a trace. diff --git a/sentry-ruby/lib/sentry/rack/capture_exceptions.rb b/sentry-ruby/lib/sentry/rack/capture_exceptions.rb index 4c1e59604..342559486 100644 --- a/sentry-ruby/lib/sentry/rack/capture_exceptions.rb +++ b/sentry-ruby/lib/sentry/rack/capture_exceptions.rb @@ -16,8 +16,11 @@ def initialize(app) def call(env) return @app.call(env) unless Sentry.initialized? - # consumed atomically, first, so it can't leak into later reuses of this env - established = env.delete(Sentry::PropagationContext::ESTABLISHED_ENV_KEY) + # consumed atomically, first, so it can't leak into later reuses of this env. + # the env is request-scoped but the hub it certifies is not, so the context only + # counts as established while it still belongs to the execution context we are on + context = env.delete(Sentry::PropagationContext::ESTABLISHED_ENV_KEY) + established = !context.nil? && context.equal?(Sentry.get_current_scope&.propagation_context) # make sure the current thread has a clean hub, unless it was already established Sentry.clone_hub_to_current_thread unless established diff --git a/sentry-ruby/spec/sentry/rack/capture_exceptions_spec.rb b/sentry-ruby/spec/sentry/rack/capture_exceptions_spec.rb index 9886c54b9..c3d2bf6bb 100644 --- a/sentry-ruby/spec/sentry/rack/capture_exceptions_spec.rb +++ b/sentry-ruby/spec/sentry/rack/capture_exceptions_spec.rb @@ -97,7 +97,7 @@ it "does not re-clone the hub and reuses the existing propagation context" do Sentry.clone_hub_to_current_thread Sentry.get_current_scope.generate_propagation_context(env) - env[Sentry::PropagationContext::ESTABLISHED_ENV_KEY] = true + env[Sentry::PropagationContext::ESTABLISHED_ENV_KEY] = Sentry.get_current_scope.propagation_context established_propagation_context = Sentry.get_current_scope.propagation_context @@ -118,7 +118,7 @@ it "deletes the established flag from env so it doesn't leak into later reuses of the same env" do Sentry.clone_hub_to_current_thread Sentry.get_current_scope.generate_propagation_context(env) - env[Sentry::PropagationContext::ESTABLISHED_ENV_KEY] = true + env[Sentry::PropagationContext::ESTABLISHED_ENV_KEY] = Sentry.get_current_scope.propagation_context app = ->(_e) { [200, {}, ['okay']] } stack = Sentry::Rack::CaptureExceptions.new(app) @@ -127,13 +127,33 @@ expect(env.key?(Sentry::PropagationContext::ESTABLISHED_ENV_KEY)).to eq(false) end + it "honors the incoming trace when the established context belongs to another execution context" do + external_transaction = Sentry::Transaction.new(op: "pageload", status: "ok", sampled: true, name: "a/path") + env["HTTP_SENTRY_TRACE"] = external_transaction.to_sentry_trace + + Sentry.clone_hub_to_current_thread + Sentry.get_current_scope.generate_propagation_context(env) + env[Sentry::PropagationContext::ESTABLISHED_ENV_KEY] = Sentry.get_current_scope.propagation_context + + trace_id_in_app = nil + app = lambda do |_e| + trace_id_in_app = Sentry.get_current_scope.get_trace_context[:trace_id] + [200, {}, ['okay']] + end + + stack = Sentry::Rack::CaptureExceptions.new(app) + Thread.new { stack.call(env) }.join + + expect(trace_id_in_app).to eq(external_transaction.trace_id) + end + it "does not reuse a stale established context on a later, unrelated call with the same env" do # Simulates a long-lived connection (e.g. Action Cable) that stores the handshake's # env and reuses it for many separate operations over its lifetime - only the very # first operation immediately following CaptureContext should honor the flag. Sentry.clone_hub_to_current_thread Sentry.get_current_scope.generate_propagation_context(env) - env[Sentry::PropagationContext::ESTABLISHED_ENV_KEY] = true + env[Sentry::PropagationContext::ESTABLISHED_ENV_KEY] = Sentry.get_current_scope.propagation_context app = ->(_e) { [200, {}, ['okay']] } stack = Sentry::Rack::CaptureExceptions.new(app) From 029569e49862b1c3557feab882abf2659df00cc7 Mon Sep 17 00:00:00 2001 From: Peter Solnica Date: Wed, 19 Aug 2026 13:59:02 +0000 Subject: [PATCH 4/4] test(e2e): cover establishing trace context --- .../lib/sentry/transport/debug_transport.rb | 5 +++ spec/apps/rails-mini/app.rb | 40 +++++++++++++++++++ spec/features/trace_context_spec.rb | 37 +++++++++++++++++ spec/support/test_helper.rb | 33 ++++++++++++++- 4 files changed, 113 insertions(+), 2 deletions(-) create mode 100644 spec/features/trace_context_spec.rb diff --git a/sentry-ruby/lib/sentry/transport/debug_transport.rb b/sentry-ruby/lib/sentry/transport/debug_transport.rb index 58d3ffb3e..3a69ca139 100644 --- a/sentry-ruby/lib/sentry/transport/debug_transport.rb +++ b/sentry-ruby/lib/sentry/transport/debug_transport.rb @@ -27,6 +27,11 @@ def send_event(event) backend.send_event(event) end + def send_envelope(envelope) + log_envelope(envelope) + backend.send_envelope(envelope) + end + def log_envelope(envelope) envelope_json = { timestamp: Time.now.utc.iso8601, diff --git a/spec/apps/rails-mini/app.rb b/spec/apps/rails-mini/app.rb index f29c500b6..95753988f 100644 --- a/spec/apps/rails-mini/app.rb +++ b/spec/apps/rails-mini/app.rb @@ -18,6 +18,24 @@ redis_url = ENV.fetch("REDIS_URL", "redis://localhost:6379") Resque.redis = redis_url if defined?(Resque) +# Emits a Sentry log from above Sentry::Rails::CaptureExceptions - the same window +# Rails::Rack::Logger writes its "Started GET ..." line from, and the window where a +# request used to pick up an unrelated or stale trace_id. Scoped to one path so the +# other e2e scenarios keep a quiet log stream. +class EarlyRequestLogMiddleware + PATH = "/trace_context" + + def initialize(app) + @app = app + end + + def call(env) + Sentry.logger.info("early middleware log", source: "middleware") if env["PATH_INFO"] == PATH + + @app.call(env) + end +end + class RailsMiniApp < Rails::Application config.hosts = nil config.secret_key_base = "test_secret_key_base_for_rails_mini_app" @@ -49,6 +67,8 @@ class RailsMiniApp < Rails::Application end config.active_job.queue_adapter = SUPPORTED_ACTIVE_JOB_ADAPTERS[adapter_name] + + config.middleware.insert_before Rails::Rack::Logger, EarlyRequestLogMiddleware config.x.active_job_adapter_name = adapter_name def debug_log_path @@ -75,6 +95,7 @@ def debug_log_path config.background_worker_threads = 0 config.enable_logs = true + config.max_log_events = 1 config.structured_logging.logger_class = Sentry::DebugStructuredLogger config.structured_logging.file_path = debug_log_path.join("sentry_e2e_tests.log") @@ -239,6 +260,24 @@ def set_cors_headers end end +class TraceContextController < ActionController::Base + before_action :set_cors_headers + + def show + Sentry.logger.info("controller log", source: "controller") + + render json: { trace: Sentry.get_current_scope.get_trace_context } + end + + private + + def set_cors_headers + response.headers["Access-Control-Allow-Origin"] = "*" + response.headers["Access-Control-Allow-Methods"] = "GET, POST, PUT, DELETE, OPTIONS" + response.headers["Access-Control-Allow-Headers"] = "Content-Type, Authorization, sentry-trace, baggage" + end +end + class JobsController < ActionController::Base before_action :set_cors_headers @@ -360,6 +399,7 @@ def set_cors_headers get '/health', to: 'events#health' get '/error', to: 'error#error' get '/trace_headers', to: 'events#trace_headers' + get '/trace_context', to: 'trace_context#show' get '/logged_events', to: 'events#logged_events' post '/clear_logged_events', to: 'events#clear_logged_events' diff --git a/spec/features/trace_context_spec.rb b/spec/features/trace_context_spec.rb new file mode 100644 index 000000000..fb8138e3c --- /dev/null +++ b/spec/features/trace_context_spec.rb @@ -0,0 +1,37 @@ +# frozen_string_literal: true + +RSpec.describe "Trace context", type: :e2e do + def early_middleware_logs + logged_log_events.select { |log| log["body"] == "early middleware log" } + end + + def request_transaction + logged_events[:events].find do |event| + event["type"] == "transaction" && event.dig("contexts", "trace", "op") == "http.server" + end + end + + it "gives a log emitted before CaptureExceptions the transaction's trace_id" do + without_trace_propagation { make_request("/trace_context") } + + expect(early_middleware_logs.first["trace_id"]) + .to eq(request_transaction.dig("contexts", "trace", "trace_id")) + end + + it "continues an incoming distributed trace in a log emitted before CaptureExceptions" do + incoming_trace_id = propagated_trace_id + + make_request("/trace_context") + + expect(early_middleware_logs.first["trace_id"]).to eq(incoming_trace_id) + end + + it "starts a new trace for every request that arrives without one" do + without_trace_propagation { 2.times { make_request("/trace_context") } } + + trace_ids = early_middleware_logs.map { |log| log["trace_id"] } + + expect(trace_ids.length).to eq(2) + expect(trace_ids.uniq.length).to eq(2) + end +end diff --git a/spec/support/test_helper.rb b/spec/support/test_helper.rb index 4cceef141..614b2bd6f 100644 --- a/spec/support/test_helper.rb +++ b/spec/support/test_helper.rb @@ -11,8 +11,12 @@ def rails_app_url ENV.fetch("SENTRY_E2E_RAILS_APP_URL") end - def make_request(path) - Net::HTTP.get_response(URI("#{rails_app_url}#{path}")) + def make_request(path, headers = {}) + uri = URI("#{rails_app_url}#{path}") + + Net::HTTP.start(uri.host, uri.port) do |http| + http.request(Net::HTTP::Get.new(uri, headers)) + end end def logged_events @@ -42,6 +46,31 @@ def logged_events end end + # The SDK instruments Net::HTTP and stamps its own sentry-trace on every outgoing + # request, so by default the app continues this process's trace. Turn that off to + # exercise requests that arrive without an incoming trace. + def without_trace_propagation + original = Sentry.configuration.propagate_traces + Sentry.configuration.propagate_traces = false + yield + ensure + Sentry.configuration.propagate_traces = original + end + + def propagated_trace_id + Sentry.get_trace_propagation_headers["sentry-trace"].split("-").first + end + + # Log events travel in their own envelope type rather than as events, so they are + # not part of logged_events[:events]. + def logged_log_events + logged_events[:envelopes].flat_map do |envelope| + envelope["items"] + .select { |item| item["headers"]["type"] == "log" } + .flat_map { |item| item["payload"]["items"] } + end + end + def clear_logged_events Sentry.get_current_client.transport.clear end