fix(client): spawn background tasks detached from the request span - #311
fix(client): spawn background tasks detached from the request span#311marsavar wants to merge 1 commit into
Conversation
The connection dispatcher and the pool's idle eviction task are scoped to a connection/the pool, rather than the request that spawned them. Executors propagate the current span into spawned tasks, which has the unintended effect of keeping a request's span open for as long as the connection is sat idle in the pool, essentially making the request duration look like it lived the same time as `pool_idle_timeout`. This change makes it so that the task is spawned with no subscriber for the duration of the call. There is then no current span for the executor to copy, which means the request's span ends when the request does. Doing this in `Exec::execute` also covers the HTTP/2 connection task that hyper spawns internally during the handshake.
| match *self { | ||
| Exec::Executor(ref e) => { | ||
| e.execute(Box::pin(fut)); | ||
| tracing::dispatcher::with_default(&tracing::Dispatch::none(), || { |
There was a problem hiding this comment.
It seems that the problem is with TokioExecutor instead of Exec.
Also, this makes tracing a dependency when running Exec without tokio.
There was a problem hiding this comment.
It seems that the problem is with TokioExecutor instead of Exec.
TokioExecutor (or any Executor someone passes in) is shared by both the client and the h2 server implementation, whereas Exec is client only. So fixing Exec seems more logical to me, because changing the behaviour of TokioExecutor would have an impact on the h2 server span propagation (which I believe works correctly at the moment). Not too sure what a good API would look like here... open to suggestions.
Also, this makes tracing a dependency when running Exec without tokio.
I believe that's already the case today, see:
$ cargo tree --invert tracing --no-default-features --features client-legacy --edges no-dev
tracing v0.1.44
└── hyper-util v0.1.20
client enables dep:tracing so the legacy client already pulls it in.
And the client-legacy feature enables hyper-util's tokio feature:
$ cargo tree --invert tokio --no-default-features --features client-legacy --edges features,no-dev
tokio v1.53.1
└── hyper-util v0.1.20
├── hyper-util feature "client"
│ └── hyper-util feature "client-legacy" (command-line)
├── hyper-util feature "client-legacy" (command-line)
└── hyper-util feature "tokio"
└── hyper-util feature "client-legacy" (command-line)
That being said, I agree with you that the question becomes whether Exec should know about tracing at all, and it probably should not. Perhaps something like this would be more semantically accurate (i.e. gating on the tracing feature):
Exec::Executor(ref e) => {
#[cfg(feature = "tracing")]
tracing::dispatcher::with_default(&tracing::Dispatch::none(), || {
e.execute(Box::pin(fut));
});
#[cfg(not(feature = "tracing"))]
e.execute(Box::pin(fut));
}What do you think?
2 participants
Fixes hyperium/hyper#3904
While instrumenting tracing for a project my team and I are working on, we stumbled into the same issue reported here:
Currently, when the
tracingfeature is enabled,TokioExecutor::executecalls.in_current_span()on every task it spawns, so a task keeps a clone of whatever span was active at the time, and that span can't close until the task drops it.The legacy client spawns its connection and pool tasks mid request, and they outlive the request, so when the connection ends up back in the pool it still the span of the request that opened it.
Note that this "stuck span" issue only happens once per connection, not per request. If a request picks up an idle connection, nothing gets spawned so nothing takes a clone of its span. You can see this in the examples below, where request 1 leaks the span, whereas requests 2 and 3 do not.
How to reproduce
I asked Claude to generate a test to reproduce the bug. You can find the source code here.
I ran the code against this commit and the
masterbranch for bothHTTP/1.1andHTTP/2to ensure the fix works for both. Below is the output for each.Current master branch - HTTP/1.1
Current master branch - HTTP/2
This PR - HTTP/1.1
This PR - HTTP/2