search

hyperium / hyper

An HTTP library for Rust
https://hyper.rs
MIT License
14.58k stars 1.6k forks source link

Graceful shutdown never finishes when there is opened connection #1885

Closed misos1 closed 8 months ago

misos1 commented 5 years ago

This will never exit. Something similar is doing google chrome. It creates two connections but sends request only to one of them. Fortunately chrome has some timeout so it closes that unused connection after some time and only after that finishes also hyper graceful shutdown.

When is this program run with argument then after one second it creates tcp connection and waits indefinitely without closing or dropping TcpStream. When is called without arguments then hyper server with graceful shutdown is created, it will run itself with argument so it will create child client process and never waits for child termination, then after 10 seconds is initiated graceful shutdown.

extern crate hyper;
extern crate futures;
extern crate tokio_tcp;
extern crate log;
extern crate pretty_env_logger;

use hyper::{Body, Response, Server};
use hyper::rt::Future;
use hyper::service::service_fn_ok;
use hyper::server::conn::AddrStream;
use log::info;

fn main()
{
    let addr = ([127, 0, 0, 1], 3000).into();

    if std::env::args().nth(1).is_some()
    {
        std::thread::sleep_ms(1000);
        std::mem::forget(tokio_tcp::TcpStream::connect(&addr).wait().unwrap());
        loop {std::thread::sleep_ms(1000);}
    } 

    std::env::set_var("RUST_LOG", "debug");
    pretty_env_logger::init_timed();

    let (tx, rx) = futures::sync::oneshot::channel::<()>();

    let server = Server::bind(&addr)
        .serve(hyper::service::make_service_fn(|addr: &AddrStream|
        {
            let addr = addr.remote_addr();
            info!("connection {}", addr);
            service_fn_ok(move |_|
            {
                info!("request {}", addr);
                Response::new(Body::from("Hello, World!"))
            })
        }))
        .with_graceful_shutdown(rx)
        .map_err(|e| eprintln!("server error: {}", e));

    std::process::Command::new("cargo").args(&["run", "client"]).spawn().unwrap();

    std::thread::spawn(move ||
    {
        std::thread::sleep_ms(10000);
        tx.send(()).unwrap();
        info!("shutting down");
    });

    hyper::rt::run(server);
    info!("quiting");
}

Possible output:

    Finished dev [unoptimized + debuginfo] target(s) in 5.10s
     Running `target/debug/test`
 2019-07-28 21:30:00 DEBUG tokio_reactor > adding I/O source: 0
 2019-07-28 21:30:00 DEBUG tokio_reactor::registration > scheduling Read for: 0
    Finished dev [unoptimized + debuginfo] target(s) in 0.06s
     Running `target/debug/test client`
 2019-07-28 21:30:02 INFO  test                        > connection 127.0.0.1:65114
 2019-07-28 21:30:02 DEBUG tokio_reactor::registration > scheduling Read for: 0
 2019-07-28 21:30:02 DEBUG tokio_reactor               > adding I/O source: 4194305
 2019-07-28 21:30:02 DEBUG tokio_reactor::registration > scheduling Read for: 1
 2019-07-28 21:30:10 INFO  test                        > shutting down
 2019-07-28 21:30:10 DEBUG hyper::server::shutdown     > signal received, starting graceful shutdown
 2019-07-28 21:30:10 DEBUG tokio_reactor               > dropping I/O source: 0
 2019-07-28 21:30:10 DEBUG tokio_reactor::registration > scheduling Read for: 1
 2019-07-28 21:30:10 DEBUG tokio_reactor::registration > scheduling Read for: 1
ghost commented 4 years ago

I hit the same issue (via the warp crate). It seems there was still a connection left.

Log 
sh-5.0$ RUST_LOG=trace ./local-dir-server --address 192.168.2.118:8080
Listening on 192.168.2.118:8080 to share "."...
[2020-07-22T11:32:47Z TRACE mio::poll] registering with poller
[2020-07-22T11:32:47Z TRACE mio::poll] registering with poller
[2020-07-22T11:33:26Z TRACE mio::poll] registering with poller
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] Conn::read_head
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] read 445 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::role] Request.parse([Header; 100], [u8; 445])
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::role] Request.parse Complete(445)
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] parsed 7 headers
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::conn] incoming body is empty
[2020-07-22T11:33:26Z TRACE warp::filters::method] method::GET?: GET
[2020-07-22T11:33:26Z TRACE warp::filters::fs] dir? base=".", route="local-dir-server.exe"
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Init, keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE warp::filters::fs] dir: "./local-dir-server.exe"
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Init, keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Init, keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::role] Server::encode status=200, body=Some(Unknown), req_method=Some(GET)
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 189 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(2007552), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1999360), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1991168), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1982976), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1974784), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1966592), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1958400), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1950208), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1942016), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1933824), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1925632), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1917440), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1909248), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1901056), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1892864), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1884672), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1876480), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1868288), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 1788 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 128480 bytes
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 804 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1737216), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1737216), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1729024), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1720832), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1712640), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1704448), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1696256), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1688064), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1679872), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1671680), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1663488), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1655296), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1647104), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1638912), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1630720), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1622528), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1614336), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z DEBUG hyper::proto::h1::io] flushed 4796 bytes
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:26Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 126276 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1483264), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1483264), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1475072), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1466880), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1458688), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1450496), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1442304), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1434112), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1425920), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1417728), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 908 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 130164 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1286656), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1286656), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1278464), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1270272), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1262080), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1253888), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1245696), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1237504), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1229312), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 5212 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 125860 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1098240), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1098240), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1090048), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1081856), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1073664), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1065472), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1057280), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1049088), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1040896), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1032704), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1024512), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1016320), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(1008128), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(999936), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(991744), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(983552), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(975360), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(967168), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 28 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 131044 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(836096), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(836096), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(827904), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(819712), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(811520), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(803328), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(795136), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(786944), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(778752), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(770560), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(762368), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(754176), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(745984), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(737792), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(729600), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(721408), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(713216), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z DEBUG hyper::proto::h1::io] flushed 3036 bytes
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:27Z TRACE mio::poll] registering with poller
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] Conn::read_head
[2020-07-22T11:33:27Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: Init, writing: Init, keep_alive: Busy }
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 128036 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(582144), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(582144), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(573952), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(565760), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(557568), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(549376), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(541184), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(532992), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(524800), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(516608), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(508416), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(500224), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(492032), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(483840), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(475648), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(467456), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(459264), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 6044 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 125028 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(328192), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(328192), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(320000), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(311808), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(303616), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(295424), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(287232), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(279040), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(270848), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(262656), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(254464), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(246272), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(238080), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(229888), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(221696), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(213504), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(205312), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(197120), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 860 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 130212 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(66048), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(66048), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(57856), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(49664), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(41472), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(33280), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(25088), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(16896), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(8704), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 8192
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 8192 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: KeepAlive, writing: Body(Encoder { kind: Length(512), is_last: false }), keep_alive: Busy }
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::encode] sized write, len = 512
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::dispatch] no more write body allowed, user body is_end_stream = false
[2020-07-22T11:33:28Z DEBUG hyper::proto::h1::io] flushed 512 bytes
[2020-07-22T11:33:28Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: Init, writing: Init, keep_alive: Idle }
^C[2020-07-22T11:33:50Z TRACE mio::poll] deregistering handle with poller
[2020-07-22T11:33:50Z DEBUG hyper::server::shutdown] signal received, starting graceful shutdown
[2020-07-22T11:33:50Z TRACE mio::poll] deregistering handle with poller
[2020-07-22T11:33:50Z TRACE hyper::proto::h1::conn] disable_keep_alive; in-progress connection
[2020-07-22T11:33:50Z TRACE hyper::proto::h1::conn] disable_keep_alive; closing idle connection
[2020-07-22T11:33:50Z TRACE hyper::proto::h1::conn] Conn::read_head
[2020-07-22T11:33:50Z TRACE hyper::proto::h1::conn] State::close()
[2020-07-22T11:33:50Z TRACE hyper::proto::h1::conn] State::close_read()
[2020-07-22T11:33:50Z TRACE hyper::proto::h1::conn] State::close_write()
[2020-07-22T11:33:50Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: Init, writing: Init, keep_alive: Disabled }
[2020-07-22T11:33:50Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: Closed, writing: Closed, keep_alive: Disabled }
[2020-07-22T11:33:50Z TRACE hyper::proto::h1::conn] shut down IO complete
[2020-07-22T11:33:50Z TRACE mio::poll] deregistering handle with poller
^C^C^C^C^C^C^C^C^C^C^C^C^C^C^C^Z
[1]+  Stopped(SIGTSTP)        RUST_LOG=trace ./local-dir-server --address 192.168.2.118:8080
sh-5.0$ ll -n /proc/$(pgrep -f local-dir-server)/fd
total 0
dr-x------. 2 1000 1000  0 Jul 22 19:39 ./
dr-xr-xr-x. 9 1000 1000  0 Jul 22 19:39 ../
lrwx------. 1 1000 1000 64 Jul 22 19:39 0 -> /dev/pts/12
lrwx------. 1 1000 1000 64 Jul 22 19:39 1 -> /dev/pts/12
lrwx------. 1 1000 1000 64 Jul 22 19:39 12 -> 'socket:[2706210]'
lrwx------. 1 1000 1000 64 Jul 22 19:39 2 -> /dev/pts/12
lrwx------. 1 1000 1000 64 Jul 22 19:39 3 -> 'anon_inode:[eventpoll]'
lr-x------. 1 1000 1000 64 Jul 22 19:39 4 -> 'pipe:[2705989]'
l-wx------. 1 1000 1000 64 Jul 22 19:39 5 -> 'pipe:[2705989]'
lrwx------. 1 1000 1000 64 Jul 22 19:39 7 -> 'socket:[2705991]'
lrwx------. 1 1000 1000 64 Jul 22 19:39 8 -> 'socket:[2705992]'
sh-5.0$ rg -F 2706210 /proc/net/tcp
8:   6: 7602A8C0:1F90 6702A8C0:C6DF 01 00000000:00000000 00:00000000 00000000  1000        0 2706210 1 000000000bb7d95e 30 0 0 10 -1
helgoboss commented 3 years ago

I think I ran into the same issue, see https://github.com/helgoboss/realearn/issues/83#issuecomment-754802273.

In my particular case, I need a "not so graceful" shutdown. It's absolutely essential to shut down the server as fast as possible without having to wait for connections that have unfinished business. My server lives in a desktop app plug-in that can be added/removed by the user at any time. From a UX perspective it would be a dealbreaker to force the user to wait and figure out which of his devices/browsers are still connected to the server. However, it would be totally okay if established connections are abruptly closed by the server side.

As a dirty workaround, I patched hyper to make graceful_shutdown() forcibly close a HTTP 1.1 connection. It does the job. Does anyone know if this is the right approach if one can afford to close connections forcibly? I'm considering to create a PR with some method like forceful_shutdown() to support this use case.

Log without that workaround (graceful shutdown was blocked from 13:44:35 until I closed the browser tab at 13:45:41):

[2021-01-05T13:44:35Z DEBUG hyper::server::shutdown] signal received, starting graceful shutdown
[2021-01-05T13:44:35Z TRACE hyper::proto::h1::conn] disable_keep_alive; in-progress connection
[2021-01-05T13:44:35Z TRACE hyper::proto::h1::conn] Conn::read_head
[2021-01-05T13:44:35Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: Init, writing: Init, keep_alive: Disabled }
[2021-01-05T13:44:35Z TRACE hyper::proto::h1::conn] disable_keep_alive; in-progress connection
[2021-01-05T13:44:35Z TRACE hyper::proto::h1::conn] Conn::read_head
[2021-01-05T13:44:35Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: Init, writing: Init, keep_alive: Disabled }
[2021-01-05T13:45:41Z TRACE hyper::proto::h1::conn] Conn::read_head
[2021-01-05T13:45:41Z DEBUG hyper::proto::h1::io] read 0 bytes
[2021-01-05T13:45:41Z TRACE hyper::proto::h1::io] parse eof
[2021-01-05T13:45:41Z TRACE hyper::proto::h1::conn] State::close_read()
[2021-01-05T13:45:41Z DEBUG hyper::proto::h1::conn] read eof
[2021-01-05T13:45:41Z TRACE hyper::proto::h1::conn] State::close_write()
[2021-01-05T13:45:41Z TRACE hyper::proto::h1::conn] State::close_read()
[2021-01-05T13:45:41Z TRACE hyper::proto::h1::conn] State::close_write()
[2021-01-05T13:45:41Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: Closed, writing: Closed, keep_alive: Disabled }
[2021-01-05T13:45:41Z TRACE hyper::proto::h1::conn] shut down IO complete
[2021-01-05T13:45:41Z TRACE hyper::proto::h1::conn] Conn::read_head
[2021-01-05T13:45:41Z DEBUG hyper::proto::h1::io] read 0 bytes
[2021-01-05T13:45:41Z TRACE hyper::proto::h1::io] parse eof
[2021-01-05T13:45:41Z TRACE hyper::proto::h1::conn] State::close_read()
[2021-01-05T13:45:41Z DEBUG hyper::proto::h1::conn] read eof
[2021-01-05T13:45:41Z TRACE hyper::proto::h1::conn] State::close_write()
[2021-01-05T13:45:41Z TRACE hyper::proto::h1::conn] State::close_read()
[2021-01-05T13:45:41Z TRACE hyper::proto::h1::conn] State::close_write()
[2021-01-05T13:45:41Z TRACE hyper::proto::h1::conn] flushed({role=server}): State { reading: Closed, writing: Closed, keep_alive: Disabled }
[2021-01-05T13:45:41Z TRACE hyper::proto::h1::conn] shut down IO complete
sfackler commented 3 years ago

If you want to forcibly shut down the server, then just let it drop.

helgoboss commented 3 years ago

@sfackler Thank you for the hint! I pursued it and it led me to what is probably a beginner's question: How do I drop it?

Attempt 1

I can't figure out how to drop the server within the runtime because I'm awaiting it. To illustrate the problem, here's some example code that should shut the server down after 20 secs and then keep waiting for a while:

#[tokio::main]
pub async fn main() -> Result<(), Box<dyn std::error::Error + Send + Sync>> {
    let make_svc = make_service_fn(|_conn| async { Ok::<_, Infallible>(service_fn(hello)) });
    let addr = ([127, 0, 0, 1], 3000).into();
    let server = Server::bind(&addr).serve(make_svc);
    let wait_a_bit_and_close_server = move || async {
        println!("Waiting 20 secs");
        delay_for(Duration::from_secs(20)).await;
        println!("Shutting down server...");
        // TODO Shutdown/drop ... but how?
    };
    async fn wait_longer_to_delay_exit() {
        delay_for(Duration::from_secs(1000));
    };
    println!("Listening on http://{}", addr);
    let _ = tokio::join!(
        server,
        wait_a_bit_and_close_server(),
        wait_longer_to_delay_exit()
    );
    Ok(())
}

Any idea what I need to do differently to drop the server?

Attempt 2

In my particular case I build the runtime myself within a new dedicated thread and then call block_on() with the hyper server future (well, actually warp but it shouldn't matter here).

Side note: I used a dedicated thread and block_on() because initially I wanted to use basic_scheduler().

        let server_thread_join_handle = std::thread::Builder::new()
            .name("ReaLearn server".to_string())
            .spawn(move || {
                let runtime = tokio::runtime::Builder::new()
                    .threaded_scheduler()
                    .enable_all()
                    .build()
                    .unwrap();
                runtime.block_on(...);
                runtime.shutdown_timeout(Duration::from_secs(10));
            });

So I naively thought, maybe one way to drop the hyper server would be to use spawn() instead of block_on(), store the runtime somewhere, call shutdown_timeout() on it when the user demands the server to be stopped and then drop the runtime. The runtime shuts down, but not completely. The ports are still bound (but don't give responses anymore). Increasing the shutdown timeout doesn't help either.

helgoboss commented 3 years ago

@misos1 You "temporarily" mentioned that I should have opened a new issue and you are right. My original reply is hidden now and here's the new issue: https://github.com/hyperium/hyper/issues/2386.

dswij commented 8 months ago

Closed by https://github.com/hyperium/hyper/issues/3582.