Legacy Client pooling messes tower::TraceLayer tracing

Version
hyper 1.6.0
hyper-util 0.1.12
tower 0.5.2
tower-http 0.6.4

Platform
Linux 6.10.14-linuxkit #1 SMP Tue Apr 15 16:00:54 UTC 2025 aarch64 GNU/Linux

Description
When using tower_http::TraceLayer with hyper_util::client::legacy::Client, with HTTP/1 requests, the request spans are kept alive all the way until the underlying idle connection is disposed (90s by default). This prevents us from effectively monitoring kubernetes controller written with kube-rs (which uses this combination).

After looking deeper into it, here's what's happening:

TraceLayer correctly creates a new span.
Client creates a new TCP connection via send_request -> try_send_request -> connection_for -> one_connection_for -> connect_to.
After the handshake, connect_to creates a background dispatcher task to manage the connection.
TokioExecutor spawns that task after wrapping it with .in_current_span(), which copies the span.
Now original request finishes, response is processed and original copy of span is dropped. This is where the span should ideally be dropped, reporting the end of the request.
Instead, the underlying connection is moved to the pool as "idle" and the dispatcher task keeps a reference to the span. Only after the connection is disposed (90s by default), do we see the span dropped and span data reported to the OTEL server.
We see a lot of requests with duration around 90s, which makes it hard to work with the reported metrics.

Here's the full stack trace of when the span is getting cloned

   3: tracing_core::dispatcher::Dispatch::clone_span
             at <index.crates.io>/tracing-core-0.1.32/src/dispatcher.rs:659:13
   4: tracing::span::Span::current::{{closure}}
             at <index.crates.io>/tracing-0.1.40/src/span.rs:552:26
   5: tracing_core::dispatcher::get_default
             at <index.crates.io>/tracing-core-0.1.32/src/dispatcher.rs:391:16
   6: tracing::span::Span::current
             at <index.crates.io>/tracing-0.1.40/src/span.rs:550:9
   7: tracing::instrument::Instrument::in_current_span
             at <index.crates.io>/tracing-0.1.40/src/instrument.rs:129:25
   8: <hyper_util::rt::tokio::TokioExecutor as hyper::rt::Executor<Fut>>::execute
             at <index.crates.io>/hyper-util-0.1.12/src/rt/tokio.rs:112:22
   9: hyper_util::common::exec::Exec::execute
             at <index.crates.io>/hyper-util-0.1.12/src/common/exec.rs:34:17
  10: hyper_util::client::legacy::client::Client<C,B>::connect_to::{{closure}}::{{closure}}::{{closure}}
             at <index.crates.io>/hyper-util-0.1.12/src/client/legacy/client.rs:585:37
  11: <core::pin::Pin<P> as core::future::future::Future>::poll
             at <rust-lib>/core/src/future/future.rs:124:9
  12: <futures_util::future::either::Either<A,B> as core::future::future::Future>::poll
             at <index.crates.io>/futures-util-0.3.30/src/future/either.rs:109:32
  13: <F as futures_core::future::TryFuture>::try_poll
             at <index.crates.io>/futures-core-0.3.30/src/future.rs:82:9
  14: <futures_util::future::try_future::try_flatten::TryFlatten<Fut,<Fut as futures_core::future::TryFuture>::Ok> as core::future::future::Future>::poll
             at <index.crates.io>/futures-util-0.3.30/src/future/try_future/try_flatten.rs:57:41
  15: <futures_util::future::try_future::TryFlatten<Fut1,Fut2> as core::future::future::Future>::poll
             at <index.crates.io>/futures-util-0.3.30/src/lib.rs:91:13
  16: <futures_util::future::try_future::AndThen<Fut1,Fut2,F> as core::future::future::Future>::poll
             at <index.crates.io>/futures-util-0.3.30/src/lib.rs:91:13
  17: <futures_util::future::either::Either<A,B> as core::future::future::Future>::poll
             at <index.crates.io>/futures-util-0.3.30/src/future/either.rs:109:32
  18: <hyper_util::common::lazy::Lazy<F,R> as core::future::future::Future>::poll
             at <index.crates.io>/hyper-util-0.1.12/src/common/lazy.rs:64:20
  19: futures_util::future::future::FutureExt::poll_unpin
             at <index.crates.io>/futures-util-0.3.30/src/future/future/mod.rs:558:9
  20: <futures_util::future::select::Select<A,B> as core::future::future::Future>::poll
             at <index.crates.io>/futures-util-0.3.30/src/future/select.rs:118:35
  21: hyper_util::client::legacy::client::Client<C,B>::one_connection_for::{{closure}}
             at <index.crates.io>/hyper-util-0.1.12/src/client/legacy/client.rs:435:49
  22: hyper_util::client::legacy::client::Client<C,B>::connection_for::{{closure}}
             at <index.crates.io>/hyper-util-0.1.12/src/client/legacy/client.rs:386:61
  23: hyper_util::client::legacy::client::Client<C,B>::try_send_request::{{closure}}
             at <index.crates.io>/hyper-util-0.1.12/src/client/legacy/client.rs:281:14
  24: hyper_util::client::legacy::client::Client<C,B>::send_request::{{closure}}
             at <index.crates.io>/hyper-util-0.1.12/src/client/legacy/client.rs:249:70
  25: <hyper_util::client::legacy::client::ResponseFuture as core::future::future::Future>::poll
             at <index.crates.io>/hyper-util-0.1.12/src/client/legacy/client.rs:704:9
  26: <F as futures_core::future::TryFuture>::try_poll
             at <index.crates.io>/futures-core-0.3.30/src/future.rs:82:9
  27: <futures_util::future::try_future::into_future::IntoFuture<Fut> as core::future::future::Future>::poll
             at <index.crates.io>/futures-util-0.3.30/src/future/try_future/into_future.rs:34:9
  28: <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll
             at <index.crates.io>/futures-util-0.3.30/src/future/future/map.rs:55:37
  29: <futures_util::future::future::Map<Fut,F> as core::future::future::Future>::poll
             at <index.crates.io>/futures-util-0.3.30/src/lib.rs:91:13
  30: <futures_util::future::try_future::MapErr<Fut,F> as core::future::future::Future>::poll
             at <index.crates.io>/futures-util-0.3.30/src/lib.rs:91:13
  31: <tower::util::map_err::MapErrFuture<F,N> as core::future::future::Future>::poll
             at <index.crates.io>/tower-0.5.2/src/macros.rs:38:17
  32: <tower_http::trace::future::ResponseFuture<Fut,C,OnResponseT,OnBodyChunkT,OnEosT,OnFailureT> as core::future::future::Future>::poll
             at <index.crates.io>/tower-http-0.6.4/src/trace/future.rs:64:29
  33: <tower::filter::future::AsyncResponseFuture<P,S,Request> as core::future::future::Future>::poll
             at <index.crates.io>/tower-0.5.2/src/filter/future.rs:93:28
  34: <tower::util::either::EitherResponseFuture<A,B> as core::future::future::Future>::poll
             at <index.crates.io>/tower-0.5.2/src/util/either.rs:85:42
  35: <tower::util::either::EitherResponseFuture<A,B> as core::future::future::Future>::poll
             at <index.crates.io>/tower-0.5.2/src/util/either.rs:84:41
  36: <tower_http::map_response_body::ResponseFuture<Fut,F> as core::future::future::Future>::poll
             at <index.crates.io>/tower-http-0.6.4/src/map_response_body.rs:182:26
  37: <core::pin::Pin<P> as core::future::future::Future>::poll
             at <rust-lib>/core/src/future/future.rs:124:9
  38: <tower_http::map_response_body::ResponseFuture<Fut,F> as core::future::future::Future>::poll
             at <index.crates.io>/tower-http-0.6.4/src/map_response_body.rs:182:26
  39: <F as futures_core::future::TryFuture>::try_poll
             at <index.crates.io>/futures-core-0.3.30/src/future.rs:82:9
  40: <futures_util::future::try_future::into_future::IntoFuture<Fut> as core::future::future::Future>::poll
             at <index.crates.io>/futures-util-0.3.30/src/future/try_future/into_future.rs:34:9
  41: <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll
             at <index.crates.io>/futures-util-0.3.30/src/future/future/map.rs:55:37
  42: <futures_util::future::future::Map<Fut,F> as core::future::future::Future>::poll
             at <index.crates.io>/futures-util-0.3.30/src/lib.rs:91:13
  43: <futures_util::future::try_future::MapErr<Fut,F> as core::future::future::Future>::poll
             at <index.crates.io>/futures-util-0.3.30/src/lib.rs:91:13
  44: <tower::util::map_err::MapErrFuture<F,N> as core::future::future::Future>::poll
             at <index.crates.io>/tower-0.5.2/src/macros.rs:38:17
  45: <core::pin::Pin<P> as core::future::future::Future>::poll
             at <rust-lib>/core/src/future/future.rs:124:9
  46: <tower::buffer::future::ResponseFuture<F> as core::future::future::Future>::poll
             at <index.crates.io>/tower-0.5.2/src/buffer/future.rs:75:59
  47: kube_client::client::Client::send::{{closure}}
             at <index.crates.io>/kube-client-1.0.0/src/client/mod.rs:213:14
  48: kube_client::client::Client::request_text::{{closure}}
             at <index.crates.io>/kube-client-1.0.0/src/client/mod.rs:285:54
  49: kube_client::client::Client::request::{{closure}}
             at <index.crates.io>/kube-client-1.0.0/src/client/mod.rs:274:47
  50: kube_client::client::Client::apiserver_version::{{closure}}
             at <index.crates.io>/kube-client-1.0.0/src/client/mod.rs:410:10

One option to resolve this is to switch off the tracing feature, but it's a bit hard to do in our case because we depend on hyper_utils via kube-client - kube crates. Plus it looks like the opposite direction of what we want to do (we want more tracing, not less).

The other option is to switch off the pooling. Not great as well.

I wonder if you have any ideas of how to maybe make it smarter than just .in_current_span()? Conceptually it seems to be mixing request lifecycle and connection lifecycle, which will always be different when pooling is involved.

Thank you!

Yea, I've seen that happen before (such as in tokio-console). I don't have an easy solution from a tracing perspective.

We could make calling in_current_span configurable on the TokioExecutor type, as one possible solution.

Thanks for the response! I see a bit more context for adding tracing in hyperium/hyper-util#166.

In the discussion there, there was exactly this concern:

I think an issue when doing this automatically is that some tasks that are spawned live longer than the initial context. For example, if a new connection is created when trying to serve a request, and then that connection is put in a pool and used for later requests, the context is no longer the same.

Amusingly, kube-rs was mentioned as one of the crates that would benefit from this :)

I'm not 100% sure how to fix it, but adding in_current_span to connection-level futures does not seem to be the right way. Maybe we can store the span more explicitly in request-level structs/closures and activate it manually?

@alpeb

I wonder if @alpeb or @olix0r as original authors of hyperium/hyper-util#166 have any ideas of how can we make it respect the request lifecycle?

Also for reference and more context, here's an issue in kube-rs: kube-rs/kube#1775

@ashtuchkin

We could make calling in_current_span configurable on the TokioExecutor type, as one possible solution.

Isn't this already the case via the tracing feature?

@ashtuchkin My understanding is ~~that the only real solution for this would be for Hyper to integrate directly with tracing to ensure the task-context accounting is correct.~~ [edit: i don't even think that's necessarily right -- there are probably bigger lifecycle issues to think through, see below]

Additionally: the connection itself probably should not have the request context associated with it, but instead only the connection-level metadata. There's a fundamental mismatch between the lifecycle of TraceLayer and the way these connections/pools are instantiated. It is also probably the case that this could be addressed in kube-rs by structuring the stack differently. (I'm not saying this is easy, just that it's in the solution-space).

the connection itself probably should not have the request context associated with it, but instead only the connection-level metadata.

Totally agree here. Alas the way it's written right now, connections implicitly clone & store the "current" span that was active at request time due to in_current_span construction.

There's a fundamental mismatch between the lifecycle of TraceLayer and the way these connections/pools are instantiated.

The way I see it is that TraceLayer works correctly here. It creates a tracing span at the beginning of request and makes sure it's dropped at the end of response. The fact that hyper Client unexpectedly holds on to that span and attaches it to a connection-level task which outlives request seems unexpected.

In fact, I struggle to see a use case where this arrangement is expected. Do we ever want to attach a span to a connection that can be shared between requests? Does it work for your use case? Is it because with HTTP/2 it's a different codepath (I haven't looked deep into it)?

It is also probably the case that this could be addressed in kube-rs by structuring the stack differently. (I'm not saying this is easy, just that it's in the solution-space).

I'm curious if you have any ideas how to do that!

I have been debugging an issue with our telemetry in a complicated internal microservice stack to eventually arrive at this issue. We have kube as a dependency for part of our cargo workspace and it enabled the hyper-util/tracing feature for the whole stack as a result. The end result is that various spans in our tracing inconsistently have their duration extended by multiple minutes if they happen to be the span that spawns a connection; it really messes with telemetry and application processing.

We could make calling in_current_span configurable on the TokioExecutor type, as one possible solution.

Note that this was / is already possible before hyperium/hyper-util#166 was merged; the caller spawning the future onto the TokioExecutor could opt-in with .in_current_span() themselves.

IMO the only question is whether opt-in or opt-out is the better behaviour here. Previously it was opt-in, after hyperium/hyper-util#166 it's opt-out for all callers and all callers need updating for the changed default. Probably any caller that spawns a long lived background task should be opting-out in case a downstream or sibling depdendency enables the hyper-util/tracing feature. (The best way to opt-out is to create a new span before calling TokioExecutor::execute with no parent, optionally using Span::follows_from to create a link to the current span without extending it.)

I started trying to update hyper-util to opt-out its own background tasks in hyperium/hyper-util@0ccd658 but this was insufficient to fix my traces; I assume that any callers downstream of hyper-util might also be creating the same problem.

In the end the only thing I could practically do was apply a hyper-util patch to revert hyperium/hyper-util#166

hyperium/hyper-util@ffb1d0d

It would be great to get this solved 🙏

My two cents - this feature seems like it's likely to cause more harm than good, perhaps it's worth considering reverting it and going back to leaving it to callers to opt-in where it's needed?

@davidhewitt

My two cents - this feature seems like it's likely to cause more harm than good, perhaps it's worth considering reverting it and going back to leaving it to callers to opt-in where it's needed?

I agree with @davidhewitt here. The fact that a sibling dependency can break your traces by activating a feature flag makes for some difficult debugging when monitoring starts raising alerts for overly long spans.

@cratelyn I see you activated this feature for kube-rs in kube-rs/kube#1734 so maybe you want to weigh in here (it's also in a similar vein as hyperium/h2#868 and shows up with the same symptoms as the problem mentioned there)

fix(rt): remove automatic span propagation from TokioExecutor

I ran into the opposite issue today.

I got this message after a while:

2026-01-18T18:58:57.751900Z DEBUG hyper_util::client::legacy::client: client connection error: hyper::Error(Io, Os { code: 104, kind: ConnectionReset, message: "Connection reset by peer" })

After some searching I ended up here, and noticed I did not have hyper-util/tracing enabled.

Doing so, combined with #![instrument] on certain functions allowed me to figure out which client destination was sending the RST packages.

Problem sis that PR #259 essentially removes that capability for me.

I agree that the trace should not capture the request as whole, so instead should we look at adding more information to the message (if possible?) like DNS / IP etc? I'm unsure if that's kept actually outside of any span information (that we wouldn't pass along anymore then).

Coming here via #4053 (comment) and tokio-rs/tracing#3521. I also opened kube-rs/kube#1972 to make the tracing feature opt-in which is a not great cargo features workaround.

I don't have much (any?) time to devote to this but I would strongly vote for the tracing feature to be removed until someone has the time to figure out how to improve it.

For others who come across this: you can define your own executor without in_current_span

/// Future executor that utilises `tokio` threads.
#[non_exhaustive]
#[derive(Default, Debug, Clone)]
pub struct TokioExecutor {}

impl<Fut> Executor<Fut> for TokioExecutor
where
    Fut: Future + Send + 'static,
    Fut::Output: Send + 'static,
{
    fn execute(&self, fut: Fut) {
        tokio::spawn(fut);
    }
}

And then pass that to hyper_util::client::legacy::Client::builder or tonic::transport::Endpoint::executor or however else you're building a client.

For others who come across this: you can define your own executor without in_current_span

/// Future executor that utilises tokio threads.
#[non_exhaustive]
#[derive(Default, Debug, Clone)]
pub struct TokioExecutor {}

impl Executor for TokioExecutor
where
Fut: Future + Send + 'static,
Fut::Output: Send + 'static,
{
fn execute(&self, fut: Fut) {
tokio::spawn(fut);
}
}
And then pass that to hyper_util::client::legacy::Client::builder or tonic::transport::Endpoint::executor or however else you're building a client.

Thanks. This is unfortunately not possible through reqwest or the AWS SDK, since both construct their hyper client internally.

OK, I've tried to solve this in hyperium/hyper-util#322. It could be considered a breaking change for some, but all the options seemed not great in some way or another. Appreciate any feedback.

i've also opened hyperium/hyper-util#323, further building on Sean's work. this branch introduces a collection of interfaces that can propagate the current span to spawned tasks, as well as instrument spawned tasks using Span::follows_from as noted above.

i'd appreciate feedback as well, and am hopeful that this should provide workable solutions to everybody here. thank you for all of your input, everybody!

feat(rt/tracing): introduce tracing executors (#323)

feat(client): allow customizable `hyper::rt::Executor<F>`

Navigation Menu

Repository navigation

Legacy Client pooling messes tower::TraceLayer tracing #3904

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Legacy Client pooling messes tower::TraceLayer tracing #3904

Description

Activity

seanmonstar commented on Jun 17, 2025

ashtuchkin commented on Jun 17, 2025

ashtuchkin commented on Jun 17, 2025

olix0r commented on Jun 18, 2025

olix0r commented on Jun 18, 2025

ashtuchkin commented on Jun 18, 2025

davidhewitt commented on Jul 7, 2025

Jesse-Bakker commented on Dec 6, 2025

kristof-mattei commented on Jan 18, 2026

mattklein123 commented on Apr 21, 2026

bouk commented on Jun 4, 2026

mlowicki-atai commented on Sep 11, 2026

seanmonstar commented on Sep 17, 2026

cratelyn commented on Sep 21, 2026

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions