From 53d2539370632e23502fcc9893254fc9e1c29a22 Mon Sep 17 00:00:00 2001 From: Leghadjeu-Christian Date: Fri, 5 Dec 2025 22:16:18 +0100 Subject: [PATCH 1/3] feat: Add `experimental_span_attributes` feature to enrich log records with span context --- opentelemetry-appender-tracing/CHANGELOG.md | 2 + opentelemetry-appender-tracing/Cargo.toml | 1 + opentelemetry-appender-tracing/src/layer.rs | 298 +++++++++++++++++++- 3 files changed, 296 insertions(+), 5 deletions(-) diff --git a/opentelemetry-appender-tracing/CHANGELOG.md b/opentelemetry-appender-tracing/CHANGELOG.md index edbdd7ed94..7d9cb267f6 100644 --- a/opentelemetry-appender-tracing/CHANGELOG.md +++ b/opentelemetry-appender-tracing/CHANGELOG.md @@ -2,6 +2,8 @@ ## vNext +- New *experimental* feature to enrich log records with attributes from active tracing spans (`experimental_span_attributes`) + - Remove the `experimental_use_tracing_span_context` since `tracing-opentelemetry` now supports [activating][31901] the OpenTelemetry context for the current tracing span. diff --git a/opentelemetry-appender-tracing/Cargo.toml b/opentelemetry-appender-tracing/Cargo.toml index 2d33fea186..440d1b0873 100644 --- a/opentelemetry-appender-tracing/Cargo.toml +++ b/opentelemetry-appender-tracing/Cargo.toml @@ -34,6 +34,7 @@ pprof = { workspace = true } [features] default = [] experimental_metadata_attributes = ["dep:tracing-log"] +experimental_span_attributes = [] spec_unstable_logs_enabled = ["opentelemetry/spec_unstable_logs_enabled"] bench_profiling = [] diff --git a/opentelemetry-appender-tracing/src/layer.rs b/opentelemetry-appender-tracing/src/layer.rs index cdce2ff122..3c18745410 100644 --- a/opentelemetry-appender-tracing/src/layer.rs +++ b/opentelemetry-appender-tracing/src/layer.rs @@ -178,6 +178,92 @@ impl tracing::field::Visit for EventVisitor<'_, LR> { // TODO: Remaining field types from AnyValue : Bytes, ListAny, Boolean } +#[cfg(feature = "experimental_span_attributes")] +use std::collections::HashMap; +#[cfg(feature = "experimental_span_attributes")] +use std::sync::Arc; + +/// Visitor to extract fields from a tracing span +#[cfg(feature = "experimental_span_attributes")] +struct SpanFieldVisitor { + fields: HashMap, +} + +#[cfg(feature = "experimental_span_attributes")] +impl SpanFieldVisitor { + fn new() -> Self { + Self { + fields: HashMap::new(), + } + } +} + +#[cfg(feature = "experimental_span_attributes")] +impl tracing::field::Visit for SpanFieldVisitor { + fn record_debug(&mut self, field: &tracing::field::Field, value: &dyn std::fmt::Debug) { + self.fields.insert( + field.name().to_string(), + AnyValue::String(format!("{value:?}").into()), + ); + } + + fn record_str(&mut self, field: &tracing::field::Field, value: &str) { + self.fields.insert( + field.name().to_string(), + AnyValue::String(value.to_owned().into()), + ); + } + + fn record_i64(&mut self, field: &tracing::field::Field, value: i64) { + self.fields + .insert(field.name().to_string(), AnyValue::Int(value)); + } + + fn record_u64(&mut self, field: &tracing::field::Field, value: u64) { + let any_value = if let Ok(signed) = i64::try_from(value) { + AnyValue::Int(signed) + } else { + AnyValue::String(format!("{value}").into()) + }; + self.fields.insert(field.name().to_string(), any_value); + } + + fn record_bool(&mut self, field: &tracing::field::Field, value: bool) { + self.fields + .insert(field.name().to_string(), AnyValue::Boolean(value)); + } + + fn record_f64(&mut self, field: &tracing::field::Field, value: f64) { + self.fields + .insert(field.name().to_string(), AnyValue::Double(value)); + } + + fn record_i128(&mut self, field: &tracing::field::Field, value: i128) { + let any_value = if let Ok(signed) = i64::try_from(value) { + AnyValue::Int(signed) + } else { + AnyValue::String(format!("{value}").into()) + }; + self.fields.insert(field.name().to_string(), any_value); + } + + fn record_u128(&mut self, field: &tracing::field::Field, value: u128) { + let any_value = if let Ok(signed) = i64::try_from(value) { + AnyValue::Int(signed) + } else { + AnyValue::String(format!("{value}").into()) + }; + self.fields.insert(field.name().to_string(), any_value); + } +} + +/// Stored span attributes in the span's extensions +#[cfg(feature = "experimental_span_attributes")] +#[derive(Debug, Clone)] +struct StoredSpanAttributes { + attributes: Arc>, +} + pub struct OpenTelemetryTracingBridge where P: LoggerProvider + Send + Sync, @@ -211,11 +297,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>) { let metadata = event.metadata(); let severity = severity_of_level(metadata.level()); let target = metadata.target(); @@ -238,6 +320,21 @@ where log_record.set_event_name(name); log_record.set_severity_number(severity); log_record.set_severity_text(metadata.level().as_str()); + + // Extract span attributes if feature is enabled + #[cfg(feature = "experimental_span_attributes")] + { + if let Some(span) = ctx.event_span(event) { + let extensions = span.extensions(); + if let Some(stored) = extensions.get::() { + // Add span attributes FIRST (event attributes will overwrite on conflict) + for (key, value) in stored.attributes.iter() { + log_record.add_attribute(Key::new(key.clone()), value.clone()); + } + } + } + } + let mut visitor = EventVisitor::new(&mut log_record); #[cfg(feature = "experimental_metadata_attributes")] visitor.visit_experimental_metadata(meta); @@ -247,6 +344,28 @@ where //emit record self.logger.emit(log_record); } + #[cfg(feature = "experimental_span_attributes")] + fn on_new_span( + &self, + attrs: &tracing::span::Attributes<'_>, + id: &tracing::span::Id, + ctx: tracing_subscriber::layer::Context<'_, S>, + ) { + let span = ctx.span(id).expect("Span not found; this is a bug"); + + let mut visitor = SpanFieldVisitor::new(); + attrs.record(&mut visitor); + + // Only store if we actually found attributes to avoid empty allocations + if !visitor.fields.is_empty() { + let stored = StoredSpanAttributes { + attributes: Arc::new(visitor.fields), + }; + + let mut extensions = span.extensions_mut(); + extensions.insert(stored); + } + } } const fn severity_of_level(level: &Level) -> Severity { @@ -824,4 +943,173 @@ mod tests { // The validation is done in the LogProcessorWithIsEnabled struct. error!(name: "my-event-name", target: "my-system", event_id = 20, user_name = "otel", user_email = "otel@opentelemetry.io"); } + + #[test] + #[cfg(feature = "experimental_span_attributes")] + fn test_span_context_enrichment_enabled() { + // Arrange + let exporter = InMemoryLogExporter::default(); + let provider = SdkLoggerProvider::builder() + .with_simple_exporter(exporter.clone()) + .build(); + + let layer = layer::OpenTelemetryTracingBridge::new(&provider); + let subscriber = tracing_subscriber::registry().with(layer); + let _guard = tracing::subscriber::set_default(subscriber); + + // Act + let span = tracing::info_span!("test_span", user_id = 123, endpoint = "/api/users"); + let _enter = span.enter(); + tracing::error!(status = 200, "test message"); + + provider.force_flush().unwrap(); + + // Assert + let logs = exporter.get_emitted_logs().unwrap(); + assert_eq!(logs.len(), 1); + let log = &logs[0]; + + // Should contain span attributes + assert!(attributes_contains( + &log.record, + &Key::new("user_id"), + &AnyValue::Int(123) + )); + assert!(attributes_contains( + &log.record, + &Key::new("endpoint"), + &AnyValue::String("/api/users".into()) + )); + + // Should also contain event attribute + assert!(attributes_contains( + &log.record, + &Key::new("status"), + &AnyValue::Int(200) + )); + } + + #[test] + #[cfg(feature = "experimental_span_attributes")] + fn test_event_attributes_overwrite_span_attributes() { + // Arrange + let exporter = InMemoryLogExporter::default(); + let provider = SdkLoggerProvider::builder() + .with_simple_exporter(exporter.clone()) + .build(); + + let layer = layer::OpenTelemetryTracingBridge::new(&provider); + let subscriber = tracing_subscriber::registry().with(layer); + let _guard = tracing::subscriber::set_default(subscriber); + + // Act: span has "status" = "pending", event has "status" = "completed" + let span = tracing::info_span!("test_span", status = "pending"); + let _enter = span.enter(); + tracing::error!(status = "completed", "test message"); + + provider.force_flush().unwrap(); + + // Assert + let logs = exporter.get_emitted_logs().unwrap(); + assert_eq!(logs.len(), 1); + let log = &logs[0]; + + // Event's "status" should win + assert!(attributes_contains( + &log.record, + &Key::new("status"), + &AnyValue::String("completed".into()) + )); + } + + #[test] + #[cfg(feature = "experimental_span_attributes")] + fn test_span_context_with_various_types() { + // Arrange + let exporter = InMemoryLogExporter::default(); + let provider = SdkLoggerProvider::builder() + .with_simple_exporter(exporter.clone()) + .build(); + + let layer = layer::OpenTelemetryTracingBridge::new(&provider); + let subscriber = tracing_subscriber::registry().with(layer); + let _guard = tracing::subscriber::set_default(subscriber); + + // Act + let span = tracing::info_span!( + "test_span", + str_field = "text", + int_field = 42, + float_field = 3.14, + bool_field = true + ); + let _enter = span.enter(); + tracing::error!("test message"); + + provider.force_flush().unwrap(); + + // Assert + let logs = exporter.get_emitted_logs().unwrap(); + assert_eq!(logs.len(), 1); + let log = &logs[0]; + + assert!(attributes_contains( + &log.record, + &Key::new("str_field"), + &AnyValue::String("text".into()) + )); + assert!(attributes_contains( + &log.record, + &Key::new("int_field"), + &AnyValue::Int(42) + )); + assert!(attributes_contains( + &log.record, + &Key::new("float_field"), + &AnyValue::Double(3.14) + )); + assert!(attributes_contains( + &log.record, + &Key::new("bool_field"), + &AnyValue::Boolean(true) + )); + } + + #[test] + #[cfg(feature = "experimental_span_attributes")] + fn test_no_span_attributes_when_no_span() { + // Arrange + let exporter = InMemoryLogExporter::default(); + let provider = SdkLoggerProvider::builder() + .with_simple_exporter(exporter.clone()) + .build(); + + let layer = layer::OpenTelemetryTracingBridge::new(&provider); + let subscriber = tracing_subscriber::registry().with(layer); + let _guard = tracing::subscriber::set_default(subscriber); + + // Act: No span entered + tracing::error!(status = 200, "test message"); + + provider.force_flush().unwrap(); + + // Assert + let logs = exporter.get_emitted_logs().unwrap(); + assert_eq!(logs.len(), 1); + let log = &logs[0]; + + // Should only have event attribute + assert!(attributes_contains( + &log.record, + &Key::new("status"), + &AnyValue::Int(200) + )); + + // Should not have any span attributes + let has_user_id = log + .record + .attributes_iter() + .any(|(k, _)| k.as_str() == "user_id"); + assert!(!has_user_id); + } } From 99b7bb4516c31f4508514cc2b7bc6b39f5af4af7 Mon Sep 17 00:00:00 2001 From: Leghadjeu-Christian Date: Wed, 10 Dec 2025 02:02:17 +0100 Subject: [PATCH 2/3] chore: add allow unused variables and conflict resolution todo --- opentelemetry-appender-tracing/src/layer.rs | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/opentelemetry-appender-tracing/src/layer.rs b/opentelemetry-appender-tracing/src/layer.rs index 9409fde946..94ae18497b 100644 --- a/opentelemetry-appender-tracing/src/layer.rs +++ b/opentelemetry-appender-tracing/src/layer.rs @@ -297,6 +297,7 @@ where P: LoggerProvider + Send + Sync + 'static, L: Logger + Send + Sync + 'static, { + #[allow(unused_variables)] fn on_event(&self, event: &tracing::Event<'_>, ctx: tracing_subscriber::layer::Context<'_, S>) { let metadata = event.metadata(); let severity = severity_of_level(metadata.level()); @@ -326,7 +327,7 @@ where if let Some(span) = ctx.event_span(event) { let extensions = span.extensions(); if let Some(stored) = extensions.get::() { - // Add span attributes FIRST (event attributes will overwrite on conflict) + // Add span attributes first (event attributes will overwrite on conflict). TODO: Consider conflict resolution strategies. for (key, value) in stored.attributes.iter() { log_record.add_attribute(Key::new(key.clone()), value.clone()); } @@ -1037,7 +1038,7 @@ mod tests { "test_span", str_field = "text", int_field = 42, - float_field = 3.14, + float_field = 1.5, bool_field = true ); let _enter = span.enter(); @@ -1063,7 +1064,7 @@ mod tests { assert!(attributes_contains( &log.record, &Key::new("float_field"), - &AnyValue::Double(3.14) + &AnyValue::Double(1.5) )); assert!(attributes_contains( &log.record, From 4a078f61cf60046ecfb3c48f0ae7734937cce566 Mon Sep 17 00:00:00 2001 From: Leghadjeu-Christian Date: Fri, 19 Dec 2025 17:25:27 +0100 Subject: [PATCH 3/3] fix: update comment for clarity on span attributes handling --- opentelemetry-appender-tracing/src/layer.rs | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/opentelemetry-appender-tracing/src/layer.rs b/opentelemetry-appender-tracing/src/layer.rs index 94ae18497b..145cc07c59 100644 --- a/opentelemetry-appender-tracing/src/layer.rs +++ b/opentelemetry-appender-tracing/src/layer.rs @@ -327,7 +327,8 @@ where if let Some(span) = ctx.event_span(event) { let extensions = span.extensions(); if let Some(stored) = extensions.get::() { - // Add span attributes first (event attributes will overwrite on conflict). TODO: Consider conflict resolution strategies. + // Add span attributes before event attributes. + // TODO: Consider conflict resolution strategies. for (key, value) in stored.attributes.iter() { log_record.add_attribute(Key::new(key.clone()), value.clone()); }