From 5ff6e37c5907e92c3ac151e14643290d0a41c498 Mon Sep 17 00:00:00 2001 From: Eliza Weisman Date: Fri, 1 Mar 2019 11:29:11 -0800 Subject: [PATCH] trace: Allow specifying a new span's parent (#923) This branch allows users of `tokio-trace` to explicitly set a span's parent, or indicate that a span should be a new root of its own trace tree. A `parent: ` key has been added to the `span!` macros. When a span is provided, that span will be set as the parent, while `parent: None` will result in a new root span. No `parent:` key results in the current behaviour. A new type, `span::Attributes`, was added to `tokio-trace-core` to act as an arguments struct for the `Subscriber::new_span` method. This will allow future fields to be added without causing breaking API changes. The `Attributes` struct currently contains the new span's metadata, `ValueSet`, and parent. Finally, the `span::Span` type in `-core` was renamed to `span::Id`, for consistency with `tokio-trace` and to differentiate it from `span::Attributes`. This name was chosen primarily due to precedent in other tracing systems. Closes #920 Signed-off-by: Eliza Weisman --- tokio-trace/benches/subscriber.rs | 8 +- tokio-trace/examples/counters.rs | 4 +- .../examples/sloggish/sloggish_subscriber.rs | 10 +- tokio-trace/src/lib.rs | 161 ++++++++++++++++-- tokio-trace/src/span.rs | 68 ++++++-- tokio-trace/tests/macros.rs | 57 +++++++ tokio-trace/tests/span.rs | 105 ++++++++++++ tokio-trace/tests/support/mod.rs | 2 + tokio-trace/tests/support/span.rs | 68 ++++++++ tokio-trace/tests/support/subscriber.rs | 63 ++++++- .../tokio-trace-core/src/dispatcher.rs | 57 +++---- tokio-trace/tokio-trace-core/src/lib.rs | 1 - tokio-trace/tokio-trace-core/src/metadata.rs | 2 +- tokio-trace/tokio-trace-core/src/span.rs | 118 ++++++++++++- .../tokio-trace-core/src/subscriber.rs | 50 +++--- 15 files changed, 671 insertions(+), 103 deletions(-) diff --git a/tokio-trace/benches/subscriber.rs b/tokio-trace/benches/subscriber.rs index fd60979b1..b425929fb 100644 --- a/tokio-trace/benches/subscriber.rs +++ b/tokio-trace/benches/subscriber.rs @@ -15,8 +15,8 @@ use tokio_trace::{field, span, Event, Id, Metadata}; struct EnabledSubscriber; impl tokio_trace::Subscriber for EnabledSubscriber { - fn new_span(&self, span: &Metadata, values: &field::ValueSet) -> Id { - let _ = (span, values); + fn new_span(&self, span: &span::Attributes) -> Id { + let _ = span; Id::from_u64(0) } @@ -59,9 +59,9 @@ impl<'a> field::Record for Recorder<'a> { } impl tokio_trace::Subscriber for RecordingSubscriber { - fn new_span(&self, _span: &Metadata, values: &field::ValueSet) -> Id { + fn new_span(&self, span: &span::Attributes) -> Id { let mut recorder = Recorder(self.0.lock().unwrap()); - values.record(&mut recorder); + span.values().record(&mut recorder); Id::from_u64(0) } diff --git a/tokio-trace/examples/counters.rs b/tokio-trace/examples/counters.rs index 9c617c4c6..c492ebb0a 100644 --- a/tokio-trace/examples/counters.rs +++ b/tokio-trace/examples/counters.rs @@ -77,8 +77,8 @@ impl Subscriber for CounterSubscriber { interest } - fn new_span(&self, _new_span: &Metadata, values: &field::ValueSet) -> Id { - values.record(&mut self.recorder()); + fn new_span(&self, new_span: &span::Attributes) -> Id { + new_span.values().record(&mut self.recorder()); let id = self.ids.fetch_add(1, Ordering::SeqCst); Id::from_u64(id as u64) } diff --git a/tokio-trace/examples/sloggish/sloggish_subscriber.rs b/tokio-trace/examples/sloggish/sloggish_subscriber.rs index 4a93f9353..ae365f3fc 100644 --- a/tokio-trace/examples/sloggish/sloggish_subscriber.rs +++ b/tokio-trace/examples/sloggish/sloggish_subscriber.rs @@ -206,14 +206,12 @@ impl Subscriber for SloggishSubscriber { true } - fn new_span( - &self, - span: &tokio_trace::Metadata, - values: &tokio_trace::field::ValueSet, - ) -> tokio_trace::Id { + fn new_span(&self, span: &tokio_trace::span::Attributes) -> tokio_trace::Id { + let meta = span.metadata(); + let values = span.values(); let next = self.ids.fetch_add(1, Ordering::SeqCst) as u64; let id = tokio_trace::Id::from_u64(next); - let span = Span::new(self.current.id(), span, values); + let span = Span::new(self.current.id(), meta, values); self.spans.lock().unwrap().insert(id.clone(), span); id } diff --git a/tokio-trace/src/lib.rs b/tokio-trace/src/lib.rs index 84c9ff563..198764ff6 100644 --- a/tokio-trace/src/lib.rs +++ b/tokio-trace/src/lib.rs @@ -247,9 +247,9 @@ //! #[macro_use] //! extern crate tokio_trace; //! # pub struct FooSubscriber; -//! # use tokio_trace::{span::Id, Metadata, field::ValueSet}; +//! # use tokio_trace::{span::{Id, Attributes}, Metadata, field::ValueSet}; //! # impl tokio_trace::Subscriber for FooSubscriber { -//! # fn new_span(&self, _: &Metadata, _: &ValueSet) -> Id { Id::from_u64(0) } +//! # fn new_span(&self, _: &Attributes) -> Id { Id::from_u64(0) } //! # fn record(&self, _: &Id, _: &ValueSet) {} //! # fn event(&self, _: &tokio_trace::Event) {} //! # fn record_follows_from(&self, _: &Id, _: &Id) {} @@ -488,12 +488,30 @@ macro_rules! callsite { /// ``` #[macro_export] macro_rules! span { - (target: $target:expr, level: $lvl:expr, $name:expr, $($k:ident $( = $val:expr )* ),*,) => { - span!(target: $target, level: $lvl, $name, $($k $( = $val)*),*) + ( + target: $target:expr, + level: $lvl:expr, + parent: $parent:expr, + $name:expr, + $($k:ident $( = $val:expr )* ),*, + ) => { + span!( + target: $target, + level: $lvl, + parent: $parent, + $name, + $($k $( = $val)*),* + ) }; - (target: $target:expr, level: $lvl:expr, $name:expr, $($k:ident $( = $val:expr )* ),*) => { + ( + target: $target:expr, + level: $lvl:expr, + parent: $parent:expr, + $name:expr, + $($k:ident $( = $val:expr )* ),* + ) => { { - use $crate::{callsite, field::{Value, ValueSet, AsField}, Span}; + use $crate::callsite; use $crate::callsite::Callsite; let callsite = callsite! { name: $name, @@ -503,17 +521,135 @@ macro_rules! span { }; if is_enabled!(callsite) { let meta = callsite.metadata(); - Span::new(meta, &valueset!(meta.fields(), $($k $( = $val)*),*)) + $crate::Span::child_of( + $parent, + meta, + &valueset!(meta.fields(), $($k $( = $val)*),*), + ) } else { - Span::new_disabled() + $crate::Span::new_disabled() } } }; + ( + target: $target:expr, + level: $lvl:expr, + $name:expr, + $($k:ident $( = $val:expr )* ),* + ) => { + { + use $crate::callsite; + use $crate::callsite::Callsite; + let callsite = callsite! { + name: $name, + target: $target, + level: $lvl, + fields: $($k),* + }; + if is_enabled!(callsite) { + let meta = callsite.metadata(); + $crate::Span::new( + meta, + &valueset!(meta.fields(), $($k $( = $val)*),*), + ) + } else { + $crate::Span::new_disabled() + } + } + }; + (target: $target:expr, level: $lvl:expr, parent: $parent:expr, $name:expr) => { + span!(target: $target, level: $lvl, parent: $parent, $name,) + }; + (level: $lvl:expr, parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr )* ),*,) => { + span!( + target: module_path!(), + level: $lvl, + parent: $parent, + $name, + $($k $( = $val)*),* + ) + }; + (level: $lvl:expr, parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr )* ),*) => { + span!( + target: module_path!(), + level: $lvl, + parent: $parent, + $name, + $($k $( = $val)*),* + ) + }; + (level: $lvl:expr, parent: $parent:expr, $name:expr) => { + span!(target: module_path!(), level: $lvl, parent: $parent, $name,) + }; + (parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr)*),*,) => { + span!( + target: module_path!(), + level: $crate::Level::TRACE, + parent: $parent, + $name, + $($k $( = $val)*),* + ) + }; + (parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr)*),*) => { + span!( + target: module_path!(), + level: $crate::Level::TRACE, + parent: $parent, + $name, + $($k $( = $val)*),* + ) + }; + (parent: $parent:expr, $name:expr) => { + span!( + target: module_path!(), + level: $crate::Level::TRACE, + parent: $parent, + $name, + ) + }; + ( + target: $target:expr, + level: $lvl:expr, + $name:expr, + $($k:ident $( = $val:expr )* ),*, + ) => { + span!( + target: $target, + level: $lvl, + $name, + $($k $( = $val)*),* + ) + }; + ( + target: $target:expr, + level: $lvl:expr, + $name:expr, + $($k:ident $( = $val:expr )* ),* + ) => { + span!( + target: $target, + level: $lvl, + $name, + $($k $( = $val)*),* + ) + }; (target: $target:expr, level: $lvl:expr, $name:expr) => { span!(target: $target, level: $lvl, $name,) }; + (target: $target:expr, level: $lvl:expr, $name:expr,) => { + span!( + target: $target, + level: $lvl, + $name, + ) + }; (level: $lvl:expr, $name:expr, $($k:ident $( = $val:expr )* ),*,) => { - span!(target: module_path!(), level: $lvl, $name, $($k $( = $val)*),*) + span!( + target: module_path!(), + level: $lvl, + $name, + $($k $( = $val)*),* + ) }; (level: $lvl:expr, $name:expr, $($k:ident $( = $val:expr )* ),*) => { span!(target: module_path!(), level: $lvl, $name, $($k $( = $val)*),*) @@ -525,7 +661,12 @@ macro_rules! span { span!(target: module_path!(), level: $crate::Level::TRACE, $name, $($k $( = $val)*),*) }; ($name:expr, $($k:ident $( = $val:expr)*),*) => { - span!(target: module_path!(), level: $crate::Level::TRACE, $name, $($k $( = $val)*),*) + span!( + target: module_path!(), + level: $crate::Level::TRACE, + $name, + $($k $( = $val)*),* + ) }; ($name:expr) => { span!(target: module_path!(), level: $crate::Level::TRACE, $name,) }; } diff --git a/tokio-trace/src/span.rs b/tokio-trace/src/span.rs index af098bdc4..f2540622c 100644 --- a/tokio-trace/src/span.rs +++ b/tokio-trace/src/span.rs @@ -135,8 +135,7 @@ //! the data for future use, record it in some manner, or discard it completely. //! //! [`Subscriber`]: ::Subscriber -// TODO: remove this re-export? -pub use tokio_trace_core::span::Span as Id; +pub use tokio_trace_core::span::{Attributes, Id}; use std::{ borrow::Borrow, @@ -209,7 +208,8 @@ struct Entered<'a> { // ===== impl Span ===== impl<'a> Span<'a> { - /// Constructs a new `Span` with the given [metadata] and set of [field values]. + /// Constructs a new `Span` with the given [metadata] and set of [field + /// values]. /// /// The new span will be constructed by the currently-active [`Subscriber`], /// with the current span as its parent (if one exists). @@ -223,14 +223,42 @@ impl<'a> Span<'a> { /// [`follows_from`]: ::span::Span::follows_from #[inline] pub fn new(meta: &'a Metadata<'a>, values: &field::ValueSet) -> Span<'a> { - let inner = dispatcher::with(move |dispatch| { - let id = dispatch.new_span(meta, values); - Some(Inner::new(id, dispatch, meta)) - }); - Self { - inner, - is_closed: false, - } + let new_span = Attributes::new(meta, values); + Self::make(meta, new_span) + } + + /// Constructs a new `Span` as the root of its own trace tree, with the + /// given [metadata] and set of [field values]. + /// + /// After the span is constructed, [field values] and/or [`follows_from`] + /// annotations may be added to it. + /// + /// [metadata]: ::metadata::Metadata + /// [field values]: ::field::ValueSet + /// [`follows_from`]: ::span::Span::follows_from + #[inline] + pub fn new_root(meta: &'a Metadata<'a>, values: &field::ValueSet) -> Span<'a> { + Self::make(meta, Attributes::new_root(meta, values)) + } + + /// Constructs a new `Span` as child of the given parent span, with the + /// given [metadata] and set of [field values]. + /// + /// After the span is constructed, [field values] and/or [`follows_from`] + /// annotations may be added to it. + /// + /// [metadata]: ::metadata::Metadata + /// [field values]: ::field::ValueSet + /// [`follows_from`]: ::span::Span::follows_from + pub fn child_of(parent: I, meta: &'a Metadata<'a>, values: &field::ValueSet) -> Span<'a> + where + I: Into>, + { + let new_span = match parent.into() { + Some(parent) => Attributes::child_of(parent, meta, values), + None => Attributes::new_root(meta, values), + }; + Self::make(meta, new_span) } /// Constructs a new disabled span. @@ -242,6 +270,18 @@ impl<'a> Span<'a> { } } + #[inline(always)] + fn make(meta: &'a Metadata<'a>, new_span: Attributes) -> Span<'a> { + let inner = dispatcher::with(move |dispatch| { + let id = dispatch.new_span(&new_span); + Some(Inner::new(id, dispatch, meta)) + }); + Self { + inner, + is_closed: false, + } + } + /// Executes the given function in the context of this span. /// /// If this span is enabled, then this function enters the span, invokes @@ -380,6 +420,12 @@ impl<'a> fmt::Debug for Span<'a> { } } +impl<'a> Into> for &'a Span<'a> { + fn into(self) -> Option { + self.id() + } +} + // ===== impl Inner ===== impl<'a> Inner<'a> { diff --git a/tokio-trace/tests/macros.rs b/tokio-trace/tests/macros.rs index 002b787c6..903fd2dbf 100644 --- a/tokio-trace/tests/macros.rs +++ b/tokio-trace/tests/macros.rs @@ -22,6 +22,63 @@ fn span() { span!("bar",); } +#[test] +fn span_root() { + span!(target: "foo_events", level: tokio_trace::Level::DEBUG, parent: None, "foo", bar = 2, baz = 3); + span!(target: "foo_events", level: tokio_trace::Level::DEBUG, parent: None, "foo", bar = 2, baz = 4,); + span!(target: "foo_events", level: tokio_trace::Level::DEBUG, parent: None, "foo"); + span!(target: "foo_events", level: tokio_trace::Level::DEBUG, parent: None, "bar",); + span!( + level: tokio_trace::Level::DEBUG, + parent: None, + "foo", + bar = 2, + baz = 3 + ); + span!( + level: tokio_trace::Level::DEBUG, + parent: None, + "foo", + bar = 2, + baz = 4, + ); + span!(level: tokio_trace::Level::DEBUG, parent: None, "foo"); + span!(level: tokio_trace::Level::DEBUG, parent: None, "bar",); + span!(parent: None, "foo", bar = 2, baz = 3); + span!(parent: None, "foo", bar = 2, baz = 4,); + span!(parent: None, "foo"); + span!(parent: None, "bar",); +} + +#[test] +fn span_with_parent() { + let p = span!("im_a_parent!"); + span!(target: "foo_events", level: tokio_trace::Level::DEBUG, parent: &p, "foo", bar = 2, baz = 3); + span!(target: "foo_events", level: tokio_trace::Level::DEBUG, parent: &p, "foo", bar = 2, baz = 4,); + span!(target: "foo_events", level: tokio_trace::Level::DEBUG, parent: &p, "foo"); + span!(target: "foo_events", level: tokio_trace::Level::DEBUG, parent: &p, "bar",); + span!( + level: tokio_trace::Level::DEBUG, + parent: &p, + "foo", + bar = 2, + baz = 3 + ); + span!( + level: tokio_trace::Level::DEBUG, + parent: &p, + "foo", + bar = 2, + baz = 4, + ); + span!(level: tokio_trace::Level::DEBUG, parent: &p, "foo"); + span!(level: tokio_trace::Level::DEBUG, parent: &p, "bar",); + span!(parent: &p, "foo", bar = 2, baz = 3); + span!(parent: &p, "foo", bar = 2, baz = 4,); + span!(parent: &p, "foo"); + span!(parent: &p, "bar",); +} + #[test] fn event() { event!(tokio_trace::Level::DEBUG, foo = 3, bar = 2, baz = false); diff --git a/tokio-trace/tests/span.rs b/tokio-trace/tests/span.rs index 45c192982..1fb3a530b 100644 --- a/tokio-trace/tests/span.rs +++ b/tokio-trace/tests/span.rs @@ -476,3 +476,108 @@ fn new_span_with_target_and_log_level() { handle.assert_finished(); } + +#[test] +fn explicit_root_span_is_root() { + let (subscriber, handle) = subscriber::mock() + .new_span(span::mock().named("foo").with_explicit_parent(None)) + .done() + .run_with_handle(); + + with_default(subscriber, || { + span!(parent: None, "foo"); + }); + + handle.assert_finished(); +} + +#[test] +fn explicit_root_span_is_root_regardless_of_ctx() { + let (subscriber, handle) = subscriber::mock() + .new_span(span::mock().named("foo")) + .enter(span::mock().named("foo")) + .new_span(span::mock().named("bar").with_explicit_parent(None)) + .exit(span::mock().named("foo")) + .done() + .run_with_handle(); + + with_default(subscriber, || { + span!("foo").enter(|| { + span!(parent: None, "bar"); + }) + }); + + handle.assert_finished(); +} + +#[test] +fn explicit_child() { + let (subscriber, handle) = subscriber::mock() + .new_span(span::mock().named("foo")) + .new_span(span::mock().named("bar").with_explicit_parent(Some("foo"))) + .done() + .run_with_handle(); + + with_default(subscriber, || { + let foo = span!("foo"); + span!(parent: foo.id(), "bar"); + }); + + handle.assert_finished(); +} + +#[test] +fn explicit_child_regardless_of_ctx() { + let (subscriber, handle) = subscriber::mock() + .new_span(span::mock().named("foo")) + .new_span(span::mock().named("bar")) + .enter(span::mock().named("bar")) + .new_span(span::mock().named("baz").with_explicit_parent(Some("foo"))) + .exit(span::mock().named("bar")) + .done() + .run_with_handle(); + + with_default(subscriber, || { + let foo = span!("foo"); + span!("bar").enter(|| span!(parent: foo.id(), "baz")) + }); + + handle.assert_finished(); +} + +#[test] +fn contextual_root() { + let (subscriber, handle) = subscriber::mock() + .new_span(span::mock().named("foo").with_contextual_parent(None)) + .done() + .run_with_handle(); + + with_default(subscriber, || { + span!("foo"); + }); + + handle.assert_finished(); +} + +#[test] +fn contextual_child() { + let (subscriber, handle) = subscriber::mock() + .new_span(span::mock().named("foo")) + .enter(span::mock().named("foo")) + .new_span( + span::mock() + .named("bar") + .with_contextual_parent(Some("foo")), + ) + .exit(span::mock().named("foo")) + .done() + .run_with_handle(); + + with_default(subscriber, || { + span!("foo").enter(|| { + span!("bar"); + }) + }); + + handle.assert_finished(); +} diff --git a/tokio-trace/tests/support/mod.rs b/tokio-trace/tests/support/mod.rs index b8f78cc7a..1bf62ec55 100644 --- a/tokio-trace/tests/support/mod.rs +++ b/tokio-trace/tests/support/mod.rs @@ -4,3 +4,5 @@ pub mod field; mod metadata; pub mod span; pub mod subscriber; + +extern crate tokio_trace_core; diff --git a/tokio-trace/tests/support/span.rs b/tokio-trace/tests/support/span.rs index e1e738780..92d9c2293 100644 --- a/tokio-trace/tests/support/span.rs +++ b/tokio-trace/tests/support/span.rs @@ -11,10 +11,19 @@ pub struct MockSpan { pub(in support) metadata: metadata::Expect, } +#[derive(Debug, Eq, PartialEq)] +pub(in support) enum Parent { + ContextualRoot, + Contextual(String), + ExplicitRoot, + Explicit(String), +} + #[derive(Debug, Default, Eq, PartialEq)] pub struct NewSpan { pub(in support) span: MockSpan, pub(in support) fields: field::Expect, + pub(in support) parent: Option, } pub fn mock() -> MockSpan { @@ -60,6 +69,30 @@ impl MockSpan { } } + pub fn with_explicit_parent(self, parent: Option<&str>) -> NewSpan { + let parent = match parent { + Some(name) => Parent::Explicit(name.into()), + None => Parent::ExplicitRoot, + }; + NewSpan { + parent: Some(parent), + span: self, + ..Default::default() + } + } + + pub fn with_contextual_parent(self, parent: Option<&str>) -> NewSpan { + let parent = match parent { + Some(name) => Parent::Contextual(name.into()), + None => Parent::ContextualRoot, + }; + NewSpan { + parent: Some(parent), + span: self, + ..Default::default() + } + } + pub fn name(&self) -> Option<&str> { self.metadata.name.as_ref().map(String::as_ref) } @@ -71,6 +104,7 @@ impl MockSpan { NewSpan { span: self, fields: fields.into(), + ..Default::default() } } @@ -98,6 +132,40 @@ impl Into for MockSpan { } } +impl NewSpan { + pub fn with_explicit_parent(self, parent: Option<&str>) -> NewSpan { + let parent = match parent { + Some(name) => Parent::Explicit(name.into()), + None => Parent::ExplicitRoot, + }; + NewSpan { + parent: Some(parent), + ..self + } + } + + pub fn with_contextual_parent(self, parent: Option<&str>) -> NewSpan { + let parent = match parent { + Some(name) => Parent::Contextual(name.into()), + None => Parent::ContextualRoot, + }; + NewSpan { + parent: Some(parent), + ..self + } + } + + pub fn with_field(self, fields: I) -> NewSpan + where + I: Into, + { + NewSpan { + fields: fields.into(), + ..self + } + } +} + impl fmt::Display for NewSpan { fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result { write!(f, "a new span{}", self.span.metadata)?; diff --git a/tokio-trace/tests/support/subscriber.rs b/tokio-trace/tests/support/subscriber.rs index 662e0cc39..b4fe5178d 100644 --- a/tokio-trace/tests/support/subscriber.rs +++ b/tokio-trace/tests/support/subscriber.rs @@ -12,7 +12,11 @@ use std::{ Arc, Mutex, }, }; -use tokio_trace::{field, Event, Id, Metadata, Subscriber}; +use tokio_trace::{ + field, + span::{Attributes, Id}, + Event, Metadata, Subscriber, +}; #[derive(Debug, Eq, PartialEq)] enum Expect { @@ -34,6 +38,7 @@ struct SpanState { struct Running bool> { spans: Mutex>, expected: Arc>>, + current: Mutex>, ids: AtomicUsize, filter: F, } @@ -120,6 +125,7 @@ impl bool> MockSubscriber { let subscriber = Running { spans: Mutex::new(HashMap::new()), expected, + current: Mutex::new(Vec::new()), ids: AtomicUsize::new(0), filter: self.filter, }; @@ -172,7 +178,10 @@ impl bool> Subscriber for Running { // TODO: it should be possible to expect spans to follow from other spans } - fn new_span(&self, meta: &Metadata, values: &field::ValueSet) -> Id { + fn new_span(&self, span: &Attributes) -> Id { + use span::Parent; + let meta = span.metadata(); + let values = span.values(); let id = self.ids.fetch_add(1, Ordering::SeqCst); let id = Id::from_u64(id as u64); println!( @@ -186,6 +195,7 @@ impl bool> Subscriber for Running { Some(Expect::NewSpan(_)) => true, _ => false, }; + let mut spans = self.spans.lock().unwrap(); if was_expected { if let Expect::NewSpan(mut expected) = expected.pop_front().unwrap() { let name = meta.name(); @@ -196,9 +206,47 @@ impl bool> Subscriber for Running { let mut checker = expected.fields.checker(format!("{}", name)); values.record(&mut checker); checker.finish(); + match expected.parent { + Some(Parent::ExplicitRoot) => { + assert!( + span.is_root(), + "expected {:?} to be an explicit root span", + name + ); + } + Some(Parent::Explicit(expected_parent)) => { + let actual_parent = + span.parent().and_then(|id| spans.get(id)).map(|s| s.name); + assert_eq!(Some(expected_parent.as_ref()), actual_parent); + } + Some(Parent::ContextualRoot) => { + assert!( + span.is_contextual(), + "expected {:?} to have a contextual parent", + name + ); + assert!( + self.current.lock().unwrap().last().is_none(), + "expected {:?} to be a root, but we were inside a span", + name + ); + } + Some(Parent::Contextual(expected_parent)) => { + assert!( + span.is_contextual(), + "expected {:?} to have a contextual parent", + name + ); + let stack = self.current.lock().unwrap(); + let actual_parent = + stack.last().and_then(|id| spans.get(id)).map(|s| s.name); + assert_eq!(Some(expected_parent.as_ref()), actual_parent); + } + None => {} + } } } - self.spans.lock().unwrap().insert( + spans.insert( id.clone(), SpanState { name: meta.name(), @@ -222,6 +270,7 @@ impl bool> Subscriber for Running { Some(ex) => ex.bad(format_args!("entered span {:?}", span.name)), } }; + self.current.lock().unwrap().push(id.clone()); } fn exit(&self, id: &Id) { @@ -236,6 +285,14 @@ impl bool> Subscriber for Running { if let Some(name) = expected_span.name() { assert_eq!(name, span.name); } + let curr = self.current.lock().unwrap().pop(); + assert_eq!( + Some(id), + curr.as_ref(), + "exited span {:?}, but the current span was {:?}", + span.name, + curr.as_ref().and_then(|id| spans.get(id)).map(|s| s.name) + ); } Some(ex) => ex.bad(format_args!("exited span {:?}", span.name)), }; diff --git a/tokio-trace/tokio-trace-core/src/dispatcher.rs b/tokio-trace/tokio-trace-core/src/dispatcher.rs index 05d35fdf3..eb874955a 100644 --- a/tokio-trace/tokio-trace-core/src/dispatcher.rs +++ b/tokio-trace/tokio-trace-core/src/dispatcher.rs @@ -1,8 +1,8 @@ //! Dispatches trace events to `Subscriber`s. use { - callsite, field, + callsite, field, span, subscriber::{self, Subscriber}, - Event, Metadata, Span, + Event, Metadata, }; use std::{ @@ -23,12 +23,12 @@ thread_local! { /// Sets this dispatch as the default for the duration of a closure. /// -/// The default dispatcher is used when creating a new [`Span`] or +/// The default dispatcher is used when creating a new [span] or /// [`Event`], _if no span is currently executing_. If a span is currently /// executing, new spans or events are dispatched to the subscriber that /// tagged that span, instead. /// -/// [`Span`]: ::span::Span +/// [span]: ../span/index.html /// [`Subscriber`]: ::Subscriber /// [`Event`]: ::Event pub fn with_default(dispatcher: Dispatch, f: impl FnOnce() -> T) -> T { @@ -97,16 +97,16 @@ impl Dispatch { self.subscriber.register_callsite(metadata) } - /// Record the construction of a new [`Span`], returning a new ID for the + /// Record the construction of a new span, returning a new [ID] for the /// span being constructed. /// /// This calls the [`new_span`](::Subscriber::new_span) /// function on the `Subscriber` that this `Dispatch` forwards to. /// - /// [`Span`]: ::span::Span + /// [ID]: ../span/struct.Id.html #[inline] - pub fn new_span(&self, metadata: &Metadata, values: &field::ValueSet) -> Span { - self.subscriber.new_span(metadata, values) + pub fn new_span(&self, span: &span::Attributes) -> span::Id { + self.subscriber.new_span(span) } /// Record a set of values on a span. @@ -114,7 +114,7 @@ impl Dispatch { /// This calls the [`record`](::Subscriber::record) /// function on the `Subscriber` that this `Dispatch` forwards to. #[inline] - pub fn record(&self, span: &Span, values: &field::ValueSet) { + pub fn record(&self, span: &span::Id, values: &field::ValueSet) { self.subscriber.record(span, &values) } @@ -124,7 +124,7 @@ impl Dispatch { /// This calls the [`record_follows_from`](::Subscriber::record_follows_from) /// function on the `Subscriber` that this `Dispatch` forwards to. #[inline] - pub fn record_follows_from(&self, span: &Span, follows: &Span) { + pub fn record_follows_from(&self, span: &span::Id, follows: &span::Id) { self.subscriber.record_follows_from(span, follows) } @@ -151,29 +151,25 @@ impl Dispatch { self.subscriber.event(event) } - /// Records that a [`Span`] has been entered. + /// Records that a span has been entered. /// /// This calls the [`enter`](::Subscriber::enter) function on the /// `Subscriber` that this `Dispatch` forwards to. - /// - /// [`Span`]: ::span::Span #[inline] - pub fn enter(&self, span: &Span) { + pub fn enter(&self, span: &span::Id) { self.subscriber.enter(span) } - /// Records that a [`Span`] has been exited. + /// Records that a span has been exited. /// /// This calls the [`exit`](::Subscriber::exit) function on the `Subscriber` /// that this `Dispatch` forwards to. - /// - /// [`Span`]: ::span::Span #[inline] - pub fn exit(&self, span: &Span) { + pub fn exit(&self, span: &span::Id) { self.subscriber.exit(span) } - /// Notifies the subscriber that a [`Span`] has been cloned. + /// Notifies the subscriber that a [span ID] has been cloned. /// /// This function is guaranteed to only be called with span IDs that were /// returned by this `Dispatch`'s `new_span` function. @@ -181,14 +177,13 @@ impl Dispatch { /// This calls the [`clone_span`](::Subscriber::clone_span) function on /// the `Subscriber` that this `Dispatch` forwards to. /// - /// [`Span`]: ::span::Span + /// [span ID]: ../span/struct.Id.html #[inline] - pub fn clone_span(&self, id: &Span) -> Span { + pub fn clone_span(&self, id: &span::Id) -> span::Id { self.subscriber.clone_span(&id) } - /// Notifies the subscriber that a [`Span`] handle with the given [`Id`] has - /// been dropped. + /// Notifies the subscriber that a [span ID] handle has been dropped. /// /// This function is guaranteed to only be called with span IDs that were /// returned by this `Dispatch`'s `new_span` function. @@ -196,9 +191,9 @@ impl Dispatch { /// This calls the [`drop_span`](::Subscriber::drop_span) function on /// the `Subscriber` that this `Dispatch` forwards to. /// - /// [`Span`]: ::span::Span + /// [span ID]: ../span/struct.Id.html #[inline] - pub fn drop_span(&self, id: Span) { + pub fn drop_span(&self, id: span::Id) { self.subscriber.drop_span(id) } } @@ -226,23 +221,23 @@ impl Subscriber for NoSubscriber { subscriber::Interest::never() } - fn new_span(&self, _meta: &Metadata, _vals: &field::ValueSet) -> Span { - Span::from_u64(0) + fn new_span(&self, _: &span::Attributes) -> span::Id { + span::Id::from_u64(0) } fn event(&self, _event: &Event) {} - fn record(&self, _span: &Span, _values: &field::ValueSet) {} + fn record(&self, _span: &span::Id, _values: &field::ValueSet) {} - fn record_follows_from(&self, _span: &Span, _follows: &Span) {} + fn record_follows_from(&self, _span: &span::Id, _follows: &span::Id) {} #[inline] fn enabled(&self, _metadata: &Metadata) -> bool { false } - fn enter(&self, _span: &Span) {} - fn exit(&self, _span: &Span) {} + fn enter(&self, _span: &span::Id) {} + fn exit(&self, _span: &span::Id) {} } impl Registrar { diff --git a/tokio-trace/tokio-trace-core/src/lib.rs b/tokio-trace/tokio-trace-core/src/lib.rs index ab9c4b7c5..a6642c0eb 100644 --- a/tokio-trace/tokio-trace-core/src/lib.rs +++ b/tokio-trace/tokio-trace-core/src/lib.rs @@ -176,7 +176,6 @@ pub use self::{ event::Event, field::Field, metadata::{Level, Metadata}, - span::Span, subscriber::{Interest, Subscriber}, }; diff --git a/tokio-trace/tokio-trace-core/src/metadata.rs b/tokio-trace/tokio-trace-core/src/metadata.rs index 154e53750..58bb31257 100644 --- a/tokio-trace/tokio-trace-core/src/metadata.rs +++ b/tokio-trace/tokio-trace-core/src/metadata.rs @@ -124,7 +124,7 @@ pub struct Metadata<'a> { pub fields: field::FieldSet, } -/// Describes the level of verbosity of a `Span`. +/// Describes the level of verbosity of a span or event. #[derive(Clone, Debug, Eq, PartialEq, Ord, PartialOrd)] pub struct Level(LevelInner); diff --git a/tokio-trace/tokio-trace-core/src/span.rs b/tokio-trace/tokio-trace-core/src/span.rs index 7b93d8d69..8428b7453 100644 --- a/tokio-trace/tokio-trace-core/src/span.rs +++ b/tokio-trace/tokio-trace-core/src/span.rs @@ -1,23 +1,41 @@ //! Spans represent periods of time in the execution of a program. -/// Identifies a span within the context of a process. -/// -/// Span IDs are used primarily to determine if two handles refer to the same -/// span, without requiring the comparison of the span's fields. +use {field, Metadata}; + +/// Identifies a span within the context of a subscriber. /// /// They are generated by [`Subscriber`](::Subscriber)s for each span as it is -/// created, through the [`new_id`](::Subscriber::new_span_id) trait +/// created, by the [`new_span`](::Subscriber::new_span) trait /// method. See the documentation for that method for more information on span /// ID generation. #[derive(Clone, Debug, PartialEq, Eq, Hash)] -pub struct Span(u64); +pub struct Id(u64); -// ===== impl Id ===== +/// Attributes provided to a `Subscriber` describing a new span when it is +/// created. +#[derive(Debug)] +pub struct Attributes<'a> { + metadata: &'a Metadata<'a>, + values: &'a field::ValueSet<'a>, + parent: Parent, +} -impl Span { +#[derive(Debug)] +enum Parent { + /// The new span will be a root span. + Root, + /// The new span will be rooted in the current span. + Current, + /// The new span has an explicitly-specified parent. + Explicit(Id), +} + +// ===== impl Span ===== + +impl Id { /// Constructs a new span ID from the given `u64`. pub fn from_u64(u: u64) -> Self { - Span(u) + Id(u) } /// Returns the span's ID as a `u64`. @@ -25,3 +43,85 @@ impl Span { self.0 } } + +// ===== impl Attributes ===== + +impl<'a> Attributes<'a> { + /// Returns `Attributes` describing a new child span of the current span, + /// with the provided metadata and values. + pub fn new(metadata: &'a Metadata<'a>, values: &'a field::ValueSet<'a>) -> Self { + Attributes { + metadata, + values, + parent: Parent::Current, + } + } + + /// Returns `Attributes` describing a new span at the root of its own trace + /// tree, with the provided metadata and values. + pub fn new_root(metadata: &'a Metadata<'a>, values: &'a field::ValueSet<'a>) -> Self { + Attributes { + metadata, + values, + parent: Parent::Root, + } + } + + /// Returns `Attributes` describing a new child span of the specified + /// parent span, with the provided metadata and values. + pub fn child_of( + parent: Id, + metadata: &'a Metadata<'a>, + values: &'a field::ValueSet<'a>, + ) -> Self { + Attributes { + metadata, + values, + parent: Parent::Explicit(parent), + } + } + + /// Returns a reference to the new span's metadata. + pub fn metadata(&self) -> &Metadata<'a> { + self.metadata + } + + /// Returns a reference to a `ValueSet` containing any values the new span + /// was created with. + pub fn values(&self) -> &field::ValueSet<'a> { + self.values + } + + /// Returns true if the new span shoold be a root. + pub fn is_root(&self) -> bool { + match self.parent { + Parent::Root => true, + _ => false, + } + } + + /// Returns true if the new span's parent should be determined based on the + /// current context. + /// + /// If this is true and the current thread is currently inside a span, then + /// that span should be the new span's parent. Otherwise, if the current + /// thread is _not_ inside a span, then the new span will be the root of its + /// own trace tree. + pub fn is_contextual(&self) -> bool { + match self.parent { + Parent::Current => true, + _ => false, + } + } + + /// Returns the new span's explicitly-specified parent, if there is one. + /// + /// Otherwise (if the new span is a root or is a child of the current span), + /// returns false. + pub fn parent(&self) -> Option<&Id> { + match self.parent { + Parent::Explicit(ref p) => Some(p), + _ => None, + } + } +} diff --git a/tokio-trace/tokio-trace-core/src/subscriber.rs b/tokio-trace/tokio-trace-core/src/subscriber.rs index 8d381e6fa..956eca176 100644 --- a/tokio-trace/tokio-trace-core/src/subscriber.rs +++ b/tokio-trace/tokio-trace-core/src/subscriber.rs @@ -1,5 +1,5 @@ //! Subscribers collect and record trace data. -use {field, Event, Metadata, Span}; +use {field, span, Event, Metadata}; /// Trait representing the functions required to collect trace data. /// @@ -106,7 +106,7 @@ pub trait Subscriber { /// [metadata]: ::Metadata fn enabled(&self, metadata: &Metadata) -> bool; - /// Record the construction of a new [`Span`], returning a new ID for the + /// Record the construction of a new span, returning a new [span ID] for the /// span being constructed. /// /// The provided `ValueSet` contains any field values that were provided @@ -122,10 +122,10 @@ pub trait Subscriber { /// return a distinct ID every time this function is called, regardless of /// the metadata. /// - /// [`Span`]: ::span::Span + /// [span ID]: ../span/struct.Id.html /// [recorder]: ::field::Record /// [`record` method]: ::field::ValueSet::record - fn new_span(&self, metadata: &Metadata, values: &field::ValueSet) -> Span; + fn new_span(&self, span: &span::Attributes) -> span::Id; // === Notification methods =============================================== @@ -136,7 +136,7 @@ pub trait Subscriber { /// /// [recorder]: ::field::Record /// [`record` method]: ::field::ValueSet::record - fn record(&self, span: &Span, values: &field::ValueSet); + fn record(&self, span: &span::Id, values: &field::ValueSet); /// Adds an indication that `span` follows from the span with the id /// `follows`. @@ -156,7 +156,7 @@ pub trait Subscriber { /// subscriber knows about, or if a cyclical relationship would be created /// (i.e., some span _a_ which proceeds some other span _b_ may not also /// follow from _b_), it may silently do nothing. - fn record_follows_from(&self, span: &Span, follows: &Span); + fn record_follows_from(&self, span: &span::Id, follows: &span::Id); /// Records that an [`Event`] has occurred. /// @@ -169,29 +169,29 @@ pub trait Subscriber { /// [`record` method]: ::event::Event::record fn event(&self, event: &Event); - /// Records that a [`Span`] has been entered. + /// Records that a spanhas been entered. /// /// When entering a span, this method is called to notify the subscriber - /// that the span has been entered. The subscriber is provided with the ID - /// of the entered span, and should update any internal state tracking the - /// current span accordingly. + /// that the span has been entered. The subscriber is provided with the + /// [span ID] of the entered span, and should update any internal state + /// tracking the current span accordingly. /// - /// [`Span`]: ::span::Span - fn enter(&self, span: &Span); + /// [span ID]: ../span/struct.Id.html + fn enter(&self, span: &span::Id); - /// Records that a [`Span`] has been exited. + /// Records that a span has been exited. /// /// When entering a span, this method is called to notify the subscriber - /// that the span has been exited. The subscriber is provided with the ID - /// of the exited span, and should update any internal state tracking the - /// current span accordingly. + /// that the span has been exited. The subscriber is provided with the + /// [span ID] of the exited span, and should update any internal state + /// tracking the current span accordingly. /// /// Exiting a span does not imply that the span will not be re-entered. /// - /// [`Span`]: ::span::Span - fn exit(&self, span: &Span); + /// [span ID]: ../span/struct.Id.html + fn exit(&self, span: &span::Id); - /// Notifies the subscriber that a [`Span`] has been cloned. + /// Notifies the subscriber that a [span ID] has been cloned. /// /// This function is guaranteed to only be called with span IDs that were /// returned by this subscriber's `new_span` function. @@ -209,20 +209,20 @@ pub trait Subscriber { /// kind this can be used as a hook to "clone" the pointer, depending on /// what that means for the specified pointer. /// - /// [`Span`]: ::span::Span, + /// [span ID]: ../span/struct.Id.html /// [`drop_span`]: ::subscriber::Subscriber::drop_span - fn clone_span(&self, id: &Span) -> Span { + fn clone_span(&self, id: &span::Id) -> span::Id { id.clone() } - /// Notifies the subscriber that a [`Span`] has been dropped. + /// Notifies the subscriber that a [span ID] has been dropped. /// /// This function is guaranteed to only be called with span IDs that were /// returned by this subscriber's `new_span` function. /// /// It's guaranteed that if this function has been called once more than the /// number of times `clone_span` was called with the same `id`, then no more - /// `Span`s using that `id` exist. This means that it can be used in + /// spans using that `id` exist. This means that it can be used in /// conjunction with [`clone_span`] to track the number of handles /// capable of `enter`ing a span. When all the handles have been dropped /// (i.e., `drop_span` has been called one more time than `clone_span` for a @@ -235,9 +235,9 @@ pub trait Subscriber { /// inside of a `drop_span` function may cause a double panic, if the span /// was dropped due to a thread unwinding. /// - /// [`Span`]: ::span::Span, + /// [span ID]: ../span/struct.Id.html /// [`drop_span`]: ::subscriber::Subscriber::drop_span - fn drop_span(&self, id: Span) { + fn drop_span(&self, id: span::Id) { let _ = id; } }