diff --git a/crates/directory/src/main.rs b/crates/directory/src/main.rs index 3f2a545..be2c9f5 100644 --- a/crates/directory/src/main.rs +++ b/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 + 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()))) - // 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(stderr) .with(otel.as_ref().map(|p| { use opentelemetry::trace::TracerProvider; tracing_opentelemetry::layer() diff --git a/crates/directory/src/otel.rs b/crates/directory/src/otel.rs index 6d9e821..3857505 100644 --- a/crates/directory/src/otel.rs +++ b/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, d)| tracing_opentelemetry::get_otel_context(id, &d)) + .and_then(|id| tracing_opentelemetry::get_otel_context(id, &dispatch)) .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); diff --git a/crates/ipx/src/logging.rs b/crates/ipx/src/logging.rs index 75de95c..bb61912 100644 --- a/crates/ipx/src/logging.rs +++ b/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( + 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() - .with((!json).then(|| { - tracing_subscriber::fmt::layer() - .with_writer(std::io::stderr) - // Colour for a terminal only: in docker logs and Loki the escapes are noise - // every query has to strip (#88). - .with_ansi(IsTerminal::is_terminal(&std::io::stderr())) - .with_filter(stderr_filter()) - })) - .with(json.then(|| json_layer(std::io::stderr, true).with_filter(stderr_filter()))) - .with(logbuf::RingLayer.with_filter(ui_filter)) - .with(otel.as_ref().map(|p| { + // Boxed rather than an Option of each: Option's Layer does not pass on_register_dispatch on, + // which the JSON layer finds each line's trace by (#408). + let stderr: Box + Send + Sync> = if json { + json_layer(out, true).with_filter(stderr_filter()).boxed() + } else { + tracing_subscriber::fmt::layer() + .with_writer(out) + // Colour for a terminal only: in docker logs and Loki the escapes are noise + // every query has to strip (#88). + .with_ansi(IsTerminal::is_terminal(&std::io::stderr())) + .with_filter(stderr_filter()) + .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() - .with(json_layer(move || Lines(b.clone()), true)) - .with(tracing_opentelemetry::layer().with_tracer(provider.tracer("test"))); + let sub = subscriber(true, Some(&provider), move || Lines(b.clone())); // Scoped, where the formatter once found no dispatcher and no line named its trace (#408). tracing::subscriber::with_default(sub, || { let out = Emitter::terminal();