summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorEliza Weisman <eliza@buoyant.io>2019-05-24 15:24:13 -0700
committerGitHub <noreply@github.com>2019-05-24 15:24:13 -0700
commit84d5a7f5a0660dbe1e2be0e831e715f13cb59a2b (patch)
treea7a7d6e37702656e68be718dfd9291bc9b0d97b2
parent1b498e8aa23b53528a5a2d6e6aad2fe41f37ff60 (diff)
trace: Change `Span::enter` to return a guard, add `Span::in_scope` (#1076)
## Motivation Currently, the primary way to use a span is to use `.enter` and pass a closure to be executed under the span. While that is convenient in many settings, it also comes with two decently inconvenient drawbacks: - It breaks control flow statements like `return`, `?`, `break`, and `continue` - It require re-indenting a potentially large chunk of code if you wish it to appear under a span ## Solution This branch changes the `Span::enter` function to return a scope guard that exits the span when dropped, as in: ```rust let guard = span.enter(); // code here is within the span drop(guard); // code here is no longer within the span ``` The method previously called `enter`, which takes a closure and executes it in the span's context, is now called `Span::in_scope`, and was reimplemented on top of the new `enter` method. This is a breaking change to `tokio-trace` that will be part of the upcoming 0.2 release. Closes #1075 Signed-off-by: Eliza Weisman <eliza@buoyant.io>
-rw-r--r--tokio-trace/README.md4
-rw-r--r--tokio-trace/benches/subscriber.rs2
-rw-r--r--tokio-trace/examples/counters.rs4
-rw-r--r--tokio-trace/examples/sloggish/main.rs12
-rw-r--r--tokio-trace/src/lib.rs107
-rw-r--r--tokio-trace/src/macros.rs14
-rw-r--r--tokio-trace/src/span.rs190
-rw-r--r--tokio-trace/test-log-support/tests/log_no_trace.rs2
-rw-r--r--tokio-trace/tests/filter_caching_is_lexically_scoped.rs4
-rw-r--r--tokio-trace/tests/filters_are_not_reevaluated_for_the_same_span.rs8
-rw-r--r--tokio-trace/tests/filters_are_reevaluated_for_different_call_sites.rs10
-rw-r--r--tokio-trace/tests/span.rs60
12 files changed, 285 insertions, 132 deletions
diff --git a/tokio-trace/README.md b/tokio-trace/README.md
index 09c1fb7e..1a94b369 100644
--- a/tokio-trace/README.md
+++ b/tokio-trace/README.md
@@ -56,7 +56,7 @@ to indicate that some code takes place within the context of that `Span`:
```rust
// Construct a new span named "my span".
let mut span = span!("my span");
-span.enter(|| {
+span.in_scope(|| {
// Any trace events in this closure or code called by it will occur within
// the span.
});
@@ -88,7 +88,7 @@ use tokio_trace::field;
pub fn shave_the_yak(yak: &mut Yak) {
// Create a new span for this invocation of `shave_the_yak`, annotated
// with the yak being shaved as a *field* on the span.
- span!("shave_the_yak", yak = field::debug(&yak)).enter(|| {
+ span!("shave_the_yak", yak = field::debug(&yak)).in_scope(|| {
// Since the span is annotated with the yak, it is part of the context
// for everything happening inside the span. Therefore, we don't need
// to add it to the message for this event, as the `log` crate does.
diff --git a/tokio-trace/benches/subscriber.rs b/tokio-trace/benches/subscriber.rs
index 7f2a32f5..c342a84d 100644
--- a/tokio-trace/benches/subscriber.rs
+++ b/tokio-trace/benches/subscriber.rs
@@ -107,7 +107,7 @@ fn span_no_fields(b: &mut Bencher) {
fn enter_span(b: &mut Bencher) {
tokio_trace::subscriber::with_default(EnabledSubscriber, || {
let span = span!(Level::TRACE, "span");
- b.iter(|| test::black_box(span.enter(|| {})))
+ b.iter(|| test::black_box(span.in_scope(|| {})))
});
}
diff --git a/tokio-trace/examples/counters.rs b/tokio-trace/examples/counters.rs
index 4c5b3583..dad02bb8 100644
--- a/tokio-trace/examples/counters.rs
+++ b/tokio-trace/examples/counters.rs
@@ -125,7 +125,7 @@ fn main() {
tokio_trace::subscriber::with_default(subscriber, || {
let mut foo: u64 = 2;
- span!(Level::TRACE, "my_great_span", foo_count = &foo).enter(|| {
+ span!(Level::TRACE, "my_great_span", foo_count = &foo).in_scope(|| {
foo += 1;
info!({ yak_shaved = true, yak_count = 1 }, "hi from inside my span");
span!(
@@ -134,7 +134,7 @@ fn main() {
foo_count = &foo,
baz_count = 5
)
- .enter(|| {
+ .in_scope(|| {
warn!({ yak_shaved = false, yak_count = -1 }, "failed to shave yak");
});
});
diff --git a/tokio-trace/examples/sloggish/main.rs b/tokio-trace/examples/sloggish/main.rs
index 4aa7cf18..00c465d6 100644
--- a/tokio-trace/examples/sloggish/main.rs
+++ b/tokio-trace/examples/sloggish/main.rs
@@ -22,25 +22,25 @@ fn main() {
let subscriber = SloggishSubscriber::new(2);
tokio_trace::subscriber::with_default(subscriber, || {
- span!(Level::TRACE, "", version = &field::display(5.0)).enter(|| {
- span!(Level::TRACE, "server", host = "localhost", port = 8080).enter(|| {
+ span!(Level::TRACE, "", version = &field::display(5.0)).in_scope(|| {
+ span!(Level::TRACE, "server", host = "localhost", port = 8080).in_scope(|| {
info!("starting");
info!("listening");
let peer1 = span!(Level::TRACE, "conn", peer_addr = "82.9.9.9", port = 42381);
- peer1.enter(|| {
+ peer1.in_scope(|| {
debug!("connected");
debug!({ length = 2 }, "message received");
});
let peer2 = span!(Level::TRACE, "conn", peer_addr = "8.8.8.8", port = 18230);
- peer2.enter(|| {
+ peer2.in_scope(|| {
debug!("connected");
});
- peer1.enter(|| {
+ peer1.in_scope(|| {
warn!({ algo = "xor" }, "weak encryption requested");
debug!({ length = 8 }, "response sent");
debug!("disconnected");
});
- peer2.enter(|| {
+ peer2.in_scope(|| {
debug!({ length = 5 }, "message received");
debug!({ length = 8 }, "response sent");
debug!("disconnected");
diff --git a/tokio-trace/src/lib.rs b/tokio-trace/src/lib.rs
index 62c77ab9..08d594c5 100644
--- a/tokio-trace/src/lib.rs
+++ b/tokio-trace/src/lib.rs
@@ -43,8 +43,22 @@
//! use tokio_trace::Level;
//!
//! # fn main() {
-//! span!(Level::TRACE, "my_span").enter(|| {
-//! // perform some work in the context of `my_span`...
+//! let span = span!(Level::TRACE, "my_span");
+//! let _enter = span.enter();
+//! // perform some work in the context of `my_span`...
+//! # }
+//!```
+//!
+//! The [`in_scope`] method may be used to execute a closure inside a
+//! span:
+//!
+//! ```
+//! # #[macro_use] extern crate tokio_trace;
+//! # use tokio_trace::Level;
+//! # fn main() {
+//! # let span = span!(Level::TRACE, "my_span");
+//! span.in_scope(|| {
+//! // perform some more work in the context of `my_span`...
//! });
//! # }
//!```
@@ -61,13 +75,13 @@
//! # use tokio_trace::Level;
//! # fn main() {
//! // this span is considered the "root" of a new trace tree:
-//! span!(Level::INFO, "root").enter(|| {
+//! span!(Level::INFO, "root").in_scope(|| {
//! // since we are now inside "root", this span is considered a child
//! // of "root":
-//! span!(Level::DEBUG, "outer_child").enter(|| {
+//! span!(Level::DEBUG, "outer_child").in_scope(|| {
//! // this span is a child of "outer_child", which is in turn a
//! // child of "root":
-//! span!(Level::TRACE, "inner_child").enter(|| {
+//! span!(Level::TRACE, "inner_child").in_scope(|| {
//! // and so on...
//! });
//! });
@@ -143,12 +157,12 @@
//! # use tokio_trace::Level;
//! # fn main() {
//! # let n = 1;
-//! span!(Level::TRACE, "my loop").enter(|| {
-//! for i in 0..n {
-//! # let _ = i;
-//! // ...
-//! }
-//! })
+//! let span = span!(Level::TRACE, "my_loop");
+//! let _enter = span.enter();
+//! for i in 0..n {
+//! # let _ = i;
+//! // ...
+//! }
//! # }
//! ```
//! Or, should we create a new span for each iteration of the loop, as in:
@@ -158,10 +172,9 @@
//! # fn main() {
//! # let n = 1u64;
//! for i in 0..n {
-//! # let _ = i;
-//! span!(Level::TRACE, "my loop", iteration = i).enter(|| {
-//! // ...
-//! })
+//! let span = span!(Level::TRACE, "my_loop", iteration = i);
+//! let _enter = span.enter();
+//! // ...
//! }
//! # }
//! ```
@@ -189,7 +202,7 @@
//! // records an event outside of any span context:
//! event!(Level::INFO, "something happened");
//!
-//! span!(Level::INFO, "my_span").enter(|| {
+//! span!(Level::INFO, "my_span").in_scope(|| {
//! // records an event within "my_span".
//! event!(Level::DEBUG, "something happened inside my_span");
//! });
@@ -257,11 +270,14 @@
//! # fn main() {
//! // Construct a new span named "my span" with trace log level.
//! let span = span!(Level::TRACE, "my span");
-//! span.enter(|| {
-//! // Any trace events in this closure or code called by it will occur within
-//! // the span.
-//! });
-//! // Dropping the span will close it, indicating that it has ended.
+//!
+//! // Enter the span, returning a guard object.
+//! let _enter = span.enter();
+//!
+//! // Any trace events that occur before the guard is dropped will occur
+//! // within the span.
+//!
+//! // Dropping the guard will exit the span.
//! # }
//! ```
//!
@@ -295,32 +311,30 @@
//! # fn find_a_razor() -> Result<u32, u32> { Ok(1) }
//! # fn main() {
//! pub fn shave_the_yak(yak: &mut Yak) {
-//! // Create a new span for this invocation of `shave_the_yak`, annotated
-//! // with the yak being shaved as a *field* on the span.
-//! span!(Level::TRACE, "shave_the_yak", yak = ?yak).enter(|| {
-//! // Since the span is annotated with the yak, it is part of the context
-//! // for everything happening inside the span. Therefore, we don't need
-//! // to add it to the message for this event, as the `log` crate does.
-//! info!(target: "yak_events", "Commencing yak shaving");
-//!
-//! loop {
-//! match find_a_razor() {
-//! Ok(razor) => {
-//! // We can add the razor as a field rather than formatting it
-//! // as part of the message, allowing subscribers to consume it
-//! // in a more structured manner:
-//! info!({ razor = %razor }, "Razor located");
-//! yak.shave(razor);
-//! break;
-//! }
-//! Err(err) => {
-//! // However, we can also create events with formatted messages,
-//! // just as we would for log records.
-//! warn!("Unable to locate a razor: {}, retrying", err);
-//! }
+//! let span = span!(Level::TRACE, "shave_the_yak", yak = ?yak);
+//! let _enter = span.enter();
+//!
+//! // Since the span is annotated with the yak, it is part of the context
+//! // for everything happening inside the span. Therefore, we don't need
+//! // to add it to the message for this event, as the `log` crate does.
+//! info!(target: "yak_events", "Commencing yak shaving");
+//! loop {
+//! match find_a_razor() {
+//! Ok(razor) => {
+//! // We can add the razor as a field rather than formatting it
+//! // as part of the message, allowing subscribers to consume it
+//! // in a more structured manner:
+//! info!({ razor = %razor }, "Razor located");
+//! yak.shave(razor);
+//! break;
+//! }
+//! Err(err) => {
+//! // However, we can also create events with formatted messages,
+//! // just as we would for log records.
+//! warn!("Unable to locate a razor: {}, retrying", err);
//! }
//! }
-//! })
+//! }
//! }
//! # }
//! ```
@@ -414,7 +428,8 @@
//! ```
//!
//! [`log`]: https://docs.rs/log/0.4.6/log/
-//! [`Span`]: span/struct.Span
+//! [`Span`]: span/struct.Span.html
+//! [`in_scope`]: span/struct.Span.html#method.in_scope
//! [`Event`]: struct.Event.html
//! [`Subscriber`]: subscriber/trait.Subscriber.html
//! [`observe_event`]: subscriber/trait.Subscriber.html#tymethod.observe_event
diff --git a/tokio-trace/src/macros.rs b/tokio-trace/src/macros.rs
index 7a44038b..6311a831 100644
--- a/tokio-trace/src/macros.rs
+++ b/tokio-trace/src/macros.rs
@@ -9,7 +9,7 @@
/// # use tokio_trace::Level;
/// # fn main() {
/// let span = span!(Level::TRACE, "my span");
-/// span.enter(|| {
+/// span.in_scope(|| {
/// // do work inside the span...
/// });
/// # }
@@ -21,7 +21,7 @@
/// # extern crate tokio_trace;
/// # use tokio_trace::Level;
/// # fn main() {
-/// span!(Level::TRACE, "my span", foo = 2, bar = "a string").enter(|| {
+/// span!(Level::TRACE, "my span", foo = 2, bar = "a string").in_scope(|| {
/// // do work inside the span...
/// });
/// # }
@@ -240,7 +240,7 @@ macro_rules! span {
/// # extern crate tokio_trace;
/// # fn main() {
/// let span = trace_span!("my span");
-/// span.enter(|| {
+/// span.in_scope(|| {
/// // do work inside the span...
/// });
/// # }
@@ -301,7 +301,7 @@ macro_rules! trace_span {
/// # extern crate tokio_trace;
/// # fn main() {
/// let span = debug_span!("my span");
-/// span.enter(|| {
+/// span.in_scope(|| {
/// // do work inside the span...
/// });
/// # }
@@ -362,7 +362,7 @@ macro_rules! debug_span {
/// # extern crate tokio_trace;
/// # fn main() {
/// let span = info_span!("my span");
-/// span.enter(|| {
+/// span.in_scope(|| {
/// // do work inside the span...
/// });
/// # }
@@ -423,7 +423,7 @@ macro_rules! info_span {
/// # extern crate tokio_trace;
/// # fn main() {
/// let span = warn_span!("my span");
-/// span.enter(|| {
+/// span.in_scope(|| {
/// // do work inside the span...
/// });
/// # }
@@ -483,7 +483,7 @@ macro_rules! warn_span {
/// # extern crate tokio_trace;
/// # fn main() {
/// let span = error_span!("my span");
-/// span.enter(|| {
+/// span.in_scope(|| {
/// // do work inside the span...
/// });
/// # }
diff --git a/tokio-trace/src/span.rs b/tokio-trace/src/span.rs
index dfdaa5ec..4c4cb9f5 100644
--- a/tokio-trace/src/span.rs
+++ b/tokio-trace/src/span.rs
@@ -4,12 +4,10 @@
//!
//! A thread of execution is said to _enter_ a span when it begins executing,
//! and _exit_ the span when it switches to another context. Spans may be
-//! entered through the [`enter`] method, which enters the target span,
-//! performs a given function (either a closure or a function pointer), exits
-//! the span, and then returns the result.
+//! entered through the [`enter`] and [`in_scope`] methods.
//!
-//! Calling `enter` on a span handle enters the span that handle corresponds to,
-//! if the span exists:
+//! The `enter` method enters a span, returning a [guard] that exits the span
+//! when dropped
//! ```
//! # #[macro_use] extern crate tokio_trace;
//! # use tokio_trace::Level;
@@ -17,18 +15,36 @@
//! let my_var: u64 = 5;
//! let my_span = span!(Level::TRACE, "my_span", my_var = &my_var);
//!
-//! my_span.enter(|| {
+//! // `my_span` exists but has not been entered.
+//!
+//! let _enter = my_span.enter();
+//!
+//! // Perform some work inside of the context of `my_span`...
+//! # }
+//!```
+//!
+//! `in_scope` takes a closure or function pointer and executes it inside the
+//! span.
+//! ```
+//! # #[macro_use] extern crate tokio_trace;
+//! # use tokio_trace::Level;
+//! # fn main() {
+//! let my_var: u64 = 5;
+//! let my_span = span!(Level::TRACE, "my_span", my_var = &my_var);
+//!
+//! my_span.in_scope(|| {
//! // perform some work in the context of `my_span`...
//! });
//!
//! // Perform some work outside of the context of `my_span`...
//!
-//! my_span.enter(|| {
+//! my_span.in_scope(|| {
//! // Perform some more work in the context of `my_span`.
//! });
//! # }
//! ```
//!
+//!
//! # The Span Lifecycle
//!
//! Execution may enter and exit a span multiple times before that
@@ -48,7 +64,7 @@
//! type Error = ();
//!
//! fn poll(&mut self) -> Poll<Self::Item, Self::Error> {
-//! self.span.enter(|| {
+//! self.span.in_scope(|| {
//! // Do actual future work
//! # Ok(Async::Ready(()))
//! })
@@ -81,7 +97,7 @@
//! # use tokio_trace::Level;
//! # fn main() {
//! {
-//! span!(Level::TRACE, "my_span").enter(|| {
+//! span!(Level::TRACE, "my_span").in_scope(|| {
//! // perform some work in the context of `my_span`...
//! }); // --> Subscriber::exit(my_span)
//!
@@ -116,6 +132,8 @@
//! [`Subscriber`]: ../subscriber/trait.Subscriber.html
//! [`Attributes`]: struct.Attributes.html
//! [`enter`]: struct.Span.html#method.enter
+//! [`in_scope`]: struct.Span.html#method.in_scope
+//! [`guard`]: struct.Entered.html
pub use tokio_trace_core::span::{Attributes, Id, Record};
use std::{
@@ -166,15 +184,15 @@ pub(crate) struct Inner {
/// A guard representing a span which has been entered and is currently
/// executing.
///
-/// This guard may be used to exit the span, returning an `Enter` to
-/// re-enter it.
+/// When the guard is dropped, the span will be exited.
+///
+/// This is returned by the [`Span::enter`] function.
///
-/// This type is primarily used for implementing span handles; users should
-/// typically not need to interact with it directly.
+/// [`Span::enter`]: ../struct.Span.html#method.enter
#[derive(Debug)]
#[must_use = "once a span has been entered, it should be exited"]
-struct Entered<'a> {
- inner: &'a Inner,
+pub struct Entered<'a> {
+ span: &'a Span,
}
// ===== impl Span =====
@@ -254,20 +272,131 @@ impl Span {
span
}
+ /// Enters this span, returning a guard that will exit the span when dropped.
+ ///
+ /// If this span is enabled by the current subscriber, then this function will
+ /// call [`Subscriber::enter`] with the span's [`Id`], and dropping the guard
+ /// will call [`Subscriber::exit`]. If the span is disabled, this does nothing.
+ ///
+ /// # Examples
+ ///
+ /// ```
+ /// #[macro_use] extern crate tokio_trace;
+ /// # use tokio_trace::Level;
+ /// # fn main() {
+ /// let span = span!(Level::INFO, "my_span");
+ /// let guard = span.enter();
+ ///
+ /// // code here is within the span
+ ///
+ /// drop(guard);
+ ///
+ /// // code here is no longer within the span
+ ///
+ /// # }
+ /// ```
+ ///
+ /// Guards need not be explicitly dropped:
+ ///
+ /// ```
+ /// #[macro_use] extern crate tokio_trace;
+ /// # fn main() {
+ /// fn my_function() -> String {
+ /// // enter a span for the duration of this function.
+ /// let span = trace_span!("my_function");
+ /// let _enter = span.enter();
+ ///
+ /// // anything happening in functions we call is still inside the span...
+ /// my_other_function();
+ ///
+ /// // returning from the function drops the guard, exiting the span.
+ /// return "Hello world".to_owned();
+ /// }
+ ///
+ /// fn my_other_function() {
+ /// // ...
+ /// }
+ /// # }
+ /// ```
+ ///
+ /// Sub-scopes may be created to limit the duration for which the span is
+ /// entered:
+ ///
+ /// ```
+ /// #[macro_use] extern crate tokio_trace;
+ /// # fn main() {
+ /// let span = info_span!("my_great_span");
+ ///
+ /// {
+ /// let _enter = span.enter();
+ ///
+ /// // this event occurs inside the span.
+ /// info!("i'm in the span!");
+ ///
+ /// // exiting the scope drops the guard, exiting the span.
+ /// }
+ ///
+ /// // this event is not inside the span.
+ /// info!("i'm outside the span!")
+ /// # }
+ /// ```
+ ///
+ /// [`Subscriber::enter`]: ../subscriber/trait.Subscriber.html#method.enter
+ /// [`Subscriber::exit`]: ../subscriber/trait.Subscriber.html#method.exit
+ /// [`Id`]: ../struct.Id.html
+ pub fn enter<'a>(&'a self) -> Entered<'a> {
+ if let Some(ref inner) = self.inner.as_ref() {
+ inner.subscriber.enter(&inner.id);
+ }
+ self.log(format_args!("-> {}", self.meta.name));
+ Entered { span: self }
+ }
+
/// Executes the given function in the context of this span.
///
- /// If this span is enabled, then this function enters the span, invokes
+ /// If this span is enabled, then this function enters the span, invokes `f`
/// and then exits the span. If the span is disabled, `f` will still be
/// invoked, but in the context of the currently-executing span (if there is
/// one).
///
/// Returns the result of evaluating `f`.
- pub fn enter<F: FnOnce() -> T, T>(&self, f: F) -> T {
- self.log(format_args!("-> {}", self.meta.name));
- let _enter = self.inner.as_ref().map(Inner::enter);
- let result = f();
- self.log(format_args!("<- {}", self.meta.name));
- result
+ ///
+ /// # Examples
+ ///
+ /// ```
+ /// # #[macro_use] extern crate tokio_trace;
+ /// # use tokio_trace::Level;
+ /// # fn main() {
+ /// let my_span = span!(Level::TRACE, "my_span");
+ ///
+ /// my_span.in_scope(|| {
+ /// // this event occurs within the span.
+ /// trace!("i'm in the span!");
+ /// });
+ ///
+ /// // this event occurs outside the span.
+ /// trace!("i'm not in the span!");
+ /// # }
+ /// ```
+ ///
+ /// Calling a function and returning the result:
+ /// ```
+ /// # #[macro_use] extern crate tokio_trace;
+ /// # use tokio_trace::Level;
+ /// fn hello_world() -> String {
+ /// "Hello world!".to_owned()
+ /// }
+ ///
+ /// # fn main() {
+ /// let span = info_span!("hello_world");
+ /// // the span will be entered for the duration of the call to
+ /// // `hello_world`.
+ /// let a_string = span.in_scope(hello_world);
+ /// # }
+ ///
+ pub fn in_scope<F: FnOnce() -> T, T>(&self, f: F) -> T {
+ let _enter = self.enter();
+ f()
}
/// Returns a [`Field`](../field/struct.Field.html) for the field with the
@@ -435,18 +564,6 @@ impl fmt::Debug for Span {
// ===== impl Inner =====
impl Inner {
- /// Enters the span, returning a guard that may be used to exit the span and
- /// re-enter the prior span.
- ///
- /// This is used internally to implement `Span::enter`. It may be used for
- /// writing custom span handles, but should generally not be called directly
- /// when entering a span.
- #[inline]
- fn enter(&self) -> Entered {
- self.subscriber.enter(&self.id);
- Entered { inner: self }
- }
-
/// Indicates that the span with the given ID has an indirect causal
/// relationship with this span.
///
@@ -519,7 +636,10 @@ impl<'a> Drop for Entered<'a> {
//
// Running this behaviour on drop rather than with an explicit function
// call means that spans may still be exited when unwinding.
- self.inner.subscriber.exit(&self.inner.id);
+ if let Some(inner) = self.span.inner.as_ref() {
+ inner.subscriber.exit(&inner.id);
+ }
+ self.span.log(format_args!("<- {}", self.span.meta.name));
}
}
diff --git a/tokio-trace/test-log-support/tests/log_no_trace.rs b/tokio-trace/test-log-support/tests/log_no_trace.rs
index 2c3b7f1d..93cf9ab6 100644
--- a/tokio-trace/test-log-support/tests/log_no_trace.rs
+++ b/tokio-trace/test-log-support/tests/log_no_trace.rs
@@ -44,7 +44,7 @@ fn test_always_log() {
let mut foo = span!(Level::TRACE, "foo");
last(&a, "foo;");
- foo.enter(|| {
+ foo.in_scope(|| {
last(&a, "-> foo");
trace!({foo = 3, bar = 4}, "hello {};", "san francisco");
diff --git a/tokio-trace/tests/filter_caching_is_lexically_scoped.rs b/tokio-trace/tests/filter_caching_is_lexically_scoped.rs
index d66e7d4f..72c07299 100644
--- a/tokio-trace/tests/filter_caching_is_lexically_scoped.rs
+++ b/tokio-trace/tests/filter_caching_is_lexically_scoped.rs
@@ -20,11 +20,11 @@ use std::sync::{
#[test]
fn filter_caching_is_lexically_scoped() {
pub fn my_great_function() -> bool {
- span!(Level::TRACE, "emily").enter(|| true)
+ span!(Level::TRACE, "emily").in_scope(|| true)
}
pub fn my_other_function() -> bool {
- span!(Level::TRACE, "frank").enter(|| true)
+ span!(Level::TRACE, "frank").in_scope(|| true)
}
let count = Arc::new(AtomicUsize::new(0));
diff --git a/tokio-trace/tests/filters_are_not_reevaluated_for_the_same_span.rs b/tokio-trace/tests/filters_are_not_reevaluated_for_the_same_span.rs
index c96fe35a..3feb766f 100644
--- a/tokio-trace/tests/filters_are_not_reevaluated_for_the_same_span.rs
+++ b/tokio-trace/tests/filters_are_not_reevaluated_for_the_same_span.rs
@@ -44,9 +44,9 @@ fn filters_are_not_reevaluated_for_the_same_span() {
// Enter "alice" and then "bob". The dispatcher expects to see "bob" but
// not "alice."
let alice = span!(Level::TRACE, "alice");
- let bob = alice.enter(|| {
+ let bob = alice.in_scope(|| {
let bob = span!(Level::TRACE, "bob");
- bob.enter(|| ());
+ bob.in_scope(|| ());
bob
});
@@ -54,14 +54,14 @@ fn filters_are_not_reevaluated_for_the_same_span() {
assert_eq!(alice_count.load(Ordering::Relaxed), 1);
assert_eq!(bob_count.load(Ordering::Relaxed), 1);
- alice.enter(|| bob.enter(|| {}));
+ alice.in_scope(|| bob.in_scope(|| {}));
// The subscriber should see "bob" again, but the filter should not have
// been called.
assert_eq!(alice_count.load(Ordering::Relaxed), 1);
assert_eq!(bob_count.load(Ordering::Relaxed), 1);
- bob.enter(|| {});
+ bob.in_scope(|| {});
assert_eq!(alice_count.load(Ordering::Relaxed), 1);
assert_eq!(bob_count.load(Ordering::Relaxed), 1);
});
diff --git a/tokio-trace/tests/filters_are_reevaluated_for_different_call_sites.rs b/tokio-trace/tests/filters_are_reevaluated_for_different_call_sites.rs
index 3a0fa186..a773354f 100644
--- a/tokio-trace/tests/filters_are_reevaluated_for_different_call_sites.rs
+++ b/tokio-trace/tests/filters_are_reevaluated_for_different_call_sites.rs
@@ -47,9 +47,9 @@ fn filters_are_reevaluated_for_different_call_sites() {
// Enter "charlie" and then "dave". The dispatcher expects to see "dave" but
// not "charlie."
let charlie = span!(Level::TRACE, "charlie");
- let dave = charlie.enter(|| {
+ let dave = charlie.in_scope(|| {
let dave = span!(Level::TRACE, "dave");
- dave.enter(|| {});
+ dave.in_scope(|| {});
dave
});
@@ -57,7 +57,7 @@ fn filters_are_reevaluated_for_different_call_sites() {
assert_eq!(charlie_count.load(Ordering::Relaxed), 1);
assert_eq!(dave_count.load(Ordering::Relaxed), 1);
- charlie.enter(|| dave.enter(|| {}));
+ charlie.in_scope(|| dave.in_scope(|| {}));
// The subscriber should see "dave" again, but the filter should not have
// been called.
@@ -67,13 +67,13 @@ fn filters_are_reevaluated_for_different_call_sites() {
// A different span with the same name has a different call site, so it
// should cause the filter to be reapplied.
let charlie2 = span!(Level::TRACE, "charlie");
- charlie.enter(|| {});
+ charlie.in_scope(|| {});
assert_eq!(charlie_count.load(Ordering::Relaxed), 2);
assert_eq!(dave_count.load(Ordering::Relaxed), 1);
// But, the filter should not be re-evaluated for the new "charlie" span
// when it is re-entered.
- charlie2.enter(|| span!(Level::TRACE, "dave").enter(|| {}));
+ charlie2.in_scope(|| span!(Level::TRACE, "dave").in_scope(|| {}));
assert_eq!(charlie_count.load(Ordering::Relaxed), 2);
assert_eq!(dave_count.load(Ordering::Relaxed), 2);
});
diff --git a/tokio-trace/tests/span.rs b/tokio-trace/tests/span.rs
index 5c3bdd61..aedba833 100644
--- a/tokio-trace/tests/span.rs
+++ b/tokio-trace/tests/span.rs
@@ -67,12 +67,12 @@ fn spans_always_go_to_the_subscriber_that_tagged_them() {
let foo = with_default(subscriber1, || {
let foo = span!(Level::TRACE, "foo");
- foo.enter(|| {});
+ foo.in_scope(|| {});
foo
});
// Even though we enter subscriber 2's context, the subscriber that
// tagged the span should see the enter/exit.
- with_default(subscriber2, move || foo.enter(|| {}));
+ with_default(subscriber2, move || foo.in_scope(|| {}));
}
#[test]
@@ -87,7 +87,7 @@ fn spans_always_go_to_the_subscriber_that_tagged_them_even_across_threads() {
.run();
let foo = with_default(subscriber1, || {
let foo = span!(Level::TRACE, "foo");
- foo.enter(|| {});
+ foo.in_scope(|| {});
foo
});
@@ -95,7 +95,7 @@ fn spans_always_go_to_the_subscriber_that_tagged_them_even_across_threads() {
// tagged the span should see the enter/exit.
thread::spawn(move || {
with_default(subscriber::mock().run(), || {
- foo.enter(|| {});
+ foo.in_scope(|| {});
})
})
.join()
@@ -112,7 +112,7 @@ fn dropping_a_span_calls_drop_span() {
.run_with_handle();
with_default(subscriber, || {
let span = span!(Level::TRACE, "foo");
- span.enter(|| {});
+ span.in_scope(|| {});
drop(span);
});
@@ -129,7 +129,7 @@ fn span_closes_after_event() {
.done()
.run_with_handle();
with_default(subscriber, || {
- span!(Level::TRACE, "foo").enter(|| {
+ span!(Level::TRACE, "foo").in_scope(|| {
event!(Level::DEBUG, {}, "my event!");
});
});
@@ -150,10 +150,10 @@ fn new_span_after_event() {
.done()
.run_with_handle();
with_default(subscriber, || {
- span!(Level::TRACE, "foo").enter(|| {
+ span!(Level::TRACE, "foo").in_scope(|| {
event!(Level::DEBUG, {}, "my event!");
});
- span!(Level::TRACE, "bar").enter(|| {});
+ span!(Level::TRACE, "bar").in_scope(|| {});
});
handle.assert_finished();
@@ -170,7 +170,7 @@ fn event_outside_of_span() {
.run_with_handle();
with_default(subscriber, || {
debug!("my event!");
- span!(Level::TRACE, "foo").enter(|| {});
+ span!(Level::TRACE, "foo").in_scope(|| {});
});
handle.assert_finished();
@@ -220,14 +220,14 @@ fn clone_and_drop_span_always_go_to_the_subscriber_that_tagged_the_span() {
let foo = with_default(subscriber1, || {
let foo = span!(Level::TRACE, "foo");
- foo.enter(|| {});
+ foo.in_scope(|| {});
foo
});
// Even though we enter subscriber 2's context, the subscriber that
// tagged the span should see the enter/exit.
with_default(subscriber2, move || {
let foo2 = foo.clone();
- foo.enter(|| {});
+ foo.in_scope(|| {});
drop(foo);
drop(foo2);
});
@@ -246,7 +246,7 @@ fn span_closes_when_exited() {
with_default(subscriber, || {
let foo = span!(Level::TRACE, "foo");
- foo.enter(|| {});
+ foo.in_scope(|| {});
drop(foo);
});
@@ -255,6 +255,24 @@ fn span_closes_when_exited() {
}
#[test]
+fn enter() {
+ let (subscriber, handle) = subscriber::mock()
+ .enter(span::mock().named("foo"))
+ .event(event::mock())
+ .exit(span::mock().named("foo"))
+ .drop_span(span::mock().named("foo"))
+ .done()
+ .run_with_handle();
+ with_default(subscriber, || {
+ let foo = span!(Level::TRACE, "foo");
+ let _enter = foo.enter();
+ debug!("dropping guard...");
+ });
+
+ handle.assert_finished();
+}
+
+#[test]
fn moved_field() {
let (subscriber, handle) = subscriber::mock()
.new_span(
@@ -276,7 +294,7 @@ fn moved_field() {
"foo",
bar = display(format!("hello from {}", from))
);
- span.enter(|| {});
+ span.in_scope(|| {});
});
handle.assert_finished();
@@ -319,7 +337,7 @@ fn borrowed_field() {
let from = "my span";
let mut message = format!("hello from {}", from);
let span = span!(Level::TRACE, "foo", bar = display(&message));
- span.enter(|| {
+ span.in_scope(|| {
message.insert_str(10, " inside");
});
});
@@ -366,8 +384,8 @@ fn move_field_out_of_struct() {
};
let foo = span!(Level::TRACE, "foo", x = debug(pos.x), y = debug(pos.y));
let bar = span!(Level::TRACE, "bar", position = debug(pos));
- foo.enter(|| {});
- bar.enter(|| {});
+ foo.in_scope(|| {});
+ bar.in_scope(|| {});
});
handle.assert_finished();
@@ -394,7 +412,7 @@ fn add_field_after_new_span() {
with_default(subscriber, || {
let span = span!(Level::TRACE, "foo", bar = 5, baz);
span.record("baz", &true);
- span.enter(|| {})
+ span.in_scope(|| {})
});
handle.assert_finished();
@@ -422,7 +440,7 @@ fn add_fields_only_after_new_span() {
let span = span!(Level::TRACE, "foo", bar, baz);
span.record("bar", &5);
span.record("baz", &true);
- span.enter(|| {})
+ span.in_scope(|| {})
});