tide icon indicating copy to clipboard operation
tide copied to clipboard

async-h1 error

Open zhuxiujia opened this issue 4 years ago • 10 comments

async-h1 error(version : 0.11.0)

when i use command test

\Apache24\bin\ab.exe -c1000 -n10000 http://localhost:8080/test
2020-06-19T20:48:35.284913500+08:00 ERROR tide::server - async-h1 error  (C:\Users\mayn\.cargo\registry\src\github.com-1ecc6299db9ec823\tide-0.11.0\src\server.rs:309)
2020-06-19T20:48:35.286893200+08:00 ERROR tide::server - async-h1 error  (C:\Users\mayn\.cargo\registry\src\github.com-1ecc6299db9ec823\tide-0.11.0\src\server.rs:309)
2020-06-19T20:48:35.288917700+08:00 ERROR tide::server - async-h1 error  (C:\Users\mayn\.cargo\registry\src\github.com-1ecc6299db9ec823\tide-0.11.0\src\server.rs:309)
2020-06-19T20:48:35.291918100+08:00 ERROR tide::server - async-h1 error  (C:\Users\mayn\.cargo\registry\src\github.com-1ecc6299db9ec823\tide-0.11.0\src\server.rs:309)
2020-06-19T20:48:35.293902200+08:00 ERROR tide::server - async-h1 error  (C:\Users\mayn\.cargo\registry\src\github.com-1ecc6299db9ec823\tide-0.11.0\src\server.rs:309)
2020-06-19T20:48:35.295916700+08:00 ERROR tide::server - async-h1 error  (C:\Users\mayn\.cargo\registry\src\github.com-1ecc6299db9ec823\tide-0.11.0\src\server.rs:309)

zhuxiujia avatar Jun 19 '20 12:06 zhuxiujia

Does this happen on master as well?

jbr avatar Jun 19 '20 18:06 jbr

Does this happen on master as well?

yes

zhuxiujia avatar Jun 20 '20 02:06 zhuxiujia

Maybe this error message is caused by a client sending HTTP/1.0 requests:

[2020-09-21 23:34:32][ERROR] async-h1 error
    error: Unsupported HTTP version 1.0
(C:\Users\fw\.cargo\registry\src\mirrors.ustc.edu.cn-61ef6e0cd06fb9b8\tide-0.13.0\src\listener\tcp_listener.rs:66)

fortunewang avatar Sep 21 '20 15:09 fortunewang

This error message can be caused by haproxy too.

for example

haproxy.cfg file:

global
    maxconn         10000

defaults
    timeout client          30s
    timeout server          30s
    timeout connect         30s


frontend my-frontend
    bind 0.0.0.0:8100
    default_backend my-backend

backend my-backend
    server s1 127.0.0.1:8080 check

run the hello example, and run haproxy to backend :8080

$ cargo run --example hello 
$ haproxy -f haproxy.cfg

error log is

tide::listener::tcp_listener async-h1 error
    error Connection reset by peer (os error 54)

async-h1 does not support HTTP 1.0

$ cargo run --example hello $ curl --http1.0 http://127.0.0.1:8080/

tide::listener::tcp_listener async-h1 error
    error Unsupported HTTP version 1.0

fiag avatar Apr 09 '21 15:04 fiag

Support for HTTP/1.0 was added to async-h1 in https://github.com/http-rs/async-h1/pull/170. However I'm not sure how to enable it, perhaps we're missing a release?

cc/ @jbr do you know what the story here is right now?

yoshuawuyts avatar Apr 09 '21 15:04 yoshuawuyts

Tide isn't set up for 1.0 yet. We'd need to be able to configure a default host. That might be another listener configuration?

jbr avatar Apr 09 '21 15:04 jbr

I think we might also need an async-h1 release. It's on the 3.0 branch because I've been considering it experimental

jbr avatar Apr 09 '21 16:04 jbr

Also this issue from Nginx proxy requests, Nginx proxy_pass default uses HTTP/1.0

jht5945 avatar Jul 15 '21 16:07 jht5945

I configured nginx to mirror traffic to an application running tide and I ended up here. I solved it with this blog post https://brokenco.de/2021/02/16/async-h1-error-tide.html

gianarb avatar Feb 10 '22 16:02 gianarb

I'm also seeing this async-h1 error without details.

With trace enabled (RUST_LOG=trace cargo run), here is some of the events before/after.

[2022-12-20T19:42:18Z INFO  tide::log::middleware] --> Response sent
[2022-12-20T19:42:18Z TRACE async_h1::server] wrote 117 response bytes
[2022-12-20T19:42:18Z TRACE async_h1::server] discarded 0 unread request body bytes
[2022-12-20T19:42:18Z TRACE polling::kqueue] add: kqueue_fd=11, fd=15, ev=Event { key: 1, readable: true, writable: false }
[2022-12-20T19:42:18Z TRACE polling] Poller::notify()
[2022-12-20T19:42:18Z TRACE polling::kqueue] notify: kqueue_fd=11
[2022-12-20T19:42:18Z TRACE async_io::driver] block_on: sleep until notification
[2022-12-20T19:42:18Z TRACE polling::kqueue] new events: kqueue_fd=11, res=1
[2022-12-20T19:42:18Z TRACE async_io::reactor] process_timers: 0 ready wakers
[2022-12-20T19:42:18Z TRACE async_io::reactor] react: 0 ready wakers
[2022-12-20T19:42:18Z TRACE async_io::driver] block_on: waiting on I/O
[2022-12-20T19:42:18Z TRACE async_io::reactor] process_timers: 0 ready wakers
[2022-12-20T19:42:18Z TRACE polling] Poller::wait(_, Some(59.999926166s))
[2022-12-20T19:42:18Z TRACE polling::kqueue] wait: kqueue_fd=11, timeout=Some(59.999926166s)
[2022-12-20T19:42:18Z TRACE polling::kqueue] new events: kqueue_fd=11, res=1
[2022-12-20T19:42:18Z TRACE async_io::reactor] react: 1 ready wakers
[2022-12-20T19:42:18Z TRACE async_io::driver] block_on: stops hogging the reactor
[2022-12-20T19:42:18Z TRACE async_io::driver] main_loop: notified
[2022-12-20T19:42:18Z TRACE polling] Poller::notify()
[2022-12-20T19:42:18Z TRACE async_io::driver] main_loop: waiting on I/O
[2022-12-20T19:42:18Z TRACE polling::kqueue] notify: kqueue_fd=11
[2022-12-20T19:42:18Z TRACE async_io::reactor] process_timers: 0 ready wakers
[2022-12-20T19:42:18Z TRACE polling] Poller::wait(_, Some(59.999855416s))
[2022-12-20T19:42:18Z TRACE polling::kqueue] add: kqueue_fd=11, fd=15, ev=Event { key: 0, readable: false, writable: false }
[2022-12-20T19:42:18Z TRACE polling::kqueue] wait: kqueue_fd=11, timeout=Some(59.999855416s)
[2022-12-20T19:42:18Z TRACE async_io::driver] block_on: sleep until notification
[2022-12-20T19:42:18Z TRACE polling::kqueue] new events: kqueue_fd=11, res=1
[2022-12-20T19:42:18Z ERROR tide::listener::tcp_listener] async-h1 error
[2022-12-20T19:42:18Z TRACE async_io::reactor] process_timers: 0 ready wakers
[2022-12-20T19:42:18Z TRACE async_io::reactor] react: 0 ready wakers
[2022-12-20T19:42:18Z TRACE async_io::driver] main_loop: sleeping for 50 us
[2022-12-20T19:42:18Z TRACE async_io::driver] block_on: waiting on I/O
[2022-12-20T19:42:18Z TRACE async_io::reactor] process_timers: 0 ready wakers
[2022-12-20T19:42:18Z TRACE polling] Poller::wait(_, None)
[2022-12-20T19:42:18Z TRACE polling::kqueue] wait: kqueue_fd=11, timeout=None
[2022-12-20T19:42:18Z TRACE async_io::driver] main_loop: sleeping for 75 us
[2022-12-20T19:42:18Z TRACE async_io::driver] main_loop: sleeping for 100 us
[2022-12-20T19:42:18Z TRACE async_io::driver] main_loop: sleeping for 250 us
[2022-12-20T19:42:18Z TRACE polling::kqueue] new events: kqueue_fd=11, res=1

I use tide for handling incoming POST requests containing json. The server runs on localhost:9000. The server is not running on 0.0.0.0:9000.

The POST requests are being made by separate Rust process that uses reqwest to perform the POST requests.

Most of the POST requests are handled fine by tide, however several of these errors are printed.

I'm on macOS 12.6 Monterey.

PROMPT> cargo --version                                
cargo 1.65.0 (4bc8f24d3 2022-10-20)
PROMPT> rustc --version
rustc 1.65.0 (897e37553 2022-11-02)
PROMPT> uname -a
Darwin a.home 21.6.0 Darwin Kernel Version 21.6.0: Mon Aug 22 20:19:52 PDT 2022; root:xnu-8020.140.49~2/RELEASE_ARM64_T6000 arm64

I don't use nginx.

neoneye avatar Dec 20 '22 19:12 neoneye