Skip to content

Fix trace_id mismatch for logs emitted before Sentry::Rails::CaptureExceptions runs#3016

Open
runephilosof-abtion wants to merge 1 commit into
getsentry:masterfrom
runephilosof-abtion:fix/early-request-log-trace-context
Open

Fix trace_id mismatch for logs emitted before Sentry::Rails::CaptureExceptions runs#3016
runephilosof-abtion wants to merge 1 commit into
getsentry:masterfrom
runephilosof-abtion:fix/early-request-log-trace-context

Conversation

@runephilosof-abtion

Copy link
Copy Markdown

Fixes #3015

Problem

Sentry::Rails::CaptureExceptions is deliberately positioned right after ActionDispatch::ShowExceptions (to skip transaction creation for static asset requests). That means anything logged before it runs - most notably Rails' own Rails::Rack::Logger "Started ..." line - gets a trace_id/span_id unrelated to the rest of the request, because no trace context has been established yet.

There's also a second, compounding issue: even once CaptureExceptions does run, if the request isn't continuing an incoming distributed trace, Hub#start_transaction's fallback (Transaction.new(**options)) generates its own independent trace_id, ignoring whatever was already on the scope's propagation context.

Fix

  • New Sentry::Rails::CaptureContext middleware, unshifted to the very front of the Rails middleware stack. It only establishes the propagation context (from incoming sentry-trace/baggage headers, if present) as early as possible - it doesn't start a transaction or capture exceptions, so CaptureExceptions's existing position/behavior is untouched.
  • Sentry::PropagationContext::ESTABLISHED_ENV_KEY - a new env flag signaling that trace context was already established for this exact request.
  • Hub#continue_trace skips regenerating the propagation context when the flag is present, instead of clobbering what CaptureContext set up.
  • Sentry::Rack::CaptureExceptions skips re-cloning the hub when the flag is present, for the same reason.
  • Hub#start_transaction, when not continuing a distributed trace and the flag is present (via custom_sampling_context[:env]), builds the new transaction with the already-established trace_id/sample_rand instead of generating an unrelated one.

The start_transaction change is intentionally scoped to only apply when the established flag is present (rather than always reusing whatever's on the scope), to avoid incorrectly linking together unrelated transactions that happen to share a thread (e.g. separate background jobs) - each of those still gets its own independent trace_id as before. This was verified against a regression in sentry-rails' ActiveJob distributed-tracing specs during development.

Testing

  • Added sentry-rails/spec/sentry/rails/capture_context_spec.rb, including an integration-style test that reproduces the original bug (probe middleware inserted before/after CaptureExceptions) both with and without tracing enabled.
  • Added unit coverage in sentry-ruby's hub/capture_exceptions specs for the new established-context guard behavior.
  • Updated sentry-rails' existing middleware-ordering spec to assert CaptureContext is the first middleware.
  • Ran the full sentry-ruby and sentry-rails suites locally; no regressions (Redis-dependent specs fail identically with/without this change due to no local Redis server, pre-existing/environment-only).

@cursor cursor Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Cursor Bugbot has reviewed your changes and found 1 potential issue.

Fix All in Cursor

❌ Bugbot Autofix is OFF. To automatically fix reported issues with cloud agents, enable autofix in the Cursor dashboard.

Want reviews to match your repository better? Bugbot Learning can learn team-specific rules from PR activity. A team admin can enable Learning in the Cursor dashboard.

Reviewed by Cursor Bugbot for commit 096916b. Configure here.

Comment thread sentry-rails/lib/sentry/rails/capture_context.rb
…xceptions runs

Rails::Rack::Logger's "Started ..." line (and anything else logged before
CaptureExceptions runs) previously got a trace_id/span_id unrelated to the
rest of the request, because CaptureExceptions is deliberately positioned
after ActionDispatch::ShowExceptions (to skip transactions for static asset
requests) - so it hadn't established any trace context yet when earlier
middleware logged.

This adds a new, minimal Sentry::Rails::CaptureContext middleware that is
unshifted to the very front of the middleware stack and only establishes the
propagation context (from incoming sentry-trace/baggage headers, if any) as
early as possible, without touching where CaptureExceptions itself runs.

To make CaptureExceptions actually reuse that early context instead of
discarding/regenerating it:
- Sentry::PropagationContext::ESTABLISHED_ENV_KEY is a new env flag that
  signals trace context was already established for this exact request.
- Hub#continue_trace skips regenerating the propagation context when the
  flag is present.
- Sentry::Rack::CaptureExceptions skips re-cloning the hub when the flag is
  present.
- Hub#start_transaction, when not continuing a distributed trace and the
  flag is present (via custom_sampling_context[:env]), builds the new
  transaction with the already-established trace_id/sample_rand instead of
  generating an unrelated one. This was needed because Transaction.new
  otherwise always generates its own independent trace_id when not
  continuing an incoming trace, which would silently diverge from the
  propagation context even after the other two fixes.

The trace_id reuse in start_transaction is intentionally scoped to only
when the established flag is present, to avoid incorrectly linking
together unrelated transactions that happen to share a thread (e.g.
separate background jobs), which have their own propagation context by
default but were never intended to share a trace_id with each other.

Co-Authored-By: GitHub Copilot <noreply@example.com>
@runephilosof-abtion runephilosof-abtion force-pushed the fix/early-request-log-trace-context branch from 096916b to 080acef Compare July 8, 2026 19:08
@runephilosof-abtion

Copy link
Copy Markdown
Author

Should I cut down on the inline code comments?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Rails::Rack::Logger's "Started ..." log line (and anything else logged before Sentry::Rails::CaptureExceptions) gets an unrelated trace_id/span_id

2 participants