Help LLVM understand that some spans are never going to do anything

[oli-obk]

Motivation

Adding #[instrument(level = "debug")] attributes to functions in rustc
caused a performance regression (in release, where debug! is fully
optimized out) across all crates:
rust-lang/rust#89048 (comment)

While trying to debug this, I noticed that spans don't have the same
advantage that events have wrt to how LLVM sees them. Spans (or more
precisely, the enter-guard), will get dropped at the end of the scope,
which throws a spanner into the LLVM optimization pipeline. I am not
entirely sure where the problem is, but I am moderately certain that the
issue is that even entering a dummy span is too much code for LLVM to
reliably (or at all) optimize out.

Solution

My hope is that in trusting the Rust compiler to generate cool code when using
drop flags, we can essentially generate a drop flag that depends on something we
know (due to events working as expected) to be optimizable.

So instead of doing

let _x = span!();
let _y = _x.enter();
// lotsa code
drop(_y)

we do

let _x;
let _y;
let must_drop = false;
if level_enabled!(DEBUG) {
    must_drop = true;
    _x = span!();
    _y = _x.enter();
}
// lotsa code
if must_drop {
    drop(_y)
}

I believe this will allow LLVM to properly optimize this again. Testing that
right now, but I wanted to open this PR immediately for review.

[hawkw]

Thanks, this is very cool!

It seems like it should also be possible to do something similar for #[instrument]ed async blocks --- we could just not add the instrument combinator at all when the span won't be enabled, avoiding the extra per-poll overhead of entering the disabled span. However, we should probably do that in a follow-up branch, rather than this one.

This change looks good to me!

[hawkw]

lovely, thank you!

[hawkw]

As an aside, I think we should be able to make the same change in the err case here as well:

tracing/tracing-attributes/src/lib.rs

Lines 540 to 553 in c945ac0

	} else if err {
	quote_spanned!(block.span()=>
	let __tracing_attr_span = #span;
	let __tracing_attr_guard = __tracing_attr_span.enter();
	#[allow(clippy::redundant_closure_call)]
	match (move || #block)() {
	#[allow(clippy::unit_arg)]
	Ok(x) => Ok(x),
	Err(e) => {
	tracing::error!(error = %e);
	Err(e)
	}
	}
	)

and I think we'll see the same benefits?

[oli-obk]

yes, once the perf is through and shows that this actually works, I will add the same change to the async and err branches

[hawkw]

yes, once the perf is through and shows that this actually works, I will add the same change to the async and err branches

cool, i'll hold off on merging this PR until then!

I think the change in the async case will be somewhat significantly different than non-async, but it should still be possible to make a similar optimization...

[oli-obk]

I have finished optimizing the other code paths. Perfbot also says that this is working.

One thing I'm wondering is whether it would be possible to backport this to tracing 0.1, as there is no published 0.2 candidate yet

[hawkw]

One thing I'm wondering is whether it would be possible to backport this to tracing 0.1, as there is no published 0.2 candidate yet

Yeah, AFAICT this should be pretty much trivial to backport to 0.1. I can handle that part, though --- I'll see about getting a release prepped today!

[hawkw]

this looks good to me, but I think we may actually be able to improve the case with futures even further. i'm going to go ahead and merge this PR, and improve things more in a follow-up.

thanks again for working on this!

[hawkw]

in this case, since we are always creating the span, we could actually do this:

Suggested change

	if tracing::level_enabled!(#level) {
	tracing::Instrument::instrument(
	fut,
	__tracing_attr_span
	)
	.await
	if !span.is_disabled() {
	tracing::Instrument::instrument(
	fut,
	__tracing_attr_span
	)
	.await

which would also let us skip instrumenting the future in the case where the span's level is enabled but it was disabled by the subscriber (e.g. if its target was not enabled)

[hawkw]

actually, we could probably also do the optimization of not creating the span at all if the level is disabled:

Suggested change

	if tracing::level_enabled!(#level) {
	tracing::Instrument::instrument(
	fut,
	__tracing_attr_span
	)
	.await
	} else {
	fut.await
	}
	if tracing::level_enabled!(#level) {
	let __tracing_attr_span = #span;
	if !span.is_disabled() {
	return tracing::Instrument::instrument(
	fut,
	__tracing_attr_span
	)
	.await;
	}
	fut.await