From feda6ee86b11eccca10e0f9a36144377435273a0 Mon Sep 17 00:00:00 2001 From: Oli Scherer Date: Wed, 29 Sep 2021 14:36:36 +0000 Subject: [PATCH 1/4] Help LLVM understand that some spans are never going to do anything --- tracing-attributes/src/lib.rs | 11 ++++++++--- 1 file changed, 8 insertions(+), 3 deletions(-) diff --git a/tracing-attributes/src/lib.rs b/tracing-attributes/src/lib.rs index d3630ffbfc..da7377cdb3 100644 --- a/tracing-attributes/src/lib.rs +++ b/tracing-attributes/src/lib.rs @@ -403,6 +403,8 @@ fn gen_block( .map(|name| quote!(#name)) .unwrap_or_else(|| quote!(#instrumented_function_name)); + let level = args.level(); + // generate this inside a closure, so we can return early on errors. let span = (|| { // Pull out the arguments-to-be-skipped first, so we can filter results @@ -448,7 +450,6 @@ fn gen_block( } } - let level = args.level(); let target = args.target(); // filter out skipped fields @@ -552,8 +553,12 @@ fn gen_block( ) } else { quote_spanned!(block.span()=> - let __tracing_attr_span = #span; - let __tracing_attr_guard = __tracing_attr_span.enter(); + let __tracing_attr_span; + let __tracing_attr_guard; + if tracing::level_enabled!(#level) { + __tracing_attr_span = #span; + __tracing_attr_guard = __tracing_attr_span.enter(); + } #block ) } From 94842edb9ee0f9d19d01bbe1cbf63d6af78389d5 Mon Sep 17 00:00:00 2001 From: Oli Scherer Date: Wed, 29 Sep 2021 14:57:33 +0000 Subject: [PATCH 2/4] Pacify clippy --- tracing-attributes/src/lib.rs | 2 ++ 1 file changed, 2 insertions(+) diff --git a/tracing-attributes/src/lib.rs b/tracing-attributes/src/lib.rs index da7377cdb3..e2cacdd1c3 100644 --- a/tracing-attributes/src/lib.rs +++ b/tracing-attributes/src/lib.rs @@ -559,6 +559,8 @@ fn gen_block( __tracing_attr_span = #span; __tracing_attr_guard = __tracing_attr_span.enter(); } + // pacify clippy::suspicious_else_formatting + let _ = (); #block ) } From 27bd20e52bf09fa316c4d929159f645708967532 Mon Sep 17 00:00:00 2001 From: Oli Scherer Date: Wed, 29 Sep 2021 16:37:01 +0000 Subject: [PATCH 3/4] Explain the lazy variable initialization --- tracing-attributes/src/lib.rs | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/tracing-attributes/src/lib.rs b/tracing-attributes/src/lib.rs index e2cacdd1c3..9f7d3f6c9f 100644 --- a/tracing-attributes/src/lib.rs +++ b/tracing-attributes/src/lib.rs @@ -553,6 +553,16 @@ fn gen_block( ) } else { quote_spanned!(block.span()=> + // These variables are left uninitialized and initialized only + // if the tracing level is statically enabled at this point. + // While the tracing level is also checked at span creation + // time, that will still create a dummy span, and a dummy guard + // and drop the dummy guard later. By lazily initializing these + // variables, Rust will generate a drop flag for them and thus + // only drop the guard if it was created. This creates code that + // is very straightforward for LLVM to optimize out if the tracing + // level is statically disabled, while not causing any performance + // regression in case the level is enabled. let __tracing_attr_span; let __tracing_attr_guard; if tracing::level_enabled!(#level) { From b1b0de2fcf4825c8dc9eb112d5bc67b65588a9d9 Mon Sep 17 00:00:00 2001 From: Oli Scherer Date: Thu, 30 Sep 2021 12:53:34 +0000 Subject: [PATCH 4/4] Apply the static level optimization to async fns and error printing --- tracing-attributes/src/lib.rs | 36 ++++++++++++++++++++++++++++++----- 1 file changed, 31 insertions(+), 5 deletions(-) diff --git a/tracing-attributes/src/lib.rs b/tracing-attributes/src/lib.rs index 9f7d3f6c9f..130002417c 100644 --- a/tracing-attributes/src/lib.rs +++ b/tracing-attributes/src/lib.rs @@ -516,7 +516,9 @@ fn gen_block( if err { quote_spanned!(block.span()=> let __tracing_attr_span = #span; - tracing::Instrument::instrument(async move { + // See comment on the default case at the end of this function + // for why we do this a bit roundabout. + let fut = async move { match async move { #block }.await { #[allow(clippy::unit_arg)] Ok(x) => Ok(x), @@ -525,22 +527,46 @@ fn gen_block( Err(e) } } - }, __tracing_attr_span).await + }; + if tracing::level_enabled!(#level) { + tracing::Instrument::instrument( + fut, + __tracing_attr_span + ) + .await + } else { + fut.await + } ) } else { quote_spanned!(block.span()=> let __tracing_attr_span = #span; + // See comment on the default case at the end of this function + // for why we do this a bit roundabout. + let fut = async move { #block }; + if tracing::level_enabled!(#level) { tracing::Instrument::instrument( - async move { #block }, + fut, __tracing_attr_span ) .await + } else { + fut.await + } ) } } else if err { quote_spanned!(block.span()=> - let __tracing_attr_span = #span; - let __tracing_attr_guard = __tracing_attr_span.enter(); + // See comment on the default case at the end of this function + // for why we do this a bit roundabout. + let __tracing_attr_span; + let __tracing_attr_guard; + if tracing::level_enabled!(#level) { + __tracing_attr_span = #span; + __tracing_attr_guard = __tracing_attr_span.enter(); + } + // pacify clippy::suspicious_else_formatting + let _ = (); #[allow(clippy::redundant_closure_call)] match (move || #block)() { #[allow(clippy::unit_arg)]