Graceful shutdown never finishes when there is opened connection #1885

misos1 · 2019-07-28T19:39:57Z

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

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

ghost · 2020-07-22T11:51:49Z

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

When opening a http1 connection, the keep_alive state is set to Busy, preventing a graceful_shutdown in that case. With this patch the keep_alive disabling and closing of idle connections is decoupled and should fix this issue. Closes hyperium#1885 Signed-off-by: Dominik Csapak <d.csapak@proxmox.com>

helgoboss · 2021-01-05T18:39:26Z

I think I ran into the same issue, see helgoboss/realearn#83 (comment).

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 · 2021-01-05T18:47:18Z

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

helgoboss · 2021-01-05T20:37:12Z

@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: #2386.

dswij · 2024-03-08T07:45:07Z

Closed by #3582.

louaykamel mentioned this issue Oct 1, 2020

Graceful shutdown never finishes #2294

Open

flumm mentioned this issue Nov 4, 2020

fix(server): fix graceful_shutdown on freshly opened connections #2318

Closed

This comment has been minimized.

Sign in to view

helgoboss mentioned this issue Jan 5, 2021

How to forcibly shut down the server? #2386

Closed

adumbidiot mentioned this issue Dec 31, 2021

Gracefull shutdown not working seanmonstar/warp#870

Open

itowlson mentioned this issue Mar 24, 2022

HTTP trigger graceful shutdown makes it hang until another request fermyon/spin#73

Closed

jleibs mentioned this issue Apr 14, 2023

Ctrl-C still hangs when hosting web-server in some cases rerun-io/rerun#1843

Open

mladedav mentioned this issue Mar 7, 2024

graceful shutdown does not shutdown when i use Google Chrome。 #3576

Closed

dswij closed this as completed Mar 8, 2024

ms140569 mentioned this issue Apr 10, 2024

Delayed shutdown when hitting ctrl-c on terminal static-web-server/static-web-server#335

Open

1 task

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Graceful shutdown never finishes when there is opened connection #1885

Graceful shutdown never finishes when there is opened connection #1885

misos1 commented Jul 28, 2019 •

edited

ghost commented Jul 22, 2020 •

edited by ghost

helgoboss commented Jan 5, 2021

sfackler commented Jan 5, 2021

This comment has been minimized.

helgoboss commented Jan 5, 2021

dswij commented Mar 8, 2024 •

edited

Navigation Menu

Graceful shutdown never finishes when there is opened connection #1885

Graceful shutdown never finishes when there is opened connection #1885

Comments

misos1 commented Jul 28, 2019 • edited

ghost commented Jul 22, 2020 • edited by ghost

helgoboss commented Jan 5, 2021

sfackler commented Jan 5, 2021

This comment has been minimized.

helgoboss commented Jan 5, 2021

dswij commented Mar 8, 2024 • edited

misos1 commented Jul 28, 2019 •

edited

ghost commented Jul 22, 2020 •

edited by ghost

dswij commented Mar 8, 2024 •

edited