diff --git a/metrics-tracing-context/CHANGELOG.md b/metrics-tracing-context/CHANGELOG.md index 389f8da2..63ed2d4d 100644 --- a/metrics-tracing-context/CHANGELOG.md +++ b/metrics-tracing-context/CHANGELOG.md @@ -8,6 +8,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased] - ReleaseDate +### Added + +- Support for dynamism using `tracing::Span::record` to add label values. ([#408](https://github.com/metrics-rs/metrics/pull/408)) + ## [0.14.0] - 2023-04-16 ### Changed diff --git a/metrics-tracing-context/Cargo.toml b/metrics-tracing-context/Cargo.toml index 0a692f7f..96287598 100644 --- a/metrics-tracing-context/Cargo.toml +++ b/metrics-tracing-context/Cargo.toml @@ -32,6 +32,7 @@ itoa = { version = "1", default-features = false } metrics = { version = "^0.21", path = "../metrics" } metrics-util = { version = "^0.15", path = "../metrics-util" } lockfree-object-pool = { version = "0.1.3", default-features = false } +indexmap = { version = "2.1", default-features = false, features = ["std"] } once_cell = { version = "1", default-features = false, features = ["std"] } tracing = { version = "0.1.29", default-features = false } tracing-core = { version = "0.1.21", default-features = false } @@ -42,3 +43,4 @@ criterion = { version = "=0.3.3", default-features = false } parking_lot = { version = "0.12.1", default-features = false } tracing = { version = "0.1.29", default-features = false, features = ["std"] } tracing-subscriber = { version = "0.3.1", default-features = false, features = ["registry"] } +itertools = { version = "0.12.0", default-features = false, features = ["use_std"] } diff --git a/metrics-tracing-context/benches/visit.rs b/metrics-tracing-context/benches/visit.rs index a3128af9..9b6db089 100644 --- a/metrics-tracing-context/benches/visit.rs +++ b/metrics-tracing-context/benches/visit.rs @@ -1,8 +1,9 @@ use std::sync::Arc; use criterion::{criterion_group, criterion_main, BatchSize, Criterion}; +use indexmap::IndexMap; use lockfree_object_pool::LinearObjectPool; -use metrics::Label; +use metrics::SharedString; use metrics_tracing_context::Labels; use once_cell::sync::OnceCell; use tracing::Metadata; @@ -13,9 +14,11 @@ use tracing_core::{ Callsite, Interest, }; -fn get_pool() -> &'static Arc>> { - static POOL: OnceCell>>> = OnceCell::new(); - POOL.get_or_init(|| Arc::new(LinearObjectPool::new(|| Vec::new(), |vec| vec.clear()))) +type Map = IndexMap; + +fn get_pool() -> &'static Arc> { + static POOL: OnceCell>> = OnceCell::new(); + POOL.get_or_init(|| Arc::new(LinearObjectPool::new(Map::new, Map::clear))) } const BATCH_SIZE: usize = 1000; diff --git a/metrics-tracing-context/src/lib.rs b/metrics-tracing-context/src/lib.rs index 253a5486..656e6449 100644 --- a/metrics-tracing-context/src/lib.rs +++ b/metrics-tracing-context/src/lib.rs @@ -55,19 +55,25 @@ //! //! # Implementation //! -//! The integration layer works by capturing all fields present when a span is created and storing -//! them as an extension to the span. If a metric is emitted while a span is entered, we check that -//! span to see if it has any fields in the extension data, and if it does, we add those fields as -//! labels to the metric key. -//! -//! There are two important behaviors to be aware of: -//! - we only capture the fields present when the span is created -//! - we store all fields that a span has, including the fields of its parent span(s) -//! -//! ## Lack of dynamism -//! -//! This means that if you use [`Span::record`][tracing::Span::record] to add fields to a span after -//! it has been created, those fields will not be captured and added to your metric key. +//! The integration layer works by capturing all fields that are present when a span is created, +//! as well as fields recorded after the fact, and storing them as an extension to the span. If +//! a metric is emitted while a span is entered, any fields captured for that span will be added +//! to the metric as additional labels. +//! +//! Be aware that we recursively capture the fields of a span, including fields from +//! parent spans, and use them when generating metric labels. This means that if a metric is being +//! emitted in span B, which is a child of span A, and span A has field X, and span B has field Y, +//! then the metric labels will include both field X and Y. This applies regardless of how many +//! nested spans are currently entered. +//! +//! ## Duplicate span fields +//! +//! When span fields are captured, they are deduplicated such that only the most recent value is kept. +//! For merging parent span fields into the current span fields, the fields from the current span have +//! the highest priority. Additionally, when using [`Span::record`][tracing::Span::record] to add fields +//! to a span after it has been created, the same behavior applies. This means that recording a field +//! multiple times only keeps the most recently recorded value, including if a field was already present +//! from a parent span and is then recorded dynamically in the current span. //! //! ## Span fields and ancestry //! @@ -104,7 +110,7 @@ pub mod label_filter; mod tracing_integration; pub use label_filter::LabelFilter; -use tracing_integration::WithContext; +use tracing_integration::Map; pub use tracing_integration::{Labels, MetricsLayer}; /// [`TracingContextLayer`] provides an implementation of a [`Layer`] for [`TracingContext`]. @@ -169,34 +175,33 @@ where // doing the iteration would likely exceed the cost of simply constructing the new key. tracing::dispatcher::get_default(|dispatch| { let current = dispatch.current_span(); - if let Some(id) = current.id() { - // We're currently within a live tracing span, so see if we have an available - // metrics context to grab any fields/labels out of. - if let Some(ctx) = dispatch.downcast_ref::() { - let mut f = |new_labels: &[Label]| { - if !new_labels.is_empty() { - let (name, mut labels) = key.clone().into_parts(); - - let filtered_labels = new_labels - .iter() - .filter(|label| { - self.label_filter.should_include_label(&name, label) - }) - .cloned(); - labels.extend(filtered_labels); - - Some(Key::from_parts(name, labels)) - } else { - None - } - }; - - // Pull in the span's fields/labels if they exist. - return ctx.with_labels(dispatch, id, &mut f); - } - } - - None + let id = current.id()?; + let ctx = dispatch.downcast_ref::()?; + + let mut f = |mut span_labels: Map| { + (!span_labels.is_empty()).then(|| { + let (name, labels) = key.clone().into_parts(); + + // Filter only span labels + span_labels.retain(|key: &SharedString, value: &mut SharedString| { + let label = Label::new(key.clone(), value.clone()); + self.label_filter.should_include_label(&name, &label) + }); + + // Overwrites labels from spans + span_labels.extend(labels.into_iter().map(Label::into_parts)); + + let labels = span_labels + .into_iter() + .map(|(key, value)| Label::new(key, value)) + .collect::>(); + + Key::from_parts(name, labels) + }) + }; + + // Pull in the span's fields/labels if they exist. + ctx.with_labels(dispatch, id, &mut f) }) } } diff --git a/metrics-tracing-context/src/tracing_integration.rs b/metrics-tracing-context/src/tracing_integration.rs index 7507b34e..d6e235f4 100644 --- a/metrics-tracing-context/src/tracing_integration.rs +++ b/metrics-tracing-context/src/tracing_integration.rs @@ -1,28 +1,49 @@ //! The code that integrates with the `tracing` crate. +use indexmap::IndexMap; use lockfree_object_pool::{LinearObjectPool, LinearOwnedReusable}; -use metrics::{Key, Label}; +use metrics::{Key, SharedString}; use once_cell::sync::OnceCell; +use std::cmp; use std::sync::Arc; -use std::{any::TypeId, marker::PhantomData}; use tracing_core::span::{Attributes, Id, Record}; use tracing_core::{field::Visit, Dispatch, Field, Subscriber}; use tracing_subscriber::{layer::Context, registry::LookupSpan, Layer}; -fn get_pool() -> &'static Arc>> { - static POOL: OnceCell>>> = OnceCell::new(); - POOL.get_or_init(|| Arc::new(LinearObjectPool::new(Vec::new, Vec::clear))) +pub(crate) type Map = IndexMap; + +fn get_pool() -> &'static Arc> { + static POOL: OnceCell>> = OnceCell::new(); + POOL.get_or_init(|| Arc::new(LinearObjectPool::new(Map::new, Map::clear))) } + /// Span fields mapped as metrics labels. /// /// Hidden from documentation as there is no need for end users to ever touch this type, but it must /// be public in order to be pulled in by external benchmark code. #[doc(hidden)] -pub struct Labels(pub LinearOwnedReusable>); +pub struct Labels(pub LinearOwnedReusable); impl Labels { - pub(crate) fn extend_from_labels(&mut self, other: &Labels) { - self.0.extend_from_slice(other.as_ref()); + fn extend(&mut self, other: &Labels, f: impl Fn(&mut Map, &SharedString, &SharedString)) { + let new_len = cmp::max(self.as_ref().len(), other.as_ref().len()); + let additional = new_len - self.as_ref().len(); + self.0.reserve(additional); + for (k, v) in other.as_ref() { + f(&mut self.0, k, v); + } + } + + fn extend_from_labels(&mut self, other: &Labels) { + self.extend(other, |map, k, v| { + map.entry(k.clone()).or_insert_with(|| v.clone()); + }); + } + + fn extend_from_labels_overwrite(&mut self, other: &Labels) { + self.extend(other, |map, k, v| { + map.insert(k.clone(), v.clone()); + }); } } @@ -34,108 +55,86 @@ impl Default for Labels { impl Visit for Labels { fn record_str(&mut self, field: &Field, value: &str) { - let label = Label::new(field.name(), value.to_string()); - self.0.push(label); + self.0.insert(field.name().into(), value.to_owned().into()); } fn record_bool(&mut self, field: &Field, value: bool) { - let label = Label::from_static_parts(field.name(), if value { "true" } else { "false" }); - self.0.push(label); + self.0.insert(field.name().into(), if value { "true" } else { "false" }.into()); } fn record_i64(&mut self, field: &Field, value: i64) { let mut buf = itoa::Buffer::new(); let s = buf.format(value); - let label = Label::new(field.name(), s.to_string()); - self.0.push(label); + self.0.insert(field.name().into(), s.to_owned().into()); } fn record_u64(&mut self, field: &Field, value: u64) { let mut buf = itoa::Buffer::new(); let s = buf.format(value); - let label = Label::new(field.name(), s.to_string()); - self.0.push(label); + self.0.insert(field.name().into(), s.to_owned().into()); } fn record_debug(&mut self, field: &Field, value: &dyn std::fmt::Debug) { - let value_string = format!("{:?}", value); - let label = Label::new(field.name(), value_string); - self.0.push(label); + self.0.insert(field.name().into(), format!("{value:?}").into()); } } impl Labels { - fn from_attributes(attrs: &Attributes<'_>) -> Labels { + fn from_record(record: &Record) -> Labels { let mut labels = Labels::default(); - let record = Record::new(attrs.values()); record.record(&mut labels); labels } } -impl AsRef<[Label]> for Labels { - fn as_ref(&self) -> &[Label] { +impl AsRef for Labels { + fn as_ref(&self) -> &Map { &self.0 } } -pub struct WithContext { - with_labels: fn(&Dispatch, &Id, f: &mut dyn FnMut(&Labels) -> Option) -> Option, -} - -impl WithContext { - pub fn with_labels( - &self, - dispatch: &Dispatch, - id: &Id, - f: &mut dyn FnMut(&[Label]) -> Option, - ) -> Option { - let mut ff = |labels: &Labels| f(labels.as_ref()); - (self.with_labels)(dispatch, id, &mut ff) - } -} - /// [`MetricsLayer`] is a [`tracing_subscriber::Layer`] that captures the span /// fields and allows them to be later on used as metrics labels. -pub struct MetricsLayer { - ctx: WithContext, - _subscriber: PhantomData, +#[derive(Default)] +pub struct MetricsLayer { + with_labels: + Option Option) -> Option>, } -impl MetricsLayer -where - S: Subscriber + for<'span> LookupSpan<'span>, -{ - /// Create a new `MetricsLayer`. +impl MetricsLayer { + /// Create a new [`MetricsLayer`]. pub fn new() -> Self { - let ctx = WithContext { with_labels: Self::with_labels }; - - Self { ctx, _subscriber: PhantomData } + Self::default() } - fn with_labels( + pub(crate) fn with_labels( + &self, dispatch: &Dispatch, id: &Id, - f: &mut dyn FnMut(&Labels) -> Option, + f: &mut dyn FnMut(Map) -> Option, ) -> Option { - let subscriber = dispatch - .downcast_ref::() - .expect("subscriber should downcast to expected type; this is a bug!"); - let span = subscriber.span(id).expect("registry should have a span for the current ID"); - - let result = - if let Some(labels) = span.extensions().get::() { f(labels) } else { None }; - result + let mut ff = |labels: &Labels| f(labels.0.clone()); + (self.with_labels?)(dispatch, id, &mut ff) } } -impl Layer for MetricsLayer +impl Layer for MetricsLayer where S: Subscriber + for<'a> LookupSpan<'a>, { + fn on_layer(&mut self, _: &mut S) { + self.with_labels = Some(|dispatch, id, f| { + let subscriber = dispatch.downcast_ref::()?; + let span = subscriber.span(id)?; + + let ext = span.extensions(); + f(ext.get::()?) + }); + } + fn on_new_span(&self, attrs: &Attributes<'_>, id: &Id, cx: Context<'_, S>) { let span = cx.span(id).expect("span must already exist!"); - let mut labels = Labels::from_attributes(attrs); + let mut labels = Labels::from_record(&Record::new(attrs.values())); if let Some(parent) = span.parent() { if let Some(parent_labels) = parent.extensions().get::() { @@ -146,20 +145,15 @@ where span.extensions_mut().insert(labels); } - unsafe fn downcast_raw(&self, id: TypeId) -> Option<*const ()> { - match id { - id if id == TypeId::of::() => Some(self as *const _ as *const ()), - id if id == TypeId::of::() => Some(&self.ctx as *const _ as *const ()), - _ => None, - } - } -} + fn on_record(&self, id: &Id, values: &Record<'_>, cx: Context<'_, S>) { + let span = cx.span(id).expect("span must already exist!"); + let labels = Labels::from_record(values); -impl Default for MetricsLayer -where - S: Subscriber + for<'span> LookupSpan<'span>, -{ - fn default() -> Self { - MetricsLayer::new() + let ext = &mut span.extensions_mut(); + if let Some(existing) = ext.get_mut::() { + existing.extend_from_labels_overwrite(&labels); + } else { + ext.insert(labels); + } } } diff --git a/metrics-tracing-context/tests/integration.rs b/metrics-tracing-context/tests/integration.rs index 0229393e..526b0c63 100644 --- a/metrics-tracing-context/tests/integration.rs +++ b/metrics-tracing-context/tests/integration.rs @@ -1,3 +1,4 @@ +use itertools::Itertools; use metrics::{counter, Key, KeyName, Label}; use metrics_tracing_context::{LabelFilter, MetricsLayer, TracingContextLayer}; use metrics_util::debugging::{DebugValue, DebuggingRecorder, Snapshotter}; @@ -8,54 +9,65 @@ use tracing::{span, Level}; use tracing_subscriber::{layer::SubscriberExt, Registry}; static TEST_MUTEX: Mutex<()> = const_mutex(()); -static LOGIN_ATTEMPTS: &'static str = "login_attempts"; -static LOGIN_ATTEMPTS_NONE: &'static str = "login_attempts_no_labels"; -static LOGIN_ATTEMPTS_STATIC: &'static str = "login_attempts_static_labels"; -static LOGIN_ATTEMPTS_DYNAMIC: &'static str = "login_attempts_dynamic_labels"; -static LOGIN_ATTEMPTS_BOTH: &'static str = "login_attempts_static_and_dynamic_labels"; -static MY_COUNTER: &'static str = "my_counter"; -static USER_EMAIL: &'static [Label] = &[ +static LOGIN_ATTEMPTS: &str = "login_attempts"; +static LOGIN_ATTEMPTS_NONE: &str = "login_attempts_no_labels"; +static LOGIN_ATTEMPTS_STATIC: &str = "login_attempts_static_labels"; +static LOGIN_ATTEMPTS_DYNAMIC: &str = "login_attempts_dynamic_labels"; +static LOGIN_ATTEMPTS_BOTH: &str = "login_attempts_static_and_dynamic_labels"; +static MY_COUNTER: &str = "my_counter"; +static USER_EMAIL: &[Label] = &[ Label::from_static_parts("user", "ferris"), Label::from_static_parts("user.email", "ferris@rust-lang.org"), ]; -static EMAIL_USER: &'static [Label] = &[ +static USER_EMAIL_ATTEMPT: &[Label] = &[ + Label::from_static_parts("user", "ferris"), Label::from_static_parts("user.email", "ferris@rust-lang.org"), + Label::from_static_parts("attempt", "42"), +]; +static USER_ID: &[Label] = &[Label::from_static_parts("user.id", "42")]; +static EMAIL_USER: &[Label] = &[ Label::from_static_parts("user", "ferris"), + Label::from_static_parts("user.email", "ferris@rust-lang.org"), ]; -static SVC_ENV: &'static [Label] = &[ +static SVC_ENV: &[Label] = &[ Label::from_static_parts("service", "login_service"), Label::from_static_parts("env", "test"), ]; -static SVC_USER_EMAIL: &'static [Label] = &[ - Label::from_static_parts("service", "login_service"), +static SVC_USER_EMAIL: &[Label] = &[ Label::from_static_parts("user", "ferris"), Label::from_static_parts("user.email", "ferris@rust-lang.org"), + Label::from_static_parts("service", "login_service"), ]; -static NODE_USER_EMAIL: &'static [Label] = &[ - Label::from_static_parts("node_name", "localhost"), +static SVC_USER_EMAIL_ID: &[Label] = &[ Label::from_static_parts("user", "ferris"), Label::from_static_parts("user.email", "ferris@rust-lang.org"), -]; -static SVC_NODE_USER_EMAIL: &'static [Label] = &[ + Label::from_static_parts("user.id", "42"), Label::from_static_parts("service", "login_service"), +]; +static NODE_USER_EMAIL: &[Label] = &[ + Label::from_static_parts("user", "ferris"), + Label::from_static_parts("user.email", "ferris@rust-lang.org"), Label::from_static_parts("node_name", "localhost"), +]; +static SVC_NODE_USER_EMAIL: &[Label] = &[ Label::from_static_parts("user", "ferris"), Label::from_static_parts("user.email", "ferris@rust-lang.org"), + Label::from_static_parts("service", "login_service"), + Label::from_static_parts("node_name", "localhost"), ]; -static COMBINED_LABELS: &'static [Label] = &[ +static COMBINED_LABELS: &[Label] = &[ Label::from_static_parts("shared_field", "inner"), Label::from_static_parts("inner_specific", "foo"), Label::from_static_parts("inner_specific_dynamic", "foo_dynamic"), - Label::from_static_parts("shared_field", "outer"), Label::from_static_parts("outer_specific", "bar"), Label::from_static_parts("outer_specific_dynamic", "bar_dynamic"), ]; -static SAME_CALLSITE_PATH_1: &'static [Label] = &[ +static SAME_CALLSITE_PATH_1: &[Label] = &[ Label::from_static_parts("shared_field", "path1"), Label::from_static_parts("path1_specific", "foo"), Label::from_static_parts("path1_specific_dynamic", "foo_dynamic"), ]; -static SAME_CALLSITE_PATH_2: &'static [Label] = &[ +static SAME_CALLSITE_PATH_2: &[Label] = &[ Label::from_static_parts("shared_field", "path2"), Label::from_static_parts("path2_specific", "bar"), Label::from_static_parts("path2_specific_dynamic", "bar_dynamic"), @@ -110,7 +122,200 @@ fn test_basic_functionality() { None, DebugValue::Counter(1), )] - ) + ); +} + +#[test] +fn test_basic_functionality_record() { + let (_guard, snapshotter) = setup(TracingContextLayer::all()); + + let user = "ferris"; + let email = "ferris@rust-lang.org"; + let span = span!( + Level::TRACE, + "login", + user, + user.email = email, + user.id = tracing_core::field::Empty, + ); + let _guard = span.enter(); + + span.record("user.id", 42); + counter!("login_attempts", "service" => "login_service").increment(1); + + let snapshot = snapshotter.snapshot().into_vec(); + + assert_eq!( + snapshot, + vec![( + CompositeKey::new( + MetricKind::Counter, + Key::from_static_parts(LOGIN_ATTEMPTS, SVC_USER_EMAIL_ID) + ), + None, + None, + DebugValue::Counter(1), + )] + ); +} + +#[test] +fn test_basic_functionality_then_record() { + let (_guard, snapshotter) = setup(TracingContextLayer::all()); + + let user = "ferris"; + let email = "ferris@rust-lang.org"; + let span = span!( + Level::TRACE, + "login", + user, + user.email = email, + user.id = tracing_core::field::Empty, + ); + let _guard = span.enter(); + let mut snapshots = vec![]; + { + counter!("login_attempts", "service" => "login_service").increment(1); + + let snapshot = snapshotter.snapshot().into_vec(); + + snapshots.push(( + CompositeKey::new( + MetricKind::Counter, + Key::from_static_parts(LOGIN_ATTEMPTS, SVC_USER_EMAIL), + ), + None, + None, + DebugValue::Counter(1), + )); + + assert_eq!(snapshot, snapshots); + } + span.record("user.id", 42); + { + counter!("login_attempts", "service" => "login_service").increment(1); + + let snapshot = snapshotter.snapshot().into_vec(); + + snapshots.push(( + CompositeKey::new( + MetricKind::Counter, + Key::from_static_parts(LOGIN_ATTEMPTS, SVC_USER_EMAIL_ID), + ), + None, + None, + DebugValue::Counter(1), + )); + + assert_eq!(snapshot, snapshots); + } +} + +#[test] +fn test_rerecord() { + static USER_ID_42: &[Label] = &[Label::from_static_parts("user.id", "42")]; + static USER_ID_123: &[Label] = &[Label::from_static_parts("user.id", "123")]; + + let (_guard, snapshotter) = setup(TracingContextLayer::all()); + + let span = span!(Level::TRACE, "login", user.id = tracing_core::field::Empty); + let _guard = span.enter(); + + span.record("user.id", 42); + counter!("login_attempts").increment(1); + + span.record("user.id", 123); + counter!("login_attempts").increment(1); + + let snapshot = snapshotter.snapshot().into_vec(); + + assert_eq!( + snapshot, + vec![ + ( + CompositeKey::new( + MetricKind::Counter, + Key::from_static_parts(LOGIN_ATTEMPTS, USER_ID_42) + ), + None, + None, + DebugValue::Counter(1), + ), + ( + CompositeKey::new( + MetricKind::Counter, + Key::from_static_parts(LOGIN_ATTEMPTS, USER_ID_123) + ), + None, + None, + DebugValue::Counter(1), + ) + ] + ); +} + +#[test] +fn test_loop() { + let (_guard, snapshotter) = setup(TracingContextLayer::all()); + + let user = "ferris"; + let email = "ferris@rust-lang.org"; + let span = span!( + Level::TRACE, + "login", + user, + user.email = email, + attempt = tracing_core::field::Empty, + ); + let _guard = span.enter(); + + for attempt in 1..=42 { + span.record("attempt", attempt); + } + counter!("login_attempts").increment(1); + + let snapshot = snapshotter.snapshot().into_vec(); + + assert_eq!( + snapshot, + vec![( + CompositeKey::new( + MetricKind::Counter, + Key::from_static_parts(LOGIN_ATTEMPTS, USER_EMAIL_ATTEMPT) + ), + None, + None, + DebugValue::Counter(1), + )] + ); +} + +#[test] +fn test_record_does_not_overwrite() { + static USER_ID_42: &[Label] = &[Label::from_static_parts("user.id", "42")]; + + let (_guard, snapshotter) = setup(TracingContextLayer::all()); + + let span = span!(Level::TRACE, "login", user.id = tracing_core::field::Empty); + let _guard = span.enter(); + + span.record("user.id", 666); + counter!("login_attempts", "user.id" => "42").increment(1); + + let snapshot = snapshotter.snapshot().into_vec(); + + assert_eq!( + snapshot, + vec![( + CompositeKey::new( + MetricKind::Counter, + Key::from_static_parts(LOGIN_ATTEMPTS, USER_ID_42) + ), + None, + None, + DebugValue::Counter(1), + )] + ); } #[test] @@ -130,8 +335,11 @@ fn test_macro_forms() { let node_name = "localhost".to_string(); counter!("login_attempts_dynamic_labels", "node_name" => node_name.clone()).increment(1); // Static and dynamic. - counter!("login_attempts_static_and_dynamic_labels", - "service" => "login_service", "node_name" => node_name.clone()) + counter!( + "login_attempts_static_and_dynamic_labels", + "service" => "login_service", + "node_name" => node_name, + ) .increment(1); let snapshot = snapshotter.snapshot().into_vec(); @@ -176,7 +384,7 @@ fn test_macro_forms() { DebugValue::Counter(1), ), ] - ) + ); } #[test] @@ -198,7 +406,30 @@ fn test_no_labels() { None, DebugValue::Counter(1), )] - ) + ); +} + +#[test] +fn test_no_labels_record() { + let (_guard, snapshotter) = setup(TracingContextLayer::all()); + + let span = span!(Level::TRACE, "login", user.id = tracing_core::field::Empty); + let _guard = span.enter(); + + span.record("user.id", 42); + counter!("login_attempts").increment(1); + + let snapshot = snapshotter.snapshot().into_vec(); + + assert_eq!( + snapshot, + vec![( + CompositeKey::new(MetricKind::Counter, Key::from_static_parts(LOGIN_ATTEMPTS, USER_ID)), + None, + None, + DebugValue::Counter(1), + )] + ); } #[test] @@ -262,7 +493,7 @@ fn test_multiple_paths_to_the_same_callsite() { DebugValue::Counter(1), ) ] - ) + ); } #[test] @@ -347,12 +578,12 @@ fn test_label_filtering() { None, DebugValue::Counter(1), )] - ) + ); } #[test] fn test_label_allowlist() { - let (_guard, snapshotter) = setup(TracingContextLayer::only_allow(&["env", "service"])); + let (_guard, snapshotter) = setup(TracingContextLayer::only_allow(["env", "service"])); let user = "ferris"; let email = "ferris@rust-lang.org"; @@ -378,5 +609,187 @@ fn test_label_allowlist() { None, DebugValue::Counter(1), )] - ) + ); +} + +#[test] +fn test_all_permutations() { + let perms = (0..9).map(|_| [false, true]).multi_cartesian_product(); + + for v in perms { + let [metric_has_labels, in_span, span_has_fields, span_field_same_as_metric, span_has_parent, parent_field_same_as_span, span_field_is_empty, record_field, increment_before_recording] = + v[..] + else { + unreachable!("{:?}, {}", v, v.len()); + }; + + test( + metric_has_labels, + in_span, + span_has_fields, + span_field_same_as_metric, + span_has_parent, + parent_field_same_as_span, + span_field_is_empty, + record_field, + increment_before_recording, + ); + } +} + +#[allow(clippy::fn_params_excessive_bools, clippy::too_many_arguments, clippy::too_many_lines)] +fn test( + metric_has_labels: bool, + in_span: bool, + span_has_fields: bool, + span_field_same_as_metric: bool, + span_has_parent: bool, + parent_field_same_as_span: bool, + span_field_is_empty: bool, + record_field: bool, + increment_before_recording: bool, +) { + let (_guard, snapshotter) = setup(TracingContextLayer::all()); + + let parent = if span_field_same_as_metric && parent_field_same_as_span { + tracing::trace_span!("outer", user.email = "changed@domain.com") + } else { + tracing::trace_span!("outer", user.id = 999) + }; + + let _guard = span_has_parent.then(|| parent.enter()); + + let span = if span_has_fields { + match (span_field_same_as_metric, span_field_is_empty) { + (false, false) => tracing::trace_span!("login", user.id = 666), + (false, true) => tracing::trace_span!("login", user.id = tracing_core::field::Empty), + (true, false) => tracing::trace_span!("login", user.email = "user@domain.com"), + (true, true) => tracing::trace_span!("login", user.email = tracing_core::field::Empty), + } + } else { + tracing::trace_span!("login") + }; + + let _guard = in_span.then(|| span.enter()); + + let increment = || { + if metric_has_labels { + counter!("login_attempts", "user.email" => "ferris@rust-lang.org").increment(1); + } else { + counter!("login_attempts").increment(1); + } + }; + + if increment_before_recording { + increment(); + } + + if record_field { + span.record("user.id", 42); + } + + increment(); + + let snapshot = snapshotter.snapshot().into_vec(); + + let mut expected = vec![]; + + if in_span + && span_has_fields + && !span_field_same_as_metric + && record_field + && increment_before_recording + { + expected.push(( + CompositeKey::new( + MetricKind::Counter, + Key::from_parts( + LOGIN_ATTEMPTS, + IntoIterator::into_iter([ + (span_has_parent || !span_field_is_empty).then(|| { + Label::new("user.id", if span_field_is_empty { "999" } else { "666" }) + }), + metric_has_labels.then(|| Label::new("user.email", "ferris@rust-lang.org")), + ]) + .flatten() + .collect::>(), + ), + ), + None, + None, + DebugValue::Counter(1), + )); + } + + let in_span_with_metric_field = + in_span && span_has_fields && span_field_same_as_metric && !span_field_is_empty; + let has_other_labels = !(!span_has_parent + && (!in_span + || (span_field_same_as_metric || !span_has_fields) + || (!record_field && span_field_is_empty))) + && !(span_field_same_as_metric && parent_field_same_as_span) + && !in_span_with_metric_field; + + expected.push(( + CompositeKey::new( + MetricKind::Counter, + Key::from_parts( + LOGIN_ATTEMPTS, + IntoIterator::into_iter([ + (metric_has_labels && !has_other_labels) + .then(|| Label::new("user.email", "ferris@rust-lang.org")), + (!metric_has_labels + && (in_span_with_metric_field + || span_field_same_as_metric + && span_has_parent + && parent_field_same_as_span)) + .then(|| { + if in_span_with_metric_field { + Label::new("user.email", "user@domain.com") + } else { + Label::new("user.email", "changed@domain.com") + } + }), + if in_span && span_has_fields && !span_field_same_as_metric && record_field { + Some(Label::new("user.id", "42")) + } else if in_span + && span_has_fields + && !span_field_same_as_metric + && !span_field_is_empty + && !record_field + { + Some(Label::new("user.id", "666")) + } else if (!in_span || !span_has_fields || span_field_same_as_metric) + && (!span_field_same_as_metric || !parent_field_same_as_span) + && span_has_parent + || span_has_parent + && span_field_is_empty + && !record_field + && !span_field_same_as_metric + { + Some(Label::new("user.id", "999")) + } else { + None + }, + (metric_has_labels && has_other_labels) + .then(|| Label::new("user.email", "ferris@rust-lang.org")), + ]) + .flatten() + .collect::>(), + ), + ), + None, + None, + DebugValue::Counter( + if !increment_before_recording + || in_span && span_has_fields && !span_field_same_as_metric && record_field + { + 1 + } else { + 2 + }, + ), + )); + + assert_eq!(snapshot, expected); }