tracing span not closed after response received

[YuKi74]

#[tokio::main]
async fn main() -> anyhow::Result<()> {
    tracing_subscriber::fmt()
        .with_env_filter(EnvFilter::from_str(&format!(
            "off,{}=trace",
            env!("CARGO_BIN_NAME").replace("-", "_")
        ))?)
        .with_span_events(FmtSpan::NEW | FmtSpan::CLOSE)
        .init();
    let client = reqwest::Client::new();
    client.get("https://google.com").send().instrument(debug_span!("request")).await?;
    // drop(client);
    tokio::time::sleep(Duration::from_secs(3)).await;
    Ok(())
}

When running the code above, the span close event is not printed until the program terminates, with the time.idle exceeding 3 seconds. If the comment for drop(client) is removed, the span close event will be printed immediately after the request is completed, with the time.idle less than 1 second.

Is this a bug with reqwest or tracing?

[dmackinn]

You didn't list the crate versions but I wasn't able to reproduce this issue. Here's the contents of my cargo.toml

[package]
name = "reqwest-test"
version = "0.1.0"
edition = "2024"

[dependencies]
anyhow = "1.0.100"
reqwest = "0.12.23"
tokio = { version = "1.47.1", features = ["full"] }
tracing = "0.1.41"
tracing-subscriber = { version = "0.3.20", features = ["env-filter"] }

Tested this with rust 1.89 on macOS.

[YuKi74]

Thank you for your reply.
My crate versions and rust version are the same with yours, but I have some additional dependencies, if I remove those additional dependencies, the issue won't occur.
I added these dependencies one by one and identified the one that caused the problem, it's kube.
Here's the content of my Cargo.toml

[package]
name = "reqwest-test"
version = "0.1.0"
edition = "2024"

[dependencies]
anyhow = "1.0.100"
reqwest = "0.12.23"
tokio = { version = "1.47.1", features = ["full"] }
tracing = "0.1.41"
tracing-subscriber = { version = "0.3.20", features = ["env-filter"] }
kube = "2.0.1"
k8s-openapi = { version = "0.26.0", features = ["latest"] }

The k8s-openapi crate is not relevant to this problem, but it's necessary to enable its latest feature, otherwise build will failed.

I think this issue might be caused by some features that were indirectly enabled by kube, I haven't yet find out what it is.

[YuKi74]

Thank you for your reply. My crate versions and rust version are the same with yours, but I have some additional dependencies, if I remove those additional dependencies, the issue won't occur. I added these dependencies one by one and identified the one that caused the problem, it's kube. Here's the content of my Cargo.toml

[package]
name = "reqwest-test"
version = "0.1.0"
edition = "2024"

[dependencies]
anyhow = "1.0.100"
reqwest = "0.12.23"
tokio = { version = "1.47.1", features = ["full"] }
tracing = "0.1.41"
tracing-subscriber = { version = "0.3.20", features = ["env-filter"] }
kube = "2.0.1"
k8s-openapi = { version = "0.26.0", features = ["latest"] }
The k8s-openapi crate is not relevant to this problem, but it's necessary to enable its latest feature, otherwise build will failed.

I think this issue might be caused by some features that were indirectly enabled by kube, I haven't yet find out what it is.

After some tests, I finally found it's hyper-util's tracing feature. Here's the Cargo.toml

[package]
name = "reqwest-test"
version = "0.1.0"
edition = "2024"

[dependencies]
anyhow = "1.0.100"
reqwest = "0.12.23"
tokio = { version = "1.47.1", features = ["full"] }
tracing = "0.1.41"
tracing-subscriber = { version = "0.3.20", features = ["env-filter"] }
hyper-util = { version = "0.1.17", features = ["tracing"] }