-
Notifications
You must be signed in to change notification settings - Fork 677
feat(appender-tracing): propagate span name to logs #3466
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Open
SuperFluffy
wants to merge
1
commit into
open-telemetry:main
Choose a base branch
from
SuperFluffy:propagate-span-name
base: main
Could not load branches
Branch not found: {{ refName }}
Loading
Could not load tags
Nothing to show
Loading
Are you sure you want to change the base?
Some commits from the old base branch may be removed from the timeline,
and old review comments may become outdated.
Open
Changes from all commits
Commits
File filter
Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
There are no files selected for viewing
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -368,6 +368,11 @@ where | |
| // - `Some(Allowlist(set))` => copy only attributes whose keys are in `set`. | ||
| #[cfg(feature = "experimental_span_attributes")] | ||
| span_attributes: Option<TracingSpanAttributesInner>, | ||
| // Tracing-span name enrichment configuration: | ||
| // - `None` => disabled (default). No scope walk unless span attributes are enabled. | ||
| // - `Some(key)` => copy the current tracing span name using `key`. | ||
| #[cfg(feature = "experimental_span_attributes")] | ||
| span_name: Option<Key>, | ||
| } | ||
|
|
||
| impl<P, L> OpenTelemetryTracingBridge<P, L> | ||
|
|
@@ -390,6 +395,8 @@ where | |
| _phantom: Default::default(), | ||
| #[cfg(feature = "experimental_span_attributes")] | ||
| span_attributes: None, | ||
| #[cfg(feature = "experimental_span_attributes")] | ||
| span_name: None, | ||
| } | ||
| } | ||
| } | ||
|
|
@@ -403,6 +410,8 @@ where | |
| _phantom: std::marker::PhantomData<P>, | ||
| #[cfg(feature = "experimental_span_attributes")] | ||
| span_attributes: Option<TracingSpanAttributesInner>, | ||
| #[cfg(feature = "experimental_span_attributes")] | ||
| span_name: Option<Key>, | ||
| } | ||
|
|
||
| impl<P, L> OpenTelemetryTracingBridgeBuilder<P, L> | ||
|
|
@@ -432,12 +441,37 @@ where | |
| self | ||
| } | ||
|
|
||
| /// Store the current tracing span's name on each emitted log record using | ||
| /// the given log attribute key. | ||
| /// | ||
| /// "Current" means the leaf/innermost [`tracing::span!`] active when the | ||
| /// event is emitted. `span_name` is the log attribute key where that | ||
| /// tracing span name will be stored, with the span name being the attribute | ||
| /// value. | ||
| /// | ||
| /// This option is independent from [`Self::with_tracing_span_attributes`]: | ||
| /// callers can enable tracing-span attributes only, tracing-span name only, | ||
| /// or both. By default, span-name enrichment is disabled and no span-name | ||
| /// attribute is added. | ||
| /// | ||
| /// Calling this method multiple times replaces any prior span-name key - | ||
| /// the last call wins. | ||
| /// | ||
| /// [`tracing::span!`]: https://docs.rs/tracing/latest/tracing/macro.span.html | ||
| #[cfg(feature = "experimental_span_attributes")] | ||
| pub fn with_tracing_span_name(mut self, span_name: &'static str) -> Self { | ||
| self.span_name = Some(Key::from_static_str(span_name)); | ||
| self | ||
| } | ||
|
|
||
| pub fn build(self) -> OpenTelemetryTracingBridge<P, L> { | ||
| OpenTelemetryTracingBridge { | ||
| logger: self.logger, | ||
| _phantom: self._phantom, | ||
| #[cfg(feature = "experimental_span_attributes")] | ||
| span_attributes: self.span_attributes, | ||
| #[cfg(feature = "experimental_span_attributes")] | ||
| span_name: self.span_name, | ||
| } | ||
| } | ||
| } | ||
|
|
@@ -476,20 +510,31 @@ where | |
| log_record.set_severity_number(severity); | ||
| log_record.set_severity_text(metadata.level().as_str()); | ||
|
|
||
| // Extract tracing-span attributes if enrichment is enabled. | ||
| // Extract tracing-span enrichment if enabled. | ||
| #[cfg(feature = "experimental_span_attributes")] | ||
| if self.span_attributes.is_some() { | ||
| if self.span_attributes.is_some() || self.span_name.is_some() { | ||
|
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. if just span_name is required, do we need to walk entire scope? Any easier way to grab the span name from current ? |
||
| // Collect attributes from all parent spans (root to leaf), including current span | ||
| if let Some(scope) = ctx.event_scope(event) { | ||
| let mut current_span_name = None; | ||
| for span_ref in scope.from_root() { | ||
| // Access extensions inline - each span has its own extension lock | ||
| let extensions = span_ref.extensions(); | ||
| if let Some(stored) = extensions.get::<StoredSpanAttributes>() { | ||
| for (key, value) in stored.attributes.iter() { | ||
| log_record.add_attribute(key.clone(), value.clone()); | ||
| if self.span_name.is_some() { | ||
| current_span_name = Some(span_ref.metadata().name()); | ||
| } | ||
|
|
||
| if self.span_attributes.is_some() { | ||
| // Access extensions inline - each span has its own extension lock | ||
| let extensions = span_ref.extensions(); | ||
| if let Some(stored) = extensions.get::<StoredSpanAttributes>() { | ||
| for (key, value) in stored.attributes.iter() { | ||
| log_record.add_attribute(key.clone(), value.clone()); | ||
| } | ||
| } | ||
| } | ||
| } | ||
|
|
||
| if let (Some(key), Some(value)) = (self.span_name.as_ref(), current_span_name) { | ||
| log_record.add_attribute(key.clone(), AnyValue::from(value)); | ||
| } | ||
| } | ||
| } | ||
|
|
||
|
|
@@ -1199,6 +1244,180 @@ mod tests { | |
| .any(|(k, _)| k == &Key::new("endpoint"))); | ||
| } | ||
|
|
||
| #[test] | ||
| #[cfg(feature = "experimental_span_attributes")] | ||
| fn tracing_appender_span_name_disabled_by_default() { | ||
| let exporter = InMemoryLogExporter::default(); | ||
| let provider = SdkLoggerProvider::builder() | ||
| .with_simple_exporter(exporter.clone()) | ||
| .build(); | ||
|
|
||
| let layer = layer::OpenTelemetryTracingBridge::builder(&provider) | ||
| .with_tracing_span_attributes(TracingSpanAttributes::all()) | ||
| .build() | ||
| .with_filter(tracing_subscriber::filter::filter_fn(|meta| { | ||
| meta.is_span() || *meta.level() <= tracing::Level::ERROR | ||
| })); | ||
| let subscriber = tracing_subscriber::registry().with(layer); | ||
| let _guard = tracing::subscriber::set_default(subscriber); | ||
|
|
||
| let span = tracing::info_span!("test_span", user_id = 123); | ||
| let _enter = span.enter(); | ||
| tracing::error!("test message"); | ||
|
|
||
| provider.force_flush().unwrap(); | ||
| let logs = exporter.get_emitted_logs().unwrap(); | ||
| assert_eq!(logs.len(), 1); | ||
| let log = &logs[0]; | ||
|
|
||
| assert!(attributes_contains( | ||
| &log.record, | ||
| &Key::new("user_id"), | ||
| &AnyValue::Int(123) | ||
| )); | ||
| assert!(!log | ||
| .record | ||
| .attributes_iter() | ||
| .any(|(k, _)| k == &Key::new("span.name"))); | ||
| } | ||
|
|
||
| #[test] | ||
| #[cfg(feature = "experimental_span_attributes")] | ||
| fn tracing_appender_span_name_enrichment_without_span_attributes() { | ||
| let exporter = InMemoryLogExporter::default(); | ||
| let provider = SdkLoggerProvider::builder() | ||
| .with_simple_exporter(exporter.clone()) | ||
| .build(); | ||
|
|
||
| let layer = layer::OpenTelemetryTracingBridge::builder(&provider) | ||
| .with_tracing_span_name("span.name") | ||
| .build() | ||
| .with_filter(tracing_subscriber::filter::filter_fn(|meta| { | ||
| meta.is_span() || *meta.level() <= tracing::Level::ERROR | ||
| })); | ||
| let subscriber = tracing_subscriber::registry().with(layer); | ||
| let _guard = tracing::subscriber::set_default(subscriber); | ||
|
|
||
| let span = tracing::info_span!("test_span", user_id = 123); | ||
| let _enter = span.enter(); | ||
| tracing::error!(status = 200, "test message"); | ||
|
|
||
| provider.force_flush().unwrap(); | ||
| let logs = exporter.get_emitted_logs().unwrap(); | ||
| assert_eq!(logs.len(), 1); | ||
| let log = &logs[0]; | ||
|
|
||
| assert!(attributes_contains( | ||
| &log.record, | ||
| &Key::new("span.name"), | ||
| &AnyValue::String("test_span".into()) | ||
| )); | ||
| assert!(attributes_contains( | ||
| &log.record, | ||
| &Key::new("status"), | ||
| &AnyValue::Int(200) | ||
| )); | ||
| assert!(!log | ||
| .record | ||
| .attributes_iter() | ||
| .any(|(k, _)| k == &Key::new("user_id"))); | ||
| } | ||
|
|
||
| #[test] | ||
| #[cfg(feature = "experimental_span_attributes")] | ||
| fn tracing_appender_span_name_uses_current_span_and_configured_key() { | ||
| let exporter = InMemoryLogExporter::default(); | ||
| let provider = SdkLoggerProvider::builder() | ||
| .with_simple_exporter(exporter.clone()) | ||
| .build(); | ||
|
|
||
| let layer = layer::OpenTelemetryTracingBridge::builder(&provider) | ||
| .with_tracing_span_name("custom.span_name") | ||
| .build() | ||
| .with_filter(tracing_subscriber::filter::filter_fn(|meta| { | ||
| meta.is_span() || *meta.level() <= tracing::Level::ERROR | ||
| })); | ||
| let subscriber = tracing_subscriber::registry().with(layer); | ||
| let _guard = tracing::subscriber::set_default(subscriber); | ||
|
|
||
| let outer = tracing::info_span!("outer_span"); | ||
| let _outer_guard = outer.enter(); | ||
| let inner = tracing::info_span!("inner_span"); | ||
| let _inner_guard = inner.enter(); | ||
| tracing::error!("test message"); | ||
|
|
||
| provider.force_flush().unwrap(); | ||
| let logs = exporter.get_emitted_logs().unwrap(); | ||
| assert_eq!(logs.len(), 1); | ||
| let log = &logs[0]; | ||
|
|
||
| assert!(attributes_contains( | ||
| &log.record, | ||
| &Key::new("custom.span_name"), | ||
| &AnyValue::String("inner_span".into()) | ||
| )); | ||
| assert!(!log | ||
| .record | ||
| .attributes_iter() | ||
| .any(|(k, _)| k == &Key::new("span.name"))); | ||
| assert!(!attributes_contains( | ||
| &log.record, | ||
| &Key::new("custom.span_name"), | ||
| &AnyValue::String("outer_span".into()) | ||
| )); | ||
| } | ||
|
|
||
| #[test] | ||
| #[cfg(feature = "experimental_span_attributes")] | ||
| fn tracing_appender_span_name_and_attributes_can_both_be_enabled() { | ||
| let exporter = InMemoryLogExporter::default(); | ||
| let provider = SdkLoggerProvider::builder() | ||
| .with_simple_exporter(exporter.clone()) | ||
| .build(); | ||
|
|
||
| let layer = layer::OpenTelemetryTracingBridge::builder(&provider) | ||
| .with_tracing_span_attributes(TracingSpanAttributes::all()) | ||
| .with_tracing_span_name("span.name") | ||
| .build() | ||
| .with_filter(tracing_subscriber::filter::filter_fn(|meta| { | ||
| meta.is_span() || *meta.level() <= tracing::Level::ERROR | ||
| })); | ||
| let subscriber = tracing_subscriber::registry().with(layer); | ||
| let _guard = tracing::subscriber::set_default(subscriber); | ||
|
|
||
| let outer = tracing::info_span!("outer_span", request_id = "req-123"); | ||
| let _outer_guard = outer.enter(); | ||
| let inner = tracing::info_span!("inner_span", user_id = 123); | ||
| let _inner_guard = inner.enter(); | ||
| tracing::error!(status = 200, "test message"); | ||
|
|
||
| provider.force_flush().unwrap(); | ||
| let logs = exporter.get_emitted_logs().unwrap(); | ||
| assert_eq!(logs.len(), 1); | ||
| let log = &logs[0]; | ||
|
|
||
| assert!(attributes_contains( | ||
| &log.record, | ||
| &Key::new("span.name"), | ||
| &AnyValue::String("inner_span".into()) | ||
| )); | ||
| assert!(attributes_contains( | ||
| &log.record, | ||
| &Key::new("request_id"), | ||
| &AnyValue::String("req-123".into()) | ||
| )); | ||
| assert!(attributes_contains( | ||
| &log.record, | ||
| &Key::new("user_id"), | ||
| &AnyValue::Int(123) | ||
| )); | ||
| assert!(attributes_contains( | ||
| &log.record, | ||
| &Key::new("status"), | ||
| &AnyValue::Int(200) | ||
| )); | ||
| } | ||
|
|
||
| #[test] | ||
| #[cfg(feature = "experimental_span_attributes")] | ||
| fn tracing_appender_span_context_enrichment_enabled() { | ||
|
|
||
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Oops, something went wrong.
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
@SuperFluffy
Thanks for continuing to work on this. This is looking better. One thing I want to discuss more:
Pretty sure we'd need to expand the support for this to let use pick inner-most or outer-most (or all 🤣 ). Could you consider that future need in mind, and see if how could we evolve?
I haven't dug into details yet, but I think we should consider a design that can accommodate future expansion without looking awkward.
An example use-case I am aware of is: When a service receives incoming request, it starts a tracing::span with name indicating overall operation. Then there are sub spans too. For the log, it may be desired to store the outermost span name, instead of inner most. I understand we agreed to start with inner-most, but could you outline how this could be expanded without ending up with confusing API ?