hyper: Client hang with hyper 0.14 (tokio, async-std)

Context: we are investigating if upgrading hyper to 0.13 fixes #2306, and it seems not.

Steps to reproduce

Prerequisites:

You need to run a docker daemon. The default setting should be ok as the reproducer uses Unix domain sockets.
ulimit -n 65536 (increasing open file limits)

clone https://github.com/pandaman64/hyper-hang-tokio
cargo run

Expected behavior

The program should run until the system resource is exhausted.

Actual behavior

It hangs after indeterminate iterations.

Log (last several iterations)

435
Oct 27 16:48:35.474 DEBUG hyper::client::pool: reuse idle connection for ("unix", 2f7661722f72756e2f646f636b65722e736f636b:0)
Oct 27 16:48:35.474 DEBUG hyper::proto::h1::io: flushed 76 bytes
Oct 27 16:48:35.475 DEBUG hyper::proto::h1::io: read 110 bytes
Oct 27 16:48:35.475 DEBUG hyper::proto::h1::io: parsed 3 headers
Oct 27 16:48:35.475 DEBUG hyper::proto::h1::conn: incoming body is empty
Oct 27 16:48:35.476 DEBUG hyper::client::pool: reuse idle connection for ("unix", 2f7661722f72756e2f646f636b65722e736f636b:0)
Oct 27 16:48:35.477 DEBUG hyper::proto::h1::io: flushed 75 bytes
Oct 27 16:48:35.477 DEBUG hyper::client::pool: pooling idle connection for ("unix", 2f7661722f72756e2f646f636b65722e736f636b:0)
Oct 27 16:48:35.478 DEBUG hyper::proto::h1::io: read 211 bytes
Oct 27 16:48:35.478 DEBUG hyper::proto::h1::io: parsed 7 headers
Oct 27 16:48:35.478 DEBUG hyper::proto::h1::conn: incoming body is chunked encoding
436
Oct 27 16:48:35.478 DEBUG hyper::client::pool: reuse idle connection for ("unix", 2f7661722f72756e2f646f636b65722e736f636b:0)
Oct 27 16:48:35.479 DEBUG hyper::proto::h1::io: flushed 76 bytes
Oct 27 16:48:35.479 DEBUG hyper::proto::h1::io: read 110 bytes
Oct 27 16:48:35.479 DEBUG hyper::proto::h1::io: parsed 3 headers
Oct 27 16:48:35.479 DEBUG hyper::proto::h1::conn: incoming body is empty
Oct 27 16:48:35.480 DEBUG hyper::client::pool: reuse idle connection for ("unix", 2f7661722f72756e2f646f636b65722e736f636b:0)
Oct 27 16:48:35.480 DEBUG hyper::client::pool: pooling idle connection for ("unix", 2f7661722f72756e2f646f636b65722e736f636b:0)
Oct 27 16:48:35.481 DEBUG hyper::proto::h1::io: flushed 75 bytes
Oct 27 16:48:35.481 DEBUG hyper::proto::h1::io: read 211 bytes
Oct 27 16:48:35.481 DEBUG hyper::proto::h1::io: parsed 7 headers
Oct 27 16:48:35.481 DEBUG hyper::proto::h1::conn: incoming body is chunked encoding
437
Oct 27 16:48:35.482 DEBUG hyper::client::pool: reuse idle connection for ("unix", 2f7661722f72756e2f646f636b65722e736f636b:0)
Oct 27 16:48:35.482 DEBUG hyper::proto::h1::io: flushed 76 bytes
Oct 27 16:48:35.482 DEBUG hyper::proto::h1::io: read 110 bytes
Oct 27 16:48:35.482 DEBUG hyper::proto::h1::io: parsed 3 headers
Oct 27 16:48:35.483 DEBUG hyper::proto::h1::conn: incoming body is empty
Oct 27 16:48:35.483 DEBUG hyper::client::pool: reuse idle connection for ("unix", 2f7661722f72756e2f646f636b65722e736f636b:0)
Oct 27 16:48:35.484 DEBUG hyper::proto::h1::io: flushed 75 bytes
Oct 27 16:48:35.484 DEBUG hyper::client::pool: pooling idle connection for ("unix", 2f7661722f72756e2f646f636b65722e736f636b:0)
Oct 27 16:48:35.484 DEBUG hyper::proto::h1::io: read 211 bytes
Oct 27 16:48:35.484 DEBUG hyper::proto::h1::io: parsed 7 headers
Oct 27 16:48:35.484 DEBUG hyper::proto::h1::conn: incoming body is chunked encoding
Oct 27 16:48:35.484 DEBUG hyper::client::pool: pooling idle connection for ("unix", 2f7661722f72756e2f646f636b65722e736f636b:0)
438
Oct 27 16:48:35.485 DEBUG hyper::client::pool: reuse idle connection for ("unix", 2f7661722f72756e2f646f636b65722e736f636b:0)

Reproducer

I’m pasting the reproducer here for ease of reference.

use futures::prelude::*;
fn main() {
    // env_logger::Builder::from_default_env()
    //     .target(env_logger::fmt::Target::Stdout)
    //     .init();
    tracing_subscriber::fmt::init();

    let mut runtime = tokio::runtime::Builder::new()
        .threaded_scheduler()
        .enable_all()
        .build()
        .unwrap();
    let client: hyper::Client<hyperlocal::UnixConnector> =
        hyper::Client::builder().build(hyperlocal::UnixConnector);
    for i in 0.. {
        println!("{}", i);
        let res = runtime
            .block_on(async {
                let _resp = client
                    .get(hyperlocal::Uri::new("/var/run/docker.sock", "//events?").into())
                    .await;
                client
                    .get(hyperlocal::Uri::new("/var/run/docker.sock", "/events?").into())
                    .await
            })
            .unwrap();
        runtime.spawn(res.into_body().into_future());
    }
}

Notes

Double slashes in the uri ("//events?") does matter. We need two requests with different uris.
I suspect this is a hyper issue because we can reproduce the same hang both with tokio and async-std:
- tokio reproducer: https://github.com/pandaman64/hyper-hang-tokio
- async-std reproducer: https://github.com/pandaman64/hyper-hang-async-std

About this issue

Original URL
State: open
Created 4 years ago
Reactions: 6
Comments: 19 (4 by maintainers)

Links to this issue

Maybe fix room joins (!453) · Merge requests · Famedly / Conduit · GitLab

Commits related to this issue

workaround for hyperium/hyper#2312 — committed to nyuichi/dockworker by nyuichi 4 years ago
workaround for hyperium/hyper#2312 — committed to nyuichi/dockworker by nyuichi 4 years ago
fix(judger): workaround for hyper issue See: https://github.com/hyperium/hyper/issues/2312 — committed to BUAA-SE-Compiling/rurikawa by lynzrand 4 years ago
workaround for hyperium/hyper#2312 — committed to Idein/dockworker by nyuichi 4 years ago
Maybe fix room joins This is a workaround for https://github.com/hyperium/hyper/issues/2312 — committed to virto-network/conduit by timokoesters a year ago
work around hang issue in hyper As indicated in #1549, there is an issue with hyper (the underlying layer used by reqwest) that hangs in some cases on connection pools. This PR uses a commonly discus... — committed to demoray/azure-sdk-for-rust by deleted user 6 months ago
work around hang issue in hyper (#1550) As indicated in #1549, there is an issue with hyper (the underlying layer used by reqwest) that hangs in some cases on connection pools. This PR uses a commo... — committed to Azure/azure-sdk-for-rust by demoray 6 months ago
fix(client): Fix deadlock; candidate solution to #2312. — committed to jevolk/hyper by jevolk 3 months ago
fix(client): Fix deadlock; candidate solution to #2312. — committed to girlbossceo/hyper by jevolk 3 months ago
client: Set pool_max_idle_per_host to 0 on hyper::Client To work around https://github.com/hyperium/hyper/issues/2312 — committed to matrix-org/matrix-rust-sdk by andybalaam 3 months ago

Most upvoted comments

Another coworker reported that adding

    .pool_idle_timeout(std::time::Duration::from_millis(0))
    .pool_max_idle_per_host(0)

to the client builder is a work around.

pandaman64 on Nov 5, 2020

I just wasted my entire day because of this. This also affects reqwest obviously because it implements hyper underneath. How I encountered this bug…

    std::thread::spawn(move || {
        let a = tokio::runtime::Builder::new_multi_thread().build().unwrap();
        a.block_on(
            async {
                // reqwest call here then `.await`
            }
        );
    }).join().expect("Thread panicked")

But, .pool_max_idle_per_host(0) did the trick of workaround

kpark-hrp on Feb 1, 2023

I do see the hang with the async-std version after a couple hundred iterations, yeah.

sfackler on Oct 28, 2020

We’ve been hit by https://github.com/hyperium/hyper/issues/2312 yesterday (and I think once before) and tracked it down to this. The example program from https://github.com/hyperium/hyper/issues/2312 can easily show the problem.

We’re using pool_max_idle_per_host(0) while no better solution exists 😭

arthurprs on Dec 13, 2022

I’m experiencing a similar issue.

In an application I’m working on, I’m sending multiple requests (from a shared reqwest Client instance) from a future (which is launched through handle.block_on(...) within a worker thread). The first three HTTP requests reproducibly succeed, while the fourth request to the same host reproducibly fails.

According to a Wireshark trace, the fourth request is never sent to the network. I added debug logging deep down into hyper, but didn’t really find the source of the issue. I suspected that it’s related to connection reuse (because the first three requests work), and just as described above, setting .pool_max_idle_per_host(0) on the client makes it work again.

In case it’s useful, here are a few screenshots from my debugging session. The reqwest library delegates the HTTP request to hyper:

When looking at the program using tokio-console, I noticed that the task 72 (with Hyper’s Exec::execute method) is reported as having lost its waker. I don’t know if this could be relevant.

threema-danilo on Dec 6, 2021

Update:

This hang does reproduce with hyper 0.14
- reproduction with hyper 0.14 + Tokio 1.2 (https://github.com/pandaman64/hyper-hang-tokio)
- reproduction with hyper 0.14 + async-std 1.6 (https://github.com/pandaman64/hyper-hang-async-std)
  - It seems that you need to wait longer with this version
To work around this hang, .pool_max_idle_per_host(0) is enough
- I suspect there is something wrong with the pool implementation, but I couldn’t find it.

pandaman64 on Feb 12, 2021