Legacy Client pooling messes tower::TraceLayer tracing
Los mantenedores suelen responder en 2 días
Nadie ha tomado este issue todavía.
Evaluación
- Dificultad
- 4/5
- Tiempo estimado
- 3-5 días
- Aptitud para principiantes
- 52/100
- Tipo de issue
- Error
- Claridad
- Bastante claro
- Estado de actividad
- Activo
- Stack tecnológico
- rust
- Área
- networking, observability
Línea de trabajo
Comienza en hyper-util/src/client/legacy/client.rs, en connect_to, y en hyper-util/src/rt/tokio.rs, en la instrumentación de tracing del executor. Reproduce una solicitud HTTP/1 a través de TraceLayer con el connection pooling habilitado y, después, inspecciona cómo el span de la solicitud es retenido por el dispatcher en segundo plano. La tarea está terminada cuando los spans de las solicitudes finalizan con la respuesta, en lugar de hacerlo cuando se elimina la conexión inactiva del pool.
Escrito por el modelo de indexación a partir del texto del issue.
Descripción
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!
- Lenguaje dominante
- Rust
- Estrellas
- 16.3k
- Forks
- 1.8k
- Merge medio
- 4 d 15 h
- PR fusionados (30 d)
- 20
Preparar el entorno
- Sin Dockerfile ni archivo de Docker Compose
- Sin plantilla de pull request
- Leer la guía de contribución
Primeros pasos
- Lee el issue completo y luego la guía de contribución del proyecto.
- Comenta en el issue que vas a ocuparte — evita que dos personas hagan lo mismo.
- Haz un fork del repositorio y trabaja en una rama.
- Abre un pull request que haga referencia al número del issue.
Más de hyperium/hyper
-
Publicly reexport the http crateAbiertoC-feature
Dificultad 1/5 Menos de una hora Aptitud para principiantes 65/100
hyperium/hyper#2652 · 4 reacciones ·
Los mantenedores suelen responder en 2 días
-
Dificultad 3/5 1-2 días Aptitud para principiantes 74/100
hyperium/hyper#4211 · 1 comentario ·
Los mantenedores suelen responder en 2 días
-
Upgraded HTTP/2 CONNECT streams cannot be reset, so a failed tunnel looks like a clean closePosiblemente ocupada @jeremyjpj0916 la tomó hace 9 días. Abierto
Dificultad 4/5 3-5 días Aptitud para principiantes 55/100
Los mantenedores suelen responder en 2 días
-
hyper-util legacy client: an HTTP/1 request can hang forever when the connection closes while the request is being queuedPosiblemente ocupada Un pull request vinculado a esta issue está abierto o ya se fusionó. Abierto
Dificultad 4/5 3-5 días Aptitud para principiantes 62/100
hyperium/hyper#4202 · 1 comentario ·
Los mantenedores suelen responder en 2 días
-
Allow connection pools to stop reusing an HTTP/2 connection before its keep-alive timeoutPosiblemente ocupada @jiahaoliang la tomó hace 27 días. AbiertoC-feature
Dificultad 5/5 Más de una semana Aptitud para principiantes 35/100
hyperium/hyper#4186 · 1 comentario ·
Los mantenedores suelen responder en 2 días
Todos los issues de hyperium/hyper
Issues similares
-
Dificultad 1/5 Menos de una hora Aptitud para principiantes 95/100
Los mantenedores suelen responder en 1 día
-
Markdown Preview Fonts Don't Show Selected OptionPosiblemente ocupada @RadhiRasho la tomó hoy. Abiertostate:needs triage
Dificultad 2/5 1-3 horas Aptitud para principiantes 61/100
zed-industries/zed#65300 · 1 comentario ·
Los mantenedores suelen responder en 1 día
-
Dificultad 2/5 1-3 horas Aptitud para principiantes 76/100
Los mantenedores suelen responder en 1 día
-
Add collect method to DataFrameAbiertoenhancement
Dificultad 2/5 1-3 horas Aptitud para principiantes 68/100
Los mantenedores suelen responder en 1 día
-
Dificultad 2/5 1-3 horas Aptitud para principiantes 82/100
Los mantenedores suelen responder en 1 día