tracing, tracing-futures: instrument Future inside Drop (#2562)

## Motivation Currently it is not possible to disable ANSI in `fmt::Subscriber` without enabling the "ansi" crate feature. This makes it difficult for users to implement interoperable settings that are controllable with crate features without having to pull in the dependencies "ansi" does. I hit this while writing an application with multiple logging options set during compile-time and I wanted to cut down on dependencies if possible. ## Solution This changes `fmt::Subscriber::with_ansi()` to not require the "ansi" feature flag. This way, `with_ansi(false)` can be called even when the "ansi" feature is disabled. Calling `with_ansi(true)` when the "ansi" feature is not enabled will panic in debug mode, or print a warning if debug assertions are disabled. Co-authored-by: daxpedda <[email protected]> Co-authored-by: Eliza Weisman <[email protected]>
tokio-rs · Apr 21, 2023 · 3a65354 · 3a65354
1 parent 29d85b1
commit 3a65354
Show file tree

Hide file tree

Showing 11 changed files with 360 additions and 65 deletions.
diff --git a/tracing-attributes/tests/async_fn.rs b/tracing-attributes/tests/async_fn.rs
@@ -90,6 +90,8 @@ fn async_fn_only_enters_for_polls() {
         .exit(span::mock().named("test_async_fn"))
         .enter(span::mock().named("test_async_fn"))
         .exit(span::mock().named("test_async_fn"))
+        .enter(span::mock().named("test_async_fn"))
+        .exit(span::mock().named("test_async_fn"))
         .drop_span(span::mock().named("test_async_fn"))
         .done()
         .run_with_handle();
@@ -120,8 +122,12 @@ fn async_fn_nested() {
         .enter(span2.clone())
         .event(event::mock().with_fields(field::mock("nested").with_value(&true)))
         .exit(span2.clone())
+        .enter(span2.clone())
+        .exit(span2.clone())
         .drop_span(span2)
         .exit(span.clone())
+        .enter(span.clone())
+        .exit(span.clone())
         .drop_span(span)
         .done()
         .run_with_handle();
@@ -199,13 +205,19 @@ fn async_fn_with_async_trait() {
         .enter(span3.clone())
         .event(event::mock().with_fields(field::mock("val").with_value(&2u64)))
         .exit(span3.clone())
+        .enter(span3.clone())
+        .exit(span3.clone())
         .drop_span(span3)
         .new_span(span2.clone().with_field(field::mock("self")))
         .enter(span2.clone())
         .event(event::mock().with_fields(field::mock("val").with_value(&5u64)))
         .exit(span2.clone())
+        .enter(span2.clone())
+        .exit(span2.clone())
         .drop_span(span2)
         .exit(span.clone())
+        .enter(span.clone())
+        .exit(span.clone())
         .drop_span(span)
         .done()
         .run_with_handle();
@@ -256,6 +268,8 @@ fn async_fn_with_async_trait_and_fields_expressions() {
         )
         .enter(span.clone())
         .exit(span.clone())
+        .enter(span.clone())
+        .exit(span.clone())
         .drop_span(span)
         .done()
         .run_with_handle();
@@ -331,8 +345,12 @@ fn async_fn_with_async_trait_and_fields_expressions_with_generic_parameter() {
                 .with_field(field::mock("Self").with_value(&std::any::type_name::<TestImpl>())),
         )
         .enter(span4.clone())
+        .exit(span4.clone())
+        .enter(span4.clone())
         .exit(span4)
         .exit(span2.clone())
+        .enter(span2.clone())
+        .exit(span2.clone())
         .drop_span(span2)
         .new_span(
             span3
@@ -341,6 +359,8 @@ fn async_fn_with_async_trait_and_fields_expressions_with_generic_parameter() {
         )
         .enter(span3.clone())
         .exit(span3.clone())
+        .enter(span3.clone())
+        .exit(span3.clone())
         .drop_span(span3)
         .done()
         .run_with_handle();
@@ -382,6 +402,8 @@ fn out_of_scope_fields() {
         .new_span(span.clone())
         .enter(span.clone())
         .exit(span.clone())
+        .enter(span.clone())
+        .exit(span.clone())
         .drop_span(span)
         .done()
         .run_with_handle();
@@ -417,6 +439,8 @@ fn manual_impl_future() {
         .enter(span.clone())
         .event(poll_event())
         .exit(span.clone())
+        .enter(span.clone())
+        .exit(span.clone())
         .drop_span(span)
         .done()
         .run_with_handle();
@@ -448,6 +472,8 @@ fn manual_box_pin() {
         .enter(span.clone())
         .event(poll_event())
         .exit(span.clone())
+        .enter(span.clone())
+        .exit(span.clone())
         .drop_span(span)
         .done()
         .run_with_handle();

diff --git a/tracing-attributes/tests/err.rs b/tracing-attributes/tests/err.rs
@@ -57,6 +57,8 @@ fn test_async() {
         .enter(span.clone())
         .event(event::mock().at_level(Level::ERROR))
         .exit(span.clone())
+        .enter(span.clone())
+        .exit(span.clone())
         .drop_span(span)
         .done()
         .run_with_handle();
@@ -111,6 +113,8 @@ fn test_mut_async() {
         .enter(span.clone())
         .event(event::mock().at_level(Level::ERROR))
         .exit(span.clone())
+        .enter(span.clone())
+        .exit(span.clone())
         .drop_span(span)
         .done()
         .run_with_handle();

diff --git a/tracing-attributes/tests/follows_from.rs b/tracing-attributes/tests/follows_from.rs
@@ -58,6 +58,8 @@ fn follows_from_async_test() {
         .follows_from(consequence.clone(), cause_b)
         .follows_from(consequence.clone(), cause_c)
         .enter(consequence.clone())
+        .exit(consequence.clone())
+        .enter(consequence.clone())
         .exit(consequence)
         .done()
         .run_with_handle();

diff --git a/tracing-attributes/tests/ret.rs b/tracing-attributes/tests/ret.rs
@@ -138,6 +138,8 @@ fn test_async() {
                 .at_level(Level::INFO),
         )
         .exit(span.clone())
+        .enter(span.clone())
+        .exit(span.clone())
         .drop_span(span)
         .done()
         .run_with_handle();

diff --git a/tracing-futures/Cargo.toml b/tracing-futures/Cargo.toml
@@ -40,6 +40,7 @@ tokio-threadpool = { version = "0.1.18", optional = true }
 mio = { version = "0.6.23", optional = true }
 
 [dev-dependencies]
+futures = "0.3.21"
 tokio-test = "0.4.2"
 tracing-core = { path = "../tracing-core", version = "0.1.28" }
 tracing-mock = { path = "../tracing-mock", features = ["tokio-test"] }

diff --git a/tracing-futures/src/executor/futures_01.rs b/tracing-futures/src/executor/futures_01.rs
@@ -4,24 +4,18 @@ use futures_01::{
     Future,
 };
 
-macro_rules! deinstrument_err {
-    ($e:expr) => {
-        $e.map_err(|e| {
-            let kind = e.kind();
-            let future = e.into_future().inner;
-            ExecuteError::new(kind, future)
-        })
-    };
-}
-
 impl<T, F> Executor<F> for Instrumented<T>
 where
     T: Executor<Instrumented<F>>,
     F: Future<Item = (), Error = ()>,
 {
     fn execute(&self, future: F) -> Result<(), ExecuteError<F>> {
         let future = future.instrument(self.span.clone());
-        deinstrument_err!(self.inner.execute(future))
+        self.inner.execute(future).map_err(|e| {
+            let kind = e.kind();
+            let future = e.into_future().into_inner();
+            ExecuteError::new(kind, future)
+        })
     }
 }
 
@@ -32,7 +26,11 @@ where
 {
     fn execute(&self, future: F) -> Result<(), ExecuteError<F>> {
         let future = self.with_dispatch(future);
-        deinstrument_err!(self.inner.execute(future))
+        self.inner.execute(future).map_err(|e| {
+            let kind = e.kind();
+            let future = e.into_future().inner;
+            ExecuteError::new(kind, future)
+        })
     }
 }