Production's log lines name their trace again (#411, #408)

ba18b44 had the JSON layer find a line's span context through the
dispatch it was registered with, and production's logging wrapped that
layer in an Option, whose Layer impl does not pass on_register_dispatch
on: the layer never got its dispatch and every line went out without
trace_id and span_id. The log test built a subscriber of its own,
without the Option, and passed.

Both services now box their stderr layer instead of an Option of each
kind (a Box passes registration on), the formatter falls back to the
default dispatcher when it was never registered, which a global
subscriber's lines find, and the log test builds the subscriber with
the function init uses, writing to its buffer, so a wrapper like this
one is under test.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01RqkrVDqdiQEMWAkNGQ2tYA

crates/directory/src/main.rs

@@ -83,11 +83,16 @@ async fn serve(path: &Path) -> Result<()> {
     let filter = || EnvFilter::try_from_env("DIRECTORY_LOG").unwrap_or_else(|_| "ipx_directory=info".into());
     // Traces to Tempo when OTEL_EXPORTER_OTLP_ENDPOINT is set, joining ipx's (#213).
     let otel = ipx_directory::otel::provider("ipx-directory")?;
+    // Each line's own fields say all its span did, and the span said it again (#363); the trace
+    // and span ids lead to the trace instead, as ipx's do (#375). Boxed rather than an Option of
+    // each: Option's Layer does not pass on_register_dispatch on, which the JSON layer needs (#408).
+    let stderr: Box<dyn tracing_subscriber::Layer<tracing_subscriber::Registry> + Send + Sync> = if json {
+        ipx_directory::otel::json_layer(std::io::stderr, false).with_filter(filter()).boxed()
+    } else {
+        tracing_subscriber::fmt::layer().with_writer(std::io::stderr).with_filter(filter()).boxed()
+    };
     tracing_subscriber::registry()
-        .with((!json).then(|| tracing_subscriber::fmt::layer().with_writer(std::io::stderr).with_filter(filter())))
+        .with(stderr)
-        // Each line's own fields say all its span did, and the span said it again (#363); the trace
-        // and span ids lead to the trace instead, as ipx's do (#375).
-        .with(json.then(|| ipx_directory::otel::json_layer(std::io::stderr, false).with_filter(filter())))
         .with(otel.as_ref().map(|p| {
             use opentelemetry::trace::TracerProvider;
             tracing_opentelemetry::layer()

crates/directory/src/otel.rs

@@ -148,13 +148,15 @@ where
         ev: &tracing::Event<'_>,
     ) -> std::fmt::Result {
         use opentelemetry::trace::TraceContextExt;
-        let dispatch = self.1.0.get().and_then(tracing::dispatcher::WeakDispatch::upgrade);
+        // Without one (a wrapper that does not pass registration on, as Option does not), the
+        // default dispatcher, which a global subscriber's lines still find.
+        let registered = self.1.0.get().and_then(tracing::dispatcher::WeakDispatch::upgrade);
+        let dispatch = registered.unwrap_or_else(|| tracing::dispatcher::get_default(Clone::clone));
         // 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| tracing_opentelemetry::get_otel_context(id, &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);

crates/ipx/src/logging.rs

@@ -8,36 +8,51 @@ use tracing_subscriber::EnvFilter;
 /// Sets up logging: to stderr, as text or as JSON (`IPX_LOG_FORMAT`), into the ring the page's log
 /// reads, and to the trace exporter when there is one.
 pub(crate) fn init(otel: Option<&opentelemetry_sdk::trace::SdkTracerProvider>) {
+    use tracing_subscriber::util::SubscriberInitExt;
+    let json = std::env::var("IPX_LOG_FORMAT").is_ok_and(|f| f.eq_ignore_ascii_case("json"));
+    subscriber(json, otel, std::io::stderr).init();
+}
+
+/// The subscriber `init` installs, writing to `out`: the test's lines are production's.
+fn subscriber<W>(
+    json: bool,
+    otel: Option<&opentelemetry_sdk::trace::SdkTracerProvider>,
+    out: W,
+) -> impl tracing::Subscriber + Send + Sync
+where
+    W: for<'w> tracing_subscriber::fmt::MakeWriter<'w> + Send + Sync + 'static,
+{
     // Everything goes to stderr as before, and is mirrored into a ring the UI can read.
     use tracing_subscriber::Layer;
     use tracing_subscriber::layer::SubscriberExt;
-    use tracing_subscriber::util::SubscriberInitExt;
     // Two filters, deliberately different. stderr follows IPX_LOG; the in-app buffer
     // keeps debug as well, so the log view can show protocol traffic and routine
     // skips that would be noise on a terminal. IPX_UI_LOG overrides it.
     let stderr_filter = || EnvFilter::try_from_env("IPX_LOG").unwrap_or_else(|_| "ipx=info".into());
     // One JSON object a line for Loki (#91), with each event's fields as its own; text
     // otherwise, for someone reading a terminal.
-    let json = std::env::var("IPX_LOG_FORMAT").is_ok_and(|f| f.eq_ignore_ascii_case("json"));
     let ui_filter = EnvFilter::try_from_env("IPX_UI_LOG").unwrap_or_else(|_| "ipx=debug".into());
-    tracing_subscriber::registry()
+    // Boxed rather than an Option of each: Option's Layer does not pass on_register_dispatch on,
-        .with((!json).then(|| {
+    // which the JSON layer finds each line's trace by (#408).
-            tracing_subscriber::fmt::layer()
+    let stderr: Box<dyn Layer<tracing_subscriber::Registry> + Send + Sync> = if json {
-                .with_writer(std::io::stderr)
+        json_layer(out, true).with_filter(stderr_filter()).boxed()
-                // Colour for a terminal only: in docker logs and Loki the escapes are noise
+    } else {
-                // every query has to strip (#88).
+        tracing_subscriber::fmt::layer()
-                .with_ansi(IsTerminal::is_terminal(&std::io::stderr()))
+            .with_writer(out)
-                .with_filter(stderr_filter())
+            // Colour for a terminal only: in docker logs and Loki the escapes are noise
-        }))
+            // every query has to strip (#88).
-        .with(json.then(|| json_layer(std::io::stderr, true).with_filter(stderr_filter())))
+            .with_ansi(IsTerminal::is_terminal(&std::io::stderr()))
-        .with(logbuf::RingLayer.with_filter(ui_filter))
+            .with_filter(stderr_filter())
-        .with(otel.as_ref().map(|p| {
+            .boxed()
+    };
+    tracing_subscriber::registry().with(stderr).with(logbuf::RingLayer.with_filter(ui_filter)).with(otel.as_ref().map(
+        |p| {
             use opentelemetry::trace::TracerProvider;
             tracing_opentelemetry::layer()
                 .with_tracer(p.tracer("ipx"))
                 .with_filter(EnvFilter::new("ipx=info,ipx_feed=info"))
-        }))
+        },
-        .init();
+    ))
 }
 
 #[cfg(test)]
@@ -61,14 +76,10 @@ mod tests {
 
     #[test]
     fn a_scans_events_are_json_lines_with_the_fields_grafana_reads() {
-        use opentelemetry::trace::TracerProvider;
-        use tracing_subscriber::layer::SubscriberExt;
         let buf = Arc::new(Mutex::new(vec![]));
         let b = buf.clone();
         let provider = opentelemetry_sdk::trace::SdkTracerProvider::builder().build();
-        let sub = tracing_subscriber::registry()
+        let sub = subscriber(true, Some(&provider), move || Lines(b.clone()));
-            .with(json_layer(move || Lines(b.clone()), true))
-            .with(tracing_opentelemetry::layer().with_tracer(provider.tracer("test")));
         // Scoped, where the formatter once found no dispatcher and no line named its trace (#408).
         tracing::subscriber::with_default(sub, || {
             let out = Emitter::terminal();