tracing-subscriber: remove clone_span on enter

[conradludgate]

Motivation

I briefly discussed this on Discord. At work, we enabled continuous profiling which gives us a flamegraph on our production workloads. Inspecting one of our hot-paths, I was surprised to see Span::enter being a significant percent of the samples.

This is currently using tracing-subscriber = "0.3.19".

Concrete numbers:
7.7% of samples were found within the stacktrace of a Span::enter.
Of those samples, 22.8% were inside clone_span.
Collectively, that's 1.8% of total CPU time spent in clone_span as a result of Span::enter.

These numbers don't surprise me. Our hot-loop of our service is a modified copy_bidirectional. Each poll will often be very short, so the Span::enter will take a not insignificant percentage of the time. And since it's only IO that can wake the task, tokio will likely move it around threads depending on which thread happened to be the driver, so any atomic operations (eg a fetch_add) will likely be a cache miss.

The rest of the time of clone_span seems to be within our various layers, we can address those somewhere else.

When looking through the code, I couldn't find a good justification for enter to need clone_span. I understand it might be defensive programming - someone can use the Collect api without using tracing::Span, and they can use it incorrectly. It would thus prevent some panics on exit (a layer using LookupSpan on exit and unwrapping) which would better prevent double-panics on drop handling during a panic. However, I see no unsafe code relying on spans definitely being alive during exit, and when using tracing::Span::enter which I think is the blessed case, the invariant that the span is alive during exit is upheld.

Solution

Remove clone_span from enter, remove try_close from exit.

[hawkw]

Hmm. If memory serves, you're correct that this was intended as defensive programming against incorrect "manual" use of the subscriber API.

As you point out, the Span type prevents the span's reference count from going to zero while it's entered, because Span::enter borrows the Span, which owns a clone of the reference count, and it cannot be dropped until it is exited. However, manual use of the lower-level tracing-core APIs could get this wrong and drop all "references" to a span while it is entered. This wouldn't cause memory corruption, since this isn't a "reference count" in the sense of keeping an allocation alive, but it would potentially result in messed up traces, if the span's ID is reused --- events might end up being associated with the wrong span incorrectly.

In practice, though, I'm not sure if it's worthwhile to guard against mistakes in manual use of the lower-level tracing-core enter/exit APIs if it comes at a significant performance cost. There are very few such manual uses of those APIs in the wild --- fewer than I had kind of anticipated. So, maybe it's worth removing this, and expecting that anyone implementing their own Span-like code using the tracing-core API should just be careful to not mess this up. It also eliminates the dispatch::get_default call in the registry's exit method, which is one of my least favorite things.