Log lines name their trace under a scoped subscriber too (#408)

WithTrace found a line's span with Span::current(), which asks the
thread's default dispatcher; inside an event under a scoped subscriber
(with_default), tracing's re-entrancy guard answers with none, so every
line went out without trace_id and span_id. Production, on the global
dispatcher, was not affected, but the log test had to go global for it.

The JSON layer now carries a small layer of its own that keeps the
subscriber it is registered with (on_register_dispatch, a weak handle),
and the formatter takes the registry's current span from its own
context and asks tracing-opentelemetry for its context through that
handle (get_otel_context), with no dispatcher lookup. The log test runs
scoped again; with the old formatter it fails for want of the ids.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01RqkrVDqdiQEMWAkNGQ2tYA
This commit is contained in:
2026-11-07 13:34:24 +00:00
parent 8acf57961e
commit ba18b445ec
2 changed files with 29 additions and 10 deletions

View File

@@ -104,6 +104,8 @@ where
S: tracing::Subscriber + for<'a> tracing_subscriber::registry::LookupSpan<'a>,
W: for<'w> tracing_subscriber::fmt::MakeWriter<'w> + Send + Sync + 'static,
{
use tracing_subscriber::Layer as _;
let registered = Registered::default();
tracing_subscriber::fmt::layer()
.fmt_fields(tracing_subscriber::fmt::format::JsonFields::new())
.event_format(WithTrace(
@@ -112,11 +114,26 @@ where
.flatten_event(true)
.with_current_span(current_span)
.with_span_list(false),
registered.clone(),
))
.with_writer(writer)
.and_then(registered)
}
pub struct WithTrace<F>(pub F);
/// The subscriber the log layer is part of, as it was handed over on registration. The span's
/// OpenTelemetry context is reached through it: `Span::current()` asks the thread's default
/// dispatcher, which inside an event under a scoped subscriber (`with_default`) is hidden by
/// tracing's re-entrancy guard, and every line went out without its ids (#408).
#[derive(Clone, Default)]
struct Registered(std::sync::Arc<std::sync::OnceLock<tracing::dispatcher::WeakDispatch>>);
impl<S: tracing::Subscriber> tracing_subscriber::Layer<S> for Registered {
fn on_register_dispatch(&self, subscriber: &tracing::Dispatch) {
let _ = self.0.set(subscriber.downgrade());
}
}
struct WithTrace<F>(F, Registered);
impl<S, N, F> tracing_subscriber::fmt::FormatEvent<S, N> for WithTrace<F>
where
@@ -131,9 +148,14 @@ where
ev: &tracing::Event<'_>,
) -> std::fmt::Result {
use opentelemetry::trace::TraceContextExt;
use tracing_opentelemetry::OpenTelemetrySpanExt;
let current = tracing::Span::current();
let sc = if current.is_none() { None } else { Some(current.context().span().span_context().clone()) };
let dispatch = self.1.0.get().and_then(tracing::dispatcher::WeakDispatch::upgrade);
// The registry's own current span, not the one this layer's filter would show.
let sc = ctx
.current_span()
.id()
.zip(dispatch)
.and_then(|(id, d)| tracing_opentelemetry::get_otel_context(id, &d))
.map(|cx| cx.span().span_context().clone());
let Some(sc) = sc.filter(|c| c.is_valid()) else {
return self.0.format_event(ctx, w, ev);
};