Missing error when reading stream of data out of an interrupted chunked-encoded request #3253

Lupus · 2023-06-16T16:07:55Z

Version
hyper 0.14.26
tokio 1.28.1

Platform
Linux my-hostname 5.10.0-18-amd64 #1 SMP Debian 5.10.140-1 (2022-09-02) x86_64 GNU/Linux

Description

Error is not propagated via stream in some cases when client drops the connection during chunked-encoding stream.

I tried this code:

use futures_util::stream::StreamExt;
use hyper::service::{make_service_fn, service_fn};
use hyper::{Body, Request, Response, Server};
use tokio::sync::mpsc;
use tokio::time::{sleep, Duration};

async fn echo(mut req: Request<Body>) -> Result<Response<Body>, hyper::Error> {
    println!("reading body!");

    // Create a channel to communicate between the reading and responding tasks
    let (tx, rx) = mpsc::channel::<Vec<u8>>(1);

    // Spawn a task to read the request body and discard it
    tokio::spawn(async move {
        while let Some(maybe_chunk) = req.body_mut().next().await {
            match maybe_chunk {
                Ok(chunk) => {
                    // Uncomment me!
                    // sleep(Duration::from_millis(100)).await;
                    let _ = tx.send(chunk.to_vec()).await;
                }

                Err(err) => {
                    println!("Got error: {}", err);
                }
            }
        }
        println!("finished reading body!");
    });

    // Create a response with a data stream that is filled by the reading task
    let stream = tokio_stream::wrappers::ReceiverStream::new(rx);
    let response = Response::builder()
        .body(Body::wrap_stream(stream.map(Result::<_, hyper::Error>::Ok)))
        .expect("Failed to build response");

    Ok(response)
}

#[tokio::main]
async fn main() -> Result<(), Box<dyn std::error::Error + Send + Sync>> {
    let addr = ([0, 0, 0, 0], 3000).into();

    let service = make_service_fn(|_| async { Ok::<_, hyper::Error>(service_fn(echo)) });

    let server = Server::bind(&addr).serve(service);

    println!("Listening on http://{}", addr);

    server.await?;

    Ok(())
}

Cargo.toml dependencies:

[dependencies]
tokio = { version = "1", features = ["full"] }
hyper = { version="0.14", features=["full"] }
http = "*"
futures = "*"
futures-util = "0.3.28"
tokio-stream = "0.1.14"

Service above is an echo-server, which sends back the stream of data that it receives. To get the repro, please launch the service, and on another terminal start the "endless" curl command like this:

$ cat /dev/zero | curl -XPOST http://127.0.0.1:3000/ -H "Transfer-Encoding: chunked" -T - -o /dev/null

It will read /dev/zero, pipe it to curl, which will send it as data stream with chunked transfer encoding, sending the output stream to /dev/null.

After some time, terminate curl with Ctrl+C. Service reports the error on the stream as expected, terminal output will look like this:

Listening on http://0.0.0.0:3000
reading body!
Got error: error reading a body from connection: Connection reset by peer (os error 104)
finished reading body!

But if we uncomment the sleep line, and repeat the experiment, there will be no error, as indicated by service output:

Listening on http://0.0.0.0:3000
reading body!
finished reading body!

I'm observing this weird behavior on a larger codebase that does approximately the same as sample server presented above.

One more interesting observation, even when sleep is in place, it does not repro (i.e. error is reported properly) with this netcat:

$ echo -ne "GET /echo-buffer HTTP/1.1\r\nHost: localhost\r\nConnection: close\r\nTransfer-Encoding: chunked\r\n\r\n6\r\naabbcc" | nc localhos
t 3000; echo
HTTP/1.1 200 OK
transfer-encoding: chunked
date: Fri, 16 Jun 2023 16:04:58 GMT

6
aabbcc
^C

My larger codebase also works as expected with netcat. Is there a race somewhere?

The text was updated successfully, but these errors were encountered:

seanmonstar · 2023-06-16T18:44:01Z

I've been playing around with the demo on my own machine, and even without the timeout, I see what you're describing. When I turn on tracing, I see that the connection task encounters a write error, because the socket is closed, and then that closes up the task.

I would guess that it depends on what exact option the connection task is doing when you kill the curl process: if it was trying to read, it will see a read error, if it was trying to write, it will log it and close up.

So, I'd say that at least the problem is that when the connection task is closing, the request body sender (the internal side giving you the request body bytes) doesn't notice it should send a final error item.

Lupus · 2023-06-16T20:28:16Z

My problem domain is storage systems, and when user uploads a file of unknown length (via chunked encoding) it is really important to get reliable information on how stream has ended. With current state of things, drop of the client might result in new object being successfully uploaded to storage system with only partial content.

seanmonstar · 2023-06-19T15:18:41Z

I've got a fix pending in #3256, I'll backport it to 0.14 after it's good in master.

If a connection has any error besides reading, a streaming body sometimes wouldn't be notified. This change makes it so that when a connection task is closing because of any error, an existing body channel is also notified. Closes #3253

Lupus · 2023-06-20T05:33:22Z

Thanks for quick turnaround @seanmonstar !

If a connection has any error besides reading, a streaming body sometimes wouldn't be notified. This change makes it so that when a connection task is closing because of any error, an existing body channel is also notified. Closes #3253

Includes a lightly-modified version of hyper-util's `TokioIo` utility. Hyper changes: v1.0.0-rc.4 (2023-07-10) Bug Fixes http1: http1 server graceful shutdown fix (#3261) ([f4b51300](hyperium/hyper@f4b5130)) send error on Incoming body when connection errors (#3256) ([52f19259](hyperium/hyper@52f1925), closes hyperium/hyper#3253) properly end chunked bodies when it was known to be empty (#3254) ([fec64cf0](hyperium/hyper@fec64cf), closes hyperium/hyper#3252) Features client: Make clients able to use non-Send executor (#3184) ([d977f209](hyperium/hyper@d977f20), closes hyperium/hyper#3017) rt: replace IO traits with hyper::rt ones (#3230) ([f9f65b7a](hyperium/hyper@f9f65b7), closes hyperium/hyper#3110) add downcast on Sleep trait (#3125) ([d92d3917](hyperium/hyper@d92d391), closes hyperium/hyper#3027) service: change Service::call to take &self (#3223) ([d894439e](hyperium/hyper@d894439), closes hyperium/hyper#3040) Breaking Changes Any IO transport type provided must not implement hyper::rt::{Read, Write} instead of tokio::io traits. You can grab a helper type from hyper-util to wrap Tokio types, or implement the traits yourself, if it's a custom type. ([f9f65b7a](hyperium/hyper@f9f65b7)) client::conn::http2 types now use another generic for an Executor. Code that names Connection needs to include the additional generic parameter. ([d977f209](hyperium/hyper@d977f20)) The Service::call function no longer takes a mutable reference to self. The FnMut trait bound on the service::util::service_fn function and the trait bound on the impl for the ServiceFn struct were changed from FnMut to Fn.

…ium#3256) If a connection has any error besides reading, a streaming body sometimes wouldn't be notified. This change makes it so that when a connection task is closing because of any error, an existing body channel is also notified. Closes hyperium#3253

…ium#3256) If a connection has any error besides reading, a streaming body sometimes wouldn't be notified. This change makes it so that when a connection task is closing because of any error, an existing body channel is also notified. Closes hyperium#3253 Signed-off-by: Sven Pfennig <s.pfennig@reply.de>

Lupus added the C-bug Category: bug. Something is wrong. This is bad! label Jun 16, 2023

seanmonstar added A-http1 Area: HTTP/1 specific. E-medium Effort: medium. Some knowledge of how hyper internal works would be useful. labels Jun 16, 2023

seanmonstar mentioned this issue Jun 19, 2023

fix(http1): send error on Incoming body when connection errors #3256

Merged

seanmonstar closed this as completed in #3256 Jun 19, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Missing error when reading stream of data out of an interrupted chunked-encoded request #3253

Missing error when reading stream of data out of an interrupted chunked-encoded request #3253

Lupus commented Jun 16, 2023

seanmonstar commented Jun 16, 2023

Lupus commented Jun 16, 2023 •

edited

seanmonstar commented Jun 19, 2023

Lupus commented Jun 20, 2023

Missing error when reading stream of data out of an interrupted chunked-encoded request #3253

Missing error when reading stream of data out of an interrupted chunked-encoded request #3253

Comments

Lupus commented Jun 16, 2023

seanmonstar commented Jun 16, 2023

Lupus commented Jun 16, 2023 • edited

seanmonstar commented Jun 19, 2023

Lupus commented Jun 20, 2023

Lupus commented Jun 16, 2023 •

edited