From fb2af021918fb7adcfd9a01e121a4c7413c90d56 Mon Sep 17 00:00:00 2001 From: Dylan Thacker-Smith Date: Fri, 13 Dec 2024 14:55:33 -0500 Subject: [PATCH 1/8] appender-tracing: Include trace ID and span ID in logs when nested in spans --- Cargo.toml | 5 ++ opentelemetry-appender-tracing/CHANGELOG.md | 1 + opentelemetry-appender-tracing/Cargo.toml | 2 + opentelemetry-appender-tracing/src/layer.rs | 88 +++++++++++++++++++-- 4 files changed, 89 insertions(+), 7 deletions(-) diff --git a/Cargo.toml b/Cargo.toml index 99d8906132..b008d6ebc5 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -51,3 +51,8 @@ tracing = { version = ">=0.1.40", default-features = false } tracing-core = { version = ">=0.1.33", default-features = false } tracing-subscriber = { version = "0.3", default-features = false } url = { version = "2.5", default-features = false } + +[patch.crates-io] +opentelemetry = { path = "opentelemetry" } +opentelemetry_sdk = { path = "opentelemetry-sdk" } +opentelemetry-stdout = { path = "opentelemetry-stdout" } diff --git a/opentelemetry-appender-tracing/CHANGELOG.md b/opentelemetry-appender-tracing/CHANGELOG.md index 9fac13a4b2..415e284925 100644 --- a/opentelemetry-appender-tracing/CHANGELOG.md +++ b/opentelemetry-appender-tracing/CHANGELOG.md @@ -3,6 +3,7 @@ ## vNext - Bump msrv to 1.75.0. +- Include trace_id & span_id when logging from inside a tracing span ## 0.27.0 diff --git a/opentelemetry-appender-tracing/Cargo.toml b/opentelemetry-appender-tracing/Cargo.toml index e3c682b77d..d9aacc9422 100644 --- a/opentelemetry-appender-tracing/Cargo.toml +++ b/opentelemetry-appender-tracing/Cargo.toml @@ -13,10 +13,12 @@ rust-version = "1.75.0" [dependencies] log = { workspace = true, optional = true } opentelemetry = { version = "0.27", path = "../opentelemetry", features = ["logs"] } +opentelemetry_sdk = { version = "0.27", path = "../opentelemetry-sdk", features = ["logs"] } tracing = { workspace = true, features = ["std"]} tracing-core = { workspace = true } tracing-log = { version = "0.2", optional = true } tracing-subscriber = { workspace = true, features = ["registry", "std"] } +tracing-opentelemetry = { version = "0.28" } [dev-dependencies] log = { workspace = true } diff --git a/opentelemetry-appender-tracing/src/layer.rs b/opentelemetry-appender-tracing/src/layer.rs index 9ba43f7d65..b3821fb24f 100644 --- a/opentelemetry-appender-tracing/src/layer.rs +++ b/opentelemetry-appender-tracing/src/layer.rs @@ -8,7 +8,8 @@ use tracing_core::Level; use tracing_core::Metadata; #[cfg(feature = "experimental_metadata_attributes")] use tracing_log::NormalizeEvent; -use tracing_subscriber::Layer; +use tracing_opentelemetry::OtelData; +use tracing_subscriber::{registry::LookupSpan, Layer}; const INSTRUMENTATION_LIBRARY_NAME: &str = "opentelemetry-appender-tracing"; @@ -149,15 +150,11 @@ where impl Layer for OpenTelemetryTracingBridge where - S: tracing::Subscriber, + S: tracing::Subscriber + for<'a> LookupSpan<'a>, 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(); @@ -180,6 +177,24 @@ where // Visit fields. event.record(&mut visitor); + if let Some(span) = ctx.event_span(event) { + let opt_span_id = span + .extensions() + .get::() + .and_then(|otd| otd.builder.span_id); + + let opt_trace_id = span.scope().last().and_then(|root_span| { + root_span + .extensions() + .get::() + .and_then(|otd| otd.builder.trace_id) + }); + + if let Some((trace_id, span_id)) = opt_trace_id.zip(opt_span_id) { + log_record.set_trace_context(trace_id, span_id, None); + } + } + //emit record self.logger.emit(log_record); } @@ -217,6 +232,7 @@ mod tests { use opentelemetry_sdk::export::logs::{LogBatch, LogExporter}; use opentelemetry_sdk::logs::{LogRecord, LogResult, LoggerProvider}; use opentelemetry_sdk::testing::logs::InMemoryLogExporter; + use opentelemetry_sdk::testing::trace::InMemorySpanExporterBuilder; use opentelemetry_sdk::trace::{Sampler, TracerProvider}; use tracing::{error, warn}; use tracing_subscriber::prelude::__tracing_subscriber_SubscriberExt; @@ -491,6 +507,64 @@ mod tests { } } + #[test] + fn tracing_appender_inside_tracing_crate_context() { + // Arrange + let exporter: InMemoryLogExporter = InMemoryLogExporter::default(); + let logger_provider = LoggerProvider::builder() + .with_simple_exporter(exporter.clone()) + .build(); + + // setup tracing layer to compare trace/span IDs against + let span_exporter = InMemorySpanExporterBuilder::new().build(); + let tracer_provider = TracerProvider::builder() + .with_simple_exporter(span_exporter.clone()) + .build(); + let tracer = tracer_provider.tracer("test-tracer"); + + let level_filter = tracing_subscriber::filter::LevelFilter::INFO; + let log_layer = + layer::OpenTelemetryTracingBridge::new(&logger_provider).with_filter(level_filter); + + let subscriber = tracing_subscriber::registry() + .with(log_layer) + .with(tracing_opentelemetry::layer().with_tracer(tracer)); + + // Avoiding global subscriber.init() as that does not play well with unit tests. + let _guard = tracing::subscriber::set_default(subscriber); + + // Act + tracing::info_span!("outer-span").in_scope(|| { + error!("first-event"); + + tracing::info_span!("inner-span").in_scope(|| { + error!("second-event"); + }); + }); + + logger_provider.force_flush(); + + let logs = exporter.get_emitted_logs().expect("No emitted logs"); + assert_eq!(logs.len(), 2); + + let spans = span_exporter.get_finished_spans().unwrap(); + assert_eq!(spans.len(), 2); + + let trace_id = spans[0].span_context.trace_id(); + assert_eq!(trace_id, spans[1].span_context.trace_id()); + let inner_span_id = spans[0].span_context.span_id(); + let outer_span_id = spans[1].span_context.span_id(); + assert_eq!(outer_span_id, spans[0].parent_span_id); + + let trace_ctx0 = logs[0].record.trace_context().unwrap(); + let trace_ctx1 = logs[1].record.trace_context().unwrap(); + + assert_eq!(trace_ctx0.trace_id, trace_id); + assert_eq!(trace_ctx1.trace_id, trace_id); + assert_eq!(trace_ctx0.span_id, outer_span_id); + assert_eq!(trace_ctx1.span_id, inner_span_id); + } + #[test] fn tracing_appender_standalone_with_tracing_log() { // Arrange From d08b480eae608bbfcd09c8a78402279c95c231b6 Mon Sep 17 00:00:00 2001 From: Dylan Thacker-Smith Date: Tue, 17 Dec 2024 00:47:15 -0500 Subject: [PATCH 2/8] appender-tracing: Make tracing-opentelemetry integration optional --- opentelemetry-appender-tracing/Cargo.toml | 4 +++- opentelemetry-appender-tracing/src/layer.rs | 15 +++++++++++---- 2 files changed, 14 insertions(+), 5 deletions(-) diff --git a/opentelemetry-appender-tracing/Cargo.toml b/opentelemetry-appender-tracing/Cargo.toml index d9aacc9422..0a974f6f17 100644 --- a/opentelemetry-appender-tracing/Cargo.toml +++ b/opentelemetry-appender-tracing/Cargo.toml @@ -18,7 +18,7 @@ tracing = { workspace = true, features = ["std"]} tracing-core = { workspace = true } tracing-log = { version = "0.2", optional = true } tracing-subscriber = { workspace = true, features = ["registry", "std"] } -tracing-opentelemetry = { version = "0.28" } +tracing-opentelemetry = { version = "0.28", optional = true } [dev-dependencies] log = { workspace = true } @@ -34,8 +34,10 @@ tokio = { workspace = true, features = ["full"]} pprof = { version = "0.13", features = ["flamegraph", "criterion"] } [features] +default = ["tracing"] experimental_metadata_attributes = ["dep:tracing-log"] spec_unstable_logs_enabled = ["opentelemetry/spec_unstable_logs_enabled"] +tracing = ["tracing-opentelemetry"] [[bench]] diff --git a/opentelemetry-appender-tracing/src/layer.rs b/opentelemetry-appender-tracing/src/layer.rs index b3821fb24f..b6a5ca3267 100644 --- a/opentelemetry-appender-tracing/src/layer.rs +++ b/opentelemetry-appender-tracing/src/layer.rs @@ -8,7 +8,6 @@ use tracing_core::Level; use tracing_core::Metadata; #[cfg(feature = "experimental_metadata_attributes")] use tracing_log::NormalizeEvent; -use tracing_opentelemetry::OtelData; use tracing_subscriber::{registry::LookupSpan, Layer}; const INSTRUMENTATION_LIBRARY_NAME: &str = "opentelemetry-appender-tracing"; @@ -154,7 +153,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(); @@ -177,7 +180,9 @@ where // Visit fields. event.record(&mut visitor); - if let Some(span) = ctx.event_span(event) { + #[cfg(feature = "tracing")] + if let Some(span) = _ctx.event_span(event) { + use tracing_opentelemetry::OtelData; let opt_span_id = span .extensions() .get::() @@ -232,7 +237,6 @@ mod tests { use opentelemetry_sdk::export::logs::{LogBatch, LogExporter}; use opentelemetry_sdk::logs::{LogRecord, LogResult, LoggerProvider}; use opentelemetry_sdk::testing::logs::InMemoryLogExporter; - use opentelemetry_sdk::testing::trace::InMemorySpanExporterBuilder; use opentelemetry_sdk::trace::{Sampler, TracerProvider}; use tracing::{error, warn}; use tracing_subscriber::prelude::__tracing_subscriber_SubscriberExt; @@ -507,8 +511,11 @@ mod tests { } } + #[cfg(feature = "tracing")] #[test] fn tracing_appender_inside_tracing_crate_context() { + use opentelemetry_sdk::testing::trace::InMemorySpanExporterBuilder; + // Arrange let exporter: InMemoryLogExporter = InMemoryLogExporter::default(); let logger_provider = LoggerProvider::builder() From c6e1141efcb78716791c49a52a7e805988af055d Mon Sep 17 00:00:00 2001 From: Dylan Thacker-Smith Date: Tue, 17 Dec 2024 14:39:41 -0500 Subject: [PATCH 3/8] Make the new feature experimental --- opentelemetry-appender-tracing/CHANGELOG.md | 2 +- opentelemetry-appender-tracing/Cargo.toml | 3 +-- opentelemetry-appender-tracing/src/layer.rs | 4 ++-- 3 files changed, 4 insertions(+), 5 deletions(-) diff --git a/opentelemetry-appender-tracing/CHANGELOG.md b/opentelemetry-appender-tracing/CHANGELOG.md index 415e284925..0bc132fb82 100644 --- a/opentelemetry-appender-tracing/CHANGELOG.md +++ b/opentelemetry-appender-tracing/CHANGELOG.md @@ -3,7 +3,7 @@ ## vNext - Bump msrv to 1.75.0. -- Include trace_id & span_id when logging from inside a tracing span +- New experimental feature to use trace\_id & span\_id from spans created through the tracing crate (experimental-use-tracing-span-context) [#2438](https://github.com/open-telemetry/opentelemetry-rust/pull/2438) ## 0.27.0 diff --git a/opentelemetry-appender-tracing/Cargo.toml b/opentelemetry-appender-tracing/Cargo.toml index 0a974f6f17..e03cea78b2 100644 --- a/opentelemetry-appender-tracing/Cargo.toml +++ b/opentelemetry-appender-tracing/Cargo.toml @@ -34,10 +34,9 @@ tokio = { workspace = true, features = ["full"]} pprof = { version = "0.13", features = ["flamegraph", "criterion"] } [features] -default = ["tracing"] experimental_metadata_attributes = ["dep:tracing-log"] spec_unstable_logs_enabled = ["opentelemetry/spec_unstable_logs_enabled"] -tracing = ["tracing-opentelemetry"] +experimental-use-tracing-span-context = ["tracing-opentelemetry"] [[bench]] diff --git a/opentelemetry-appender-tracing/src/layer.rs b/opentelemetry-appender-tracing/src/layer.rs index b6a5ca3267..c08b3fd555 100644 --- a/opentelemetry-appender-tracing/src/layer.rs +++ b/opentelemetry-appender-tracing/src/layer.rs @@ -180,7 +180,7 @@ where // Visit fields. event.record(&mut visitor); - #[cfg(feature = "tracing")] + #[cfg(feature = "experimental-use-tracing-span-context")] if let Some(span) = _ctx.event_span(event) { use tracing_opentelemetry::OtelData; let opt_span_id = span @@ -511,7 +511,7 @@ mod tests { } } - #[cfg(feature = "tracing")] + #[cfg(feature = "experimental-use-tracing-span-context")] #[test] fn tracing_appender_inside_tracing_crate_context() { use opentelemetry_sdk::testing::trace::InMemorySpanExporterBuilder; From 12cf39955f9e3d3ebae9fc2e3214bcce295f3aa2 Mon Sep 17 00:00:00 2001 From: Dylan Thacker-Smith Date: Tue, 17 Dec 2024 16:44:17 -0500 Subject: [PATCH 4/8] appender-tracing: Remove undesired dependency on opentelemetry_sdk --- opentelemetry-appender-tracing/Cargo.toml | 1 - 1 file changed, 1 deletion(-) diff --git a/opentelemetry-appender-tracing/Cargo.toml b/opentelemetry-appender-tracing/Cargo.toml index e03cea78b2..34503b47c9 100644 --- a/opentelemetry-appender-tracing/Cargo.toml +++ b/opentelemetry-appender-tracing/Cargo.toml @@ -13,7 +13,6 @@ rust-version = "1.75.0" [dependencies] log = { workspace = true, optional = true } opentelemetry = { version = "0.27", path = "../opentelemetry", features = ["logs"] } -opentelemetry_sdk = { version = "0.27", path = "../opentelemetry-sdk", features = ["logs"] } tracing = { workspace = true, features = ["std"]} tracing-core = { workspace = true } tracing-log = { version = "0.2", optional = true } From 750df51821af17e926b3b9c14abc1a322874925b Mon Sep 17 00:00:00 2001 From: Dylan Thacker-Smith Date: Wed, 18 Dec 2024 13:42:27 -0500 Subject: [PATCH 5/8] s/experimental-use-tracing-span-context/experimental_use_tracing_span_context/ --- opentelemetry-appender-tracing/CHANGELOG.md | 2 +- opentelemetry-appender-tracing/Cargo.toml | 2 +- opentelemetry-appender-tracing/src/layer.rs | 4 ++-- 3 files changed, 4 insertions(+), 4 deletions(-) diff --git a/opentelemetry-appender-tracing/CHANGELOG.md b/opentelemetry-appender-tracing/CHANGELOG.md index 0bc132fb82..293da80f81 100644 --- a/opentelemetry-appender-tracing/CHANGELOG.md +++ b/opentelemetry-appender-tracing/CHANGELOG.md @@ -3,7 +3,7 @@ ## vNext - Bump msrv to 1.75.0. -- New experimental feature to use trace\_id & span\_id from spans created through the tracing crate (experimental-use-tracing-span-context) [#2438](https://github.com/open-telemetry/opentelemetry-rust/pull/2438) +- New experimental feature to use trace\_id & span\_id from spans created through the tracing crate (experimental_use_tracing_span_context) [#2438](https://github.com/open-telemetry/opentelemetry-rust/pull/2438) ## 0.27.0 diff --git a/opentelemetry-appender-tracing/Cargo.toml b/opentelemetry-appender-tracing/Cargo.toml index 34503b47c9..c93441b85a 100644 --- a/opentelemetry-appender-tracing/Cargo.toml +++ b/opentelemetry-appender-tracing/Cargo.toml @@ -35,7 +35,7 @@ pprof = { version = "0.13", features = ["flamegraph", "criterion"] } [features] experimental_metadata_attributes = ["dep:tracing-log"] spec_unstable_logs_enabled = ["opentelemetry/spec_unstable_logs_enabled"] -experimental-use-tracing-span-context = ["tracing-opentelemetry"] +experimental_use_tracing_span_context = ["tracing-opentelemetry"] [[bench]] diff --git a/opentelemetry-appender-tracing/src/layer.rs b/opentelemetry-appender-tracing/src/layer.rs index c08b3fd555..71d75ed2ad 100644 --- a/opentelemetry-appender-tracing/src/layer.rs +++ b/opentelemetry-appender-tracing/src/layer.rs @@ -180,7 +180,7 @@ where // Visit fields. event.record(&mut visitor); - #[cfg(feature = "experimental-use-tracing-span-context")] + #[cfg(feature = "experimental_use_tracing_span_context")] if let Some(span) = _ctx.event_span(event) { use tracing_opentelemetry::OtelData; let opt_span_id = span @@ -511,7 +511,7 @@ mod tests { } } - #[cfg(feature = "experimental-use-tracing-span-context")] + #[cfg(feature = "experimental_use_tracing_span_context")] #[test] fn tracing_appender_inside_tracing_crate_context() { use opentelemetry_sdk::testing::trace::InMemorySpanExporterBuilder; From 80741cd589af6b76470e5e07cab3bb1386c32dec Mon Sep 17 00:00:00 2001 From: Dylan Thacker-Smith Date: Wed, 22 Jan 2025 18:18:47 +0000 Subject: [PATCH 6/8] Remove opentelemetry-prometheus as a workspace member --- Cargo.toml | 3 +++ opentelemetry-prometheus/Cargo.toml | 12 ++++++------ scripts/test.sh | 4 ++++ 3 files changed, 13 insertions(+), 6 deletions(-) diff --git a/Cargo.toml b/Cargo.toml index b21910ca1f..1e004eddc3 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -8,6 +8,9 @@ members = [ "stress", ] resolver = "2" +# Avoid applying patch to force use of workspace members for this +# not actively maintained crate +exclude = ["opentelemetry-prometheus"] [profile.bench] # https://doc.rust-lang.org/cargo/reference/profiles.html#bench diff --git a/opentelemetry-prometheus/Cargo.toml b/opentelemetry-prometheus/Cargo.toml index fc6c2221d6..4ace0c2a84 100644 --- a/opentelemetry-prometheus/Cargo.toml +++ b/opentelemetry-prometheus/Cargo.toml @@ -20,19 +20,19 @@ all-features = true rustdoc-args = ["--cfg", "docsrs"] [dependencies] -once_cell = { workspace = true } +once_cell = { version = "1.13" } opentelemetry = { version = "0.27", default-features = false, features = ["metrics"] } opentelemetry_sdk = { version = "0.27", default-features = false, features = ["metrics"] } prometheus = "0.13" protobuf = "2.14" -tracing = {workspace = true, optional = true} # optional for opentelemetry internal logging +tracing = {version = ">=0.1.40", default-features = false, optional = true} # optional for opentelemetry internal logging [dev-dependencies] opentelemetry-semantic-conventions = { version = "0.27" } -http-body-util = { workspace = true } -hyper = { workspace = true, features = ["full"] } -hyper-util = { workspace = true, features = ["full"] } -tokio = { workspace = true, features = ["full"] } +http-body-util = { version = "0.1" } +hyper = { version = "1.3", features = ["full"] } +hyper-util = { version = "0.1", features = ["full"] } +tokio = { version = "1", features = ["full"] } [features] default = ["internal-logs"] diff --git a/scripts/test.sh b/scripts/test.sh index 467d5f7c4a..b77df21e1c 100755 --- a/scripts/test.sh +++ b/scripts/test.sh @@ -13,6 +13,10 @@ cargo test --workspace --all-features --lib echo "Running tests for opentelemetry package with --no-default-features" cargo test --manifest-path=opentelemetry/Cargo.toml --no-default-features --lib +# Run tests for non-workspace member crate +echo "Running tests for opentelemetry-prometheus with --all-features" +(cd opentelemetry-prometheus && cargo test --all-features --lib) + # Run global tracer provider test in single thread # //TODO: This tests were not running for a while. Need to find out how to run # run them. Using --ignored will run other tests as well, so that cannot be used. From a53f3fc89db91f31375cb93429c1ad56e1d8c484 Mon Sep 17 00:00:00 2001 From: Dylan Thacker-Smith Date: Fri, 24 Jan 2025 00:49:17 -0500 Subject: [PATCH 7/8] Link tracing crate in new changelog entry Co-authored-by: Cijo Thomas --- opentelemetry-appender-tracing/CHANGELOG.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/opentelemetry-appender-tracing/CHANGELOG.md b/opentelemetry-appender-tracing/CHANGELOG.md index 293da80f81..0bbeabb275 100644 --- a/opentelemetry-appender-tracing/CHANGELOG.md +++ b/opentelemetry-appender-tracing/CHANGELOG.md @@ -3,7 +3,7 @@ ## vNext - Bump msrv to 1.75.0. -- New experimental feature to use trace\_id & span\_id from spans created through the tracing crate (experimental_use_tracing_span_context) [#2438](https://github.com/open-telemetry/opentelemetry-rust/pull/2438) +- New experimental feature to use trace\_id & span\_id from spans created through the [tracing](https://crates.io/crates/tracing) crate (experimental_use_tracing_span_context) [#2438](https://github.com/open-telemetry/opentelemetry-rust/pull/2438) ## 0.27.0 From 50b549a08443656d81fa0f441f89b2930be9f458 Mon Sep 17 00:00:00 2001 From: Dylan Thacker-Smith Date: Fri, 24 Jan 2025 01:50:37 -0500 Subject: [PATCH 8/8] Add a comment for the [patch.crates-io] Cargo.toml section --- Cargo.toml | 1 + 1 file changed, 1 insertion(+) diff --git a/Cargo.toml b/Cargo.toml index 1e004eddc3..3f119360d1 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -54,6 +54,7 @@ tracing-core = { version = ">=0.1.33", default-features = false } tracing-subscriber = { version = "0.3", default-features = false } url = { version = "2.5", default-features = false } +# Aviod use of crates.io version of these crates through the tracing-opentelemetry dependencies [patch.crates-io] opentelemetry = { path = "opentelemetry" } opentelemetry_sdk = { path = "opentelemetry-sdk" }