Log lines lose their trace ids under a scoped subscriber #408
Reference in New Issue
Block a user
Delete Branch "%!s()"
Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?
otel::WithTrace finds the line's span with tracing::Span::current(), which goes through dispatcher::get_default. Inside an event callback under a scoped dispatcher (tracing::subscriber::with_default or set_default), tracing-core's re-entrancy guard makes get_default answer with no dispatcher, so the line is written without trace_id and span_id. Production is unaffected: it sets the global dispatcher, and get_default takes a path without the guard while no scoped one exists. Found writing the log test for #403, which has to set the global dispatcher for this reason. Looking the span up through the formatter's own FmtContext (ctx.lookup_current()) would not depend on the dispatcher.
Looked at while closing the test issues. Not a quick fix: tracing-opentelemetry 0.34 keeps a span's OpenTelemetry data private (OtelDataLock), and every public way to reach it (OpenTelemetrySpanExt::context, get_otel_context) needs the Dispatch, which is exactly what the re-entrancy guard hides inside a callback under a scoped subscriber. A fix would be a layer of ipx's own that records each span's trace and span ids into its extensions on creation (Layer::on_new_span, after the OpenTelemetry layer), which WithTrace then reads through FmtContext::lookup_current. Production is unaffected (a global subscriber), so left open.
Fixed in
ba18b44, withf5a3847for what it broke in production (#411). The JSON layer carries a small layer of its own that keeps the dispatch it is registered with (on_register_dispatch, a weak handle), and WithTrace takes the registry's current span from its FmtContext and asks tracing-opentelemetry for its context through that handle (get_otel_context), so it no longer goes through get_default and its re-entrancy guard. The log test runs under with_default again, on production's own subscriber; with the old formatter it fails for want of the ids. Deployed in ipx 1.5.2-dev and ipx-directory.