Timeout not always respected

[johan-bjareholt]

I have an application where the request times out way too late. I've also seen cases where the request succeeds, but it does so way past the timeout specified, but I have not yet been able to reproduce that with a minimal example.

In the example below, I make a request with a timeout of 2 seconds, but the request doesn't time out until after 4.7 seconds.

client

use std::time::Instant;

fn main() {
    let string = "abcde ".repeat(1000000);
    let req = ureq::post("http://127.0.0.1:1234/")
        .timeout(std::time::Duration::from_secs(2));
    let start = Instant::now();
    let result = req.send(string.as_bytes());
    match result {
        Ok(response) => {
            println!("request took: {}ms", start.elapsed().as_millis());
            println!("res2: {:?}", response);
            assert_eq!(response.status(), 200);
            let body = response.into_string().unwrap();
            assert_eq!("Hello, world!", body);
        }
        Err(err) => {
            println!("request took: {}ms", start.elapsed().as_millis());
            println!("request failed: {:?}", err);
        }
    };

}

server

fn main() {
    let server = tiny_http::Server::http("0.0.0.0:1234").unwrap();

    loop {
        // blocks until the next request is received
        let mut request = match server.recv() {
            Ok(rq) => rq,
            Err(e) => { println!("error: {}", e); break }
        };

        loop {
            let reader = request.as_reader();
            let mut buf = vec![0; 66000];
            let bytes_read = reader.read(&mut buf).unwrap();
            println!("Read {bytes_read} bytes");
            if bytes_read == 0 {
                break;
            }
            std::thread::sleep(std::time::Duration::from_millis(10));
        }

        let resp_body = "Hello, world!";
        let response = tiny_http::Response::new(
            tiny_http::StatusCode(200),
            vec![],
            resp_body.as_bytes(),
            Some(resp_body.len()),
            None);

        request.respond(response).unwrap();
    }
}

Client output

request took: 4733ms
request failed: Transport(Transport { kind: Io, message: None, url: Some(Url { scheme: "http", cannot_be_a_base: false, username: "", password: None, host: Some(Ipv4(127.0.0.1)), port: Some(1234), path: "/", query: None, fragment: None }), source: Some(Custom { kind: TimedOut, error: Transport(Transport { kind: Io, message: Some("Error encountered in the status line"), url: None, source: Some(Custom { kind: TimedOut, error: "timed out reading response" }) }) }) })

[johan-bjareholt]

It seems to have something to do with chunked transfer encoding, as the following fixes it

-let result = req.send(string.as_bytes());
+let result = req.send_bytes(string.as_bytes());

[algesten]

Can you wireshark what's going on the wire here?

[johan-bjareholt]

I was able to reproduce it with "Content-Length" too, but it was a bit trickier.

I have some "dirty fixes" for it on the following branch https://github.com/johan-bjareholt/ureq/commits/super-main/, once #688 is fixed I will try to clean them up and submit some PR:s.

[algesten]

#688 is in. Let's see it! :)

[johan-bjareholt]

@algesten It's unfortunately based on the #679 and doesn't cleanly apply without it. We should probably try to merge that first.