-
-
Notifications
You must be signed in to change notification settings - Fork 1.7k
Closed as not planned
Labels
C-bugCategory: bug. Something is wrong. This is bad!Category: bug. Something is wrong. This is bad!
Description
Version
hyper 1.6.0
hyper-util 0.1.10 (where the crash occurs)
Platform
Linux archlinux 6.12.9-arch1-1 #1 SMP PREEMPT_DYNAMIC Fri, 10 Jan 2025 00:39:41 +0000 x86_64 GNU/Linux
Description
I tried this code:
#[tokio::main]
async fn main() {
tracing_subscriber::registry()
.with(tracing_subscriber::fmt::layer())
.init();
let override_default_registry =
tracing_subscriber::Registry::default().with(tracing_subscriber::fmt::layer());
async move {
tracing::info!("Starting request");
reqwest::Client::new()
.post("http://localhost:8787/ping")
.body("")
.send()
.await
.expect("HTTP request failed");
tracing::info!("Finished request");
}
.with_subscriber(override_default_registry)
.await;
}
What it looks like is that a span is created on 1 thread & then dropped on the blocking thread. I think this is a misuse of tracing given the note at https://docs.rs/tracing/latest/tracing/struct.Span.html
Note: The returned [EnteredSpan](https://docs.rs/tracing/latest/struct.EnteredSpan.html) guard does not implement Send. Dropping the guard will exit this span, and if the guard is sent to another thread and dropped there, that thread may never have entered this span. Thus, EnteredSpans should not be sent between threads.
I expected to see this happen: "Starting request" followed by "HTTP request failed" or "Finished request"
Instead, this happened:
2025-02-22T15:15:43.460425Z INFO mycrate: Starting request
2025-02-22T15:15:43.461298Z TRACE hyper_util::client::legacy::pool: checkout waiting for idle connection: ("http", localhost:8787)
2025-02-22T15:15:43.461428Z DEBUG reqwest::connect: starting new connection: http://localhost:8787/
2025-02-22T15:15:43.461486Z TRACE hyper_util::client::legacy::connect::http: Http::connect; scheme=Some("http"), host=Some("localhost"), port=Some(Port(8787))
thread 'tokio-runtime-worker' panicked at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tracing-subscriber-0.3.19/src/registry/sharded.rs:350:21:
tried to drop a ref to Id(1), but no such span exists!
stack backtrace:
0: rust_begin_unwind
at /rustc/4d91de4e48198da2e33413efdcd9cd2cc0c46688/library/std/src/panicking.rs:692:5
1: core::panicking::panic_fmt
at /rustc/4d91de4e48198da2e33413efdcd9cd2cc0c46688/library/core/src/panicking.rs:75:14
2: <tracing_subscriber::registry::sharded::Registry as tracing_core::subscriber::Subscriber>::try_close
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tracing-subscriber-0.3.19/src/registry/sharded.rs:350:21
3: <tracing_subscriber::layer::layered::Layered<L,S> as tracing_core::subscriber::Subscriber>::try_close
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tracing-subscriber-0.3.19/src/layer/layered.rs:186:12
4: tracing_core::dispatcher::Dispatch::try_close
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tracing-core-0.1.33/src/dispatcher.rs:703:9
5: <tracing_subscriber::registry::sharded::Registry as tracing_core::subscriber::Subscriber>::exit::{{closure}}
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tracing-subscriber-0.3.19/src/registry/sharded.rs:303:52
6: tracing_core::dispatcher::get_default
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tracing-core-0.1.33/src/dispatcher.rs:389:16
7: <tracing_subscriber::registry::sharded::Registry as tracing_core::subscriber::Subscriber>::exit
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tracing-subscriber-0.3.19/src/registry/sharded.rs:303:17
8: <tracing_subscriber::layer::layered::Layered<L,S> as tracing_core::subscriber::Subscriber>::exit
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tracing-subscriber-0.3.19/src/layer/layered.rs:162:9
9: tracing_core::dispatcher::Dispatch::exit
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tracing-core-0.1.33/src/dispatcher.rs:636:9
10: tracing::span::Span::do_exit
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tracing-0.1.41/src/span.rs:1054:13
11: <tracing::span::Entered as core::ops::drop::Drop>::drop
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tracing-0.1.41/src/span.rs:1562:9
12: core::ptr::drop_in_place<tracing::span::Entered>
at /home/me/.rustup/toolchains/stable-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/ptr/mod.rs:523:1
13: <hyper_util::client::legacy::connect::dns::GaiResolver as tower_service::Service<hyper_util::client::legacy::connect::dns::Name>>::call::{{closure}}
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/hyper-util-0.1.10/src/client/legacy/connect/dns.rs:127:9
14: <tokio::runtime::blocking::task::BlockingTask<T> as core::future::future::Future>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/blocking/task.rs:42:21
15: tokio::runtime::task::core::Core<T,S>::poll::{{closure}}
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/task/core.rs:331:17
16: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/loom/std/unsafe_cell.rs:16:9
17: tokio::runtime::task::core::Core<T,S>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/task/core.rs:320:13
18: tokio::runtime::task::harness::poll_future::{{closure}}
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/task/harness.rs:532:19
19: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
at /home/me/.rustup/toolchains/stable-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/panic/unwind_safe.rs:272:9
20: std::panicking::try::do_call
at /home/me/.rustup/toolchains/stable-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/panicking.rs:584:40
21: __rust_try
22: std::panicking::try
at /home/me/.rustup/toolchains/stable-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/panicking.rs:547:19
23: std::panic::catch_unwind
at /home/me/.rustup/toolchains/stable-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/panic.rs:358:14
24: tokio::runtime::task::harness::poll_future
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/task/harness.rs:520:18
25: tokio::runtime::task::harness::Harness<T,S>::poll_inner
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/task/harness.rs:209:27
26: tokio::runtime::task::harness::Harness<T,S>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/task/harness.rs:154:15
27: tokio::runtime::task::raw::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/task/raw.rs:271:5
28: tokio::runtime::task::raw::RawTask::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/task/raw.rs:201:18
29: tokio::runtime::task::UnownedTask<S>::run
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/task/mod.rs:486:9
30: tokio::runtime::blocking::pool::Task::run
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/blocking/pool.rs:161:9
31: tokio::runtime::blocking::pool::Inner::run
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/blocking/pool.rs:511:17
32: tokio::runtime::blocking::pool::Spawner::spawn_thread::{{closure}}
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/blocking/pool.rs:469:13
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
thread 'main' panicked at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/hyper-util-0.1.10/src/client/legacy/connect/dns.rs:150:21:
gai background task failed: JoinError::Panic(Id(33), "tried to drop a ref to Id(1), but no such span exists!", ...)
stack backtrace:
0: rust_begin_unwind
at /rustc/4d91de4e48198da2e33413efdcd9cd2cc0c46688/library/std/src/panicking.rs:692:5
1: core::panicking::panic_fmt
at /rustc/4d91de4e48198da2e33413efdcd9cd2cc0c46688/library/core/src/panicking.rs:75:14
2: <hyper_util::client::legacy::connect::dns::GaiFuture as core::future::future::Future>::poll::{{closure}}
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/hyper-util-0.1.10/src/client/legacy/connect/dns.rs:150:21
3: core::task::poll::Poll<T>::map
at /home/me/.rustup/toolchains/stable-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/task/poll.rs:54:43
4: <hyper_util::client::legacy::connect::dns::GaiFuture as core::future::future::Future>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/hyper-util-0.1.10/src/client/legacy/connect/dns.rs:143:9
5: <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-util-0.3.31/src/future/future/map.rs:55:37
6: <futures_util::future::future::Map<Fut,F> as core::future::future::Future>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-util-0.3.31/src/lib.rs:86:13
7: <core::pin::Pin<P> as core::future::future::Future>::poll
at /home/me/.rustup/toolchains/stable-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/future/future.rs:124:9
8: hyper_util::client::legacy::connect::dns::resolve::{{closure}}
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/hyper-util-0.1.10/src/client/legacy/connect/dns.rs:299:28
9: hyper_util::client::legacy::connect::http::HttpConnector<R>::call_async::{{closure}}
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/hyper-util-0.1.10/src/client/legacy/connect/http.rs:443:18
10: <hyper_util::client::legacy::connect::http::HttpConnector<R> as tower_service::Service<http::uri::Uri>>::call::{{closure}}
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/hyper-util-0.1.10/src/client/legacy/connect/http.rs:376:62
11: <core::pin::Pin<P> as core::future::future::Future>::poll
at /home/me/.rustup/toolchains/stable-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/future/future.rs:124:9
12: <hyper_util::client::legacy::connect::http::HttpConnecting<R> as core::future::future::Future>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/hyper-util-0.1.10/src/client/legacy/connect/http.rs:526:9
13: <hyper_rustls::connector::HttpsConnector<T> as tower_service::Service<http::uri::Uri>>::call::{{closure}}
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/hyper-rustls-0.27.5/src/connector.rs:75:54
14: <core::pin::Pin<P> as core::future::future::Future>::poll
at /home/me/.rustup/toolchains/stable-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/future/future.rs:124:9
15: reqwest::connect::ConnectorService::connect_with_maybe_proxy::{{closure}}
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/reqwest-0.12.12/src/connect.rs:468:41
16: reqwest::connect::with_timeout::{{closure}}
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/reqwest-0.12.12/src/connect.rs:606:11
17: <core::pin::Pin<P> as core::future::future::Future>::poll
at /home/me/.rustup/toolchains/stable-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/future/future.rs:124:9
18: <hyper_util::service::oneshot::Oneshot<S,Req> as core::future::future::Future>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/hyper-util-0.1.10/src/service/oneshot.rs:55:38
19: <F as futures_core::future::TryFuture>::try_poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-core-0.3.31/src/future.rs:92:9
20: <futures_util::future::try_future::into_future::IntoFuture<Fut> as core::future::future::Future>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-util-0.3.31/src/future/try_future/into_future.rs:34:9
21: <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-util-0.3.31/src/future/future/map.rs:55:37
22: <futures_util::future::future::Map<Fut,F> as core::future::future::Future>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-util-0.3.31/src/lib.rs:86:13
23: <futures_util::future::try_future::MapErr<Fut,F> as core::future::future::Future>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-util-0.3.31/src/lib.rs:86:13
24: <F as futures_core::future::TryFuture>::try_poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-core-0.3.31/src/future.rs:92:9
25: <futures_util::future::try_future::into_future::IntoFuture<Fut> as core::future::future::Future>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-util-0.3.31/src/future/try_future/into_future.rs:34:9
26: <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-util-0.3.31/src/future/future/map.rs:55:37
27: <futures_util::future::future::Map<Fut,F> as core::future::future::Future>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-util-0.3.31/src/lib.rs:86:13
28: <futures_util::future::try_future::MapOk<Fut,F> as core::future::future::Future>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-util-0.3.31/src/lib.rs:86:13
29: <F as futures_core::future::TryFuture>::try_poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-core-0.3.31/src/future.rs:92:9
30: <futures_util::future::try_future::try_flatten::TryFlatten<Fut,<Fut as futures_core::future::TryFuture>::Ok> as core::future::future::Future>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-util-0.3.31/src/future/try_future/try_flatten.rs:49:61
31: <futures_util::future::try_future::TryFlatten<Fut1,Fut2> as core::future::future::Future>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-util-0.3.31/src/lib.rs:86:13
32: <futures_util::future::try_future::AndThen<Fut1,Fut2,F> as core::future::future::Future>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-util-0.3.31/src/lib.rs:86:13
33: <futures_util::future::either::Either<A,B> as core::future::future::Future>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-util-0.3.31/src/future/either.rs:108:32
34: <hyper_util::common::lazy::Lazy<F,R> as core::future::future::Future>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/hyper-util-0.1.10/src/common/lazy.rs:64:20
35: futures_util::future::future::FutureExt::poll_unpin
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-util-0.3.31/src/future/future/mod.rs:558:9
36: <futures_util::future::select::Select<A,B> as core::future::future::Future>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-util-0.3.31/src/future/select.rs:118:35
37: hyper_util::client::legacy::client::Client<C,B>::one_connection_for::{{closure}}
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/hyper-util-0.1.10/src/client/legacy/client.rs:445:49
38: hyper_util::client::legacy::client::Client<C,B>::connection_for::{{closure}}
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/hyper-util-0.1.10/src/client/legacy/client.rs:396:61
39: hyper_util::client::legacy::client::Client<C,B>::try_send_request::{{closure}}
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/hyper-util-0.1.10/src/client/legacy/client.rs:280:14
40: hyper_util::client::legacy::client::Client<C,B>::send_request::{{closure}}
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/hyper-util-0.1.10/src/client/legacy/client.rs:248:70
41: <hyper_util::client::legacy::client::ResponseFuture as core::future::future::Future>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/hyper-util-0.1.10/src/client/legacy/client.rs:714:9
42: <reqwest::async_impl::client::PendingRequest as core::future::future::Future>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/reqwest-0.12.12/src/async_impl/client.rs:2673:53
43: <reqwest::async_impl::client::Pending as core::future::future::Future>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/reqwest-0.12.12/src/async_impl/client.rs:2643:51
44: mycrate::main::{{closure}}::{{closure}}
at ./mycrate/src/main.rs:732:14
45: <tracing::instrument::WithDispatch<T> as core::future::future::Future>::poll
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tracing-0.1.41/src/instrument.rs:388:9
46: mycrate::main::{{closure}}
at ./mycrate/src/main.rs:737:6
47: tokio::runtime::park::CachedParkThread::block_on::{{closure}}
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/park.rs:284:63
48: tokio::runtime::coop::with_budget
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/coop.rs:107:5
49: tokio::runtime::coop::budget
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/coop.rs:73:5
50: tokio::runtime::park::CachedParkThread::block_on
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/park.rs:284:31
51: tokio::runtime::context::blocking::BlockingRegionGuard::block_on
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/context/blocking.rs:66:9
52: tokio::runtime::scheduler::multi_thread::MultiThread::block_on::{{closure}}
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/scheduler/multi_thread/mod.rs:87:13
53: tokio::runtime::context::runtime::enter_runtime
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/context/runtime.rs:65:16
54: tokio::runtime::scheduler::multi_thread::MultiThread::block_on
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/scheduler/multi_thread/mod.rs:86:9
55: tokio::runtime::runtime::Runtime::block_on_inner
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/runtime.rs:370:45
56: tokio::runtime::runtime::Runtime::block_on
at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/runtime.rs:342:13
57: mycrate::main
at ./mycrate/src/main.rs:726:5
58: core::ops::function::FnOnce::call_once
at /home/me/.rustup/toolchains/stable-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/ops/function.rs:250:5
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
2025-02-22T15:15:43.779563Z TRACE hyper_util::client::legacy::pool: checkout dropped for ("http", localhost:8787)
Metadata
Metadata
Assignees
Labels
C-bugCategory: bug. Something is wrong. This is bad!Category: bug. Something is wrong. This is bad!