From 48ea3905b24852f773741e6875f457254325ece6 Mon Sep 17 00:00:00 2001 From: Morgante Pell Date: Mon, 21 Oct 2024 11:36:51 -0500 Subject: [PATCH 1/3] fix: attempt to add trace context to logs --- crates/cli/Cargo.toml | 1 + crates/cli/src/tracing_bridge.rs | 25 +++++++++++++++++++------ 2 files changed, 20 insertions(+), 6 deletions(-) diff --git a/crates/cli/Cargo.toml b/crates/cli/Cargo.toml index 4edaf29e5..cf4f519b2 100644 --- a/crates/cli/Cargo.toml +++ b/crates/cli/Cargo.toml @@ -156,5 +156,6 @@ grit_beta = [ "remote_workflows", "workflow_server", # "grit_timing", + # "grit_tracing", ] grit_timing = [] diff --git a/crates/cli/src/tracing_bridge.rs b/crates/cli/src/tracing_bridge.rs index a3379f6cc..0defd7ed8 100644 --- a/crates/cli/src/tracing_bridge.rs +++ b/crates/cli/src/tracing_bridge.rs @@ -167,11 +167,7 @@ where P: LoggerProvider + Send + Sync + 'static, L: Logger + Send + Sync + 'static, { - fn on_event( - &self, - event: &tracing::Event<'_>, - _ctx: tracing_subscriber::layer::Context<'_, S>, - ) { + fn on_event(&self, event: &tracing::Event<'_>, ctx: tracing_subscriber::layer::Context<'_, S>) { #[cfg(feature = "experimental_metadata_attributes")] let normalized_meta = event.normalized_metadata(); #[cfg(feature = "experimental_metadata_attributes")] @@ -186,7 +182,24 @@ where // Extract the trace_id & span_id from the opentelemetry extension. // This isn't really working for us. - // set_trace_context(&mut log_record, &_ctx); + if let Some((trace_id, span_id)) = ctx.lookup_current().and_then(|span| { + span.extensions() + .get::() + .and_then(|ext| ext.builder.trace_id.zip(ext.builder.span_id)) + }) { + log_record.trace_context = Some(opentelemetry::logs::TraceContext::from( + &opentelemetry::trace::SpanContext::new( + trace_id, + span_id, + opentelemetry::trace::TraceFlags::default(), + false, + opentelemetry::trace::TraceState::default(), + ), + )); + eprintln!("trace_id: {:?}, span_id: {:?}", trace_id, span_id); + } else { + eprintln!("No trace_id or span_id found"); + } // Not populating ObservedTimestamp, instead relying on OpenTelemetry // API to populate it with current time. From 6151193d456500ceb3c9ede2d4625197f9f9e328 Mon Sep 17 00:00:00 2001 From: Morgante Pell Date: Mon, 21 Oct 2024 18:46:58 -0500 Subject: [PATCH 2/3] ok, this works --- crates/cli/src/tracing_bridge.rs | 29 ++++++++++++++++------------- 1 file changed, 16 insertions(+), 13 deletions(-) diff --git a/crates/cli/src/tracing_bridge.rs b/crates/cli/src/tracing_bridge.rs index 0defd7ed8..7b94515ce 100644 --- a/crates/cli/src/tracing_bridge.rs +++ b/crates/cli/src/tracing_bridge.rs @@ -167,7 +167,11 @@ where P: LoggerProvider + Send + Sync + 'static, L: Logger + Send + Sync + 'static, { - fn on_event(&self, event: &tracing::Event<'_>, ctx: tracing_subscriber::layer::Context<'_, S>) { + fn on_event( + &self, + event: &tracing::Event<'_>, + _ctx: tracing_subscriber::layer::Context<'_, S>, + ) { #[cfg(feature = "experimental_metadata_attributes")] let normalized_meta = event.normalized_metadata(); #[cfg(feature = "experimental_metadata_attributes")] @@ -180,13 +184,16 @@ where log_record.severity_number = Some(severity_of_level(meta.level())); log_record.severity_text = Some(meta.level().to_string().into()); - // Extract the trace_id & span_id from the opentelemetry extension. - // This isn't really working for us. - if let Some((trace_id, span_id)) = ctx.lookup_current().and_then(|span| { - span.extensions() - .get::() - .and_then(|ext| ext.builder.trace_id.zip(ext.builder.span_id)) - }) { + // Extract the trace_id & span_id from *tracing*, which propagates across async boundaries better + use opentelemetry::trace::TraceContextExt; + use tracing_opentelemetry::OpenTelemetrySpanExt; + let s = tracing::Span::current().context(); + + if s.has_active_span() { + let sr = s.span(); + let sc = sr.span_context(); + let trace_id = sc.trace_id(); + let span_id = sc.span_id(); log_record.trace_context = Some(opentelemetry::logs::TraceContext::from( &opentelemetry::trace::SpanContext::new( trace_id, @@ -196,14 +203,10 @@ where opentelemetry::trace::TraceState::default(), ), )); - eprintln!("trace_id: {:?}, span_id: {:?}", trace_id, span_id); } else { - eprintln!("No trace_id or span_id found"); + // eprintln!("no active span"); } - // Not populating ObservedTimestamp, instead relying on OpenTelemetry - // API to populate it with current time. - let mut visitor = EventVisitor::default(); visitor.visit_metadata(meta); // Visit fields. From aadf086ab7df381cc9f8bee686210552047f6852 Mon Sep 17 00:00:00 2001 From: Morgante Pell Date: Mon, 21 Oct 2024 18:49:20 -0500 Subject: [PATCH 3/3] run the tests