Nov 18 17:50:39.676 INFO testing chttp-0.2.2 against try#2e026d6e5d7621634147ad4c8074f1d964dbb1be for pr-55982 Nov 18 17:50:39.678 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-55982/worker-0/try#2e026d6e5d7621634147ad4c8074f1d964dbb1be:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-0/pr-55982/try#2e026d6e5d7621634147ad4c8074f1d964dbb1be:/source:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +2e026d6e5d7621634147ad4c8074f1d964dbb1be-alt build --frozen" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"` Nov 18 17:50:40.097 INFO [stdout] 81c435b182c3b73bdf1a1857d65b820dc344b42158523f1040d3f05ad0a1ce33 Nov 18 17:50:40.101 INFO running `"docker" "start" "-a" "81c435b182c3b73bdf1a1857d65b820dc344b42158523f1040d3f05ad0a1ce33"` Nov 18 17:50:41.362 INFO [stderr] usermod: no changes Nov 18 17:50:41.667 INFO [stderr] Compiling libnghttp2-sys v0.1.0 Nov 18 17:50:41.667 INFO [stderr] Compiling curl-sys v0.4.15 Nov 18 17:50:41.675 INFO [stderr] Compiling withers_derive v0.2.0 Nov 18 17:51:04.439 INFO [stderr] Compiling curl v0.4.19 Nov 18 17:51:08.083 INFO [stderr] Compiling chttp v0.2.2 (/source) Nov 18 17:51:15.746 INFO [stderr] Finished dev [unoptimized + debuginfo] target(s) in 34.35s Nov 18 17:51:15.759 INFO [stderr] su: No module specific data is present Nov 18 17:51:16.497 INFO running `"docker" "inspect" "81c435b182c3b73bdf1a1857d65b820dc344b42158523f1040d3f05ad0a1ce33"` Nov 18 17:51:16.727 INFO running `"docker" "rm" "-f" "81c435b182c3b73bdf1a1857d65b820dc344b42158523f1040d3f05ad0a1ce33"` Nov 18 17:51:16.981 INFO [stdout] 81c435b182c3b73bdf1a1857d65b820dc344b42158523f1040d3f05ad0a1ce33 Nov 18 17:51:16.986 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-55982/worker-0/try#2e026d6e5d7621634147ad4c8074f1d964dbb1be:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-0/pr-55982/try#2e026d6e5d7621634147ad4c8074f1d964dbb1be:/source:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +2e026d6e5d7621634147ad4c8074f1d964dbb1be-alt test --frozen --no-run" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"` Nov 18 17:51:17.297 INFO [stdout] 9039620afffbf0b40c2cec0b7fdf7f9883426b00dbee76b337e6421ee8a8c3cd Nov 18 17:51:17.298 INFO running `"docker" "start" "-a" "9039620afffbf0b40c2cec0b7fdf7f9883426b00dbee76b337e6421ee8a8c3cd"` Nov 18 17:51:18.503 INFO [stderr] usermod: no changes Nov 18 17:51:18.984 INFO [stderr] Compiling chttp v0.2.2 (/source) Nov 18 17:52:04.183 INFO [stderr] Finished dev [unoptimized + debuginfo] target(s) in 45.61s Nov 18 17:52:04.245 INFO [stderr] su: No module specific data is present Nov 18 17:52:05.376 INFO running `"docker" "inspect" "9039620afffbf0b40c2cec0b7fdf7f9883426b00dbee76b337e6421ee8a8c3cd"` Nov 18 17:52:05.657 INFO running `"docker" "rm" "-f" "9039620afffbf0b40c2cec0b7fdf7f9883426b00dbee76b337e6421ee8a8c3cd"` Nov 18 17:52:05.995 INFO [stdout] 9039620afffbf0b40c2cec0b7fdf7f9883426b00dbee76b337e6421ee8a8c3cd Nov 18 17:52:06.001 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-55982/worker-0/try#2e026d6e5d7621634147ad4c8074f1d964dbb1be:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-0/pr-55982/try#2e026d6e5d7621634147ad4c8074f1d964dbb1be:/source:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +2e026d6e5d7621634147ad4c8074f1d964dbb1be-alt test --frozen" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"` Nov 18 17:52:06.703 INFO [stdout] fef1fec4e360dee3b7d9686d5ea0b43b42e4f4f76050da26a141480706da9c99 Nov 18 17:52:06.711 INFO running `"docker" "start" "-a" "fef1fec4e360dee3b7d9686d5ea0b43b42e4f4f76050da26a141480706da9c99"` Nov 18 17:52:08.150 INFO [stderr] usermod: no changes Nov 18 17:52:08.431 INFO [stderr] Finished dev [unoptimized + debuginfo] target(s) in 0.26s Nov 18 17:52:08.455 INFO [stderr] Running /target/debug/deps/chttp-65820d7893863116 Nov 18 17:52:08.463 INFO [stderr] Running /target/debug/deps/redirects-ebcb0def7e1c5e7e Nov 18 17:52:08.464 INFO [stdout] Nov 18 17:52:08.464 INFO [stdout] running 0 tests Nov 18 17:52:08.464 INFO [stdout] Nov 18 17:52:08.465 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out Nov 18 17:52:08.465 INFO [stdout] Nov 18 17:52:08.467 INFO [stdout] Nov 18 17:52:08.467 INFO [stdout] running 3 tests Nov 18 17:52:08.623 INFO [stderr] DEBUG 2018-11-18T17:52:08Z: chttp::internal::agent: agent ready Nov 18 17:52:08.624 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: received message from agent handle: BeginRequest(CurlRequest(Easy { handle: 0x7fca10025a40, handler: 0x7fca10025a40 })) Nov 18 17:52:08.624 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Trying 127.0.0.1... Nov 18 17:52:08.624 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 42647 (#0) Nov 18 17:52:08.625 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: >> GET /a HTTP/1.1\r\nHost: 127.0.0.1:42647\r\nAccept: */*\r\n\r\n Nov 18 17:52:08.625 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: polling with timeout of 200ms Nov 18 17:52:08.625 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: woke up from notify fd Nov 18 17:52:08.626 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: polling with timeout of 200ms Nov 18 17:52:08.626 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: woke up from notify fd Nov 18 17:52:08.626 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: received message from agent handle: BeginRequest(CurlRequest(Easy { handle: 0x7fca0c002360, handler: 0x7fca0c002360 })) Nov 18 17:52:08.627 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fc9f800ff60 [serially] Nov 18 17:52:08.627 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Server doesn't support multi-use (yet) Nov 18 17:52:08.627 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Trying 127.0.0.1... Nov 18 17:52:08.628 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 35965 (#1) Nov 18 17:52:08.628 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: >> GET /0 HTTP/1.1\r\nHost: 127.0.0.1:35965\r\nAccept: */*\r\n\r\n Nov 18 17:52:08.628 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: polling with timeout of 200ms Nov 18 17:52:08.629 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: woke up from notify fd Nov 18 17:52:08.629 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: received message from agent handle: BeginRequest(CurlRequest(Easy { handle: 0x7fca08002360, handler: 0x7fca08002360 })) Nov 18 17:52:08.629 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fc9f800ff60 [serially] Nov 18 17:52:08.629 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Server doesn't support multi-use (yet) Nov 18 17:52:08.630 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Trying 127.0.0.1... Nov 18 17:52:08.630 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 38725 (#2) Nov 18 17:52:08.630 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: >> GET /a HTTP/1.1\r\nHost: 127.0.0.1:38725\r\nAccept: */*\r\n\r\n Nov 18 17:52:08.631 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: polling with timeout of 200ms Nov 18 17:52:08.643 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << HTTP/1.1 301 Moved Permanently\r\n Nov 18 17:52:08.643 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n Nov 18 17:52:08.689 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Date: Sun, 18 Nov 2018 17:52:08 GMT\r\n Nov 18 17:52:08.689 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Location: /b\r\n Nov 18 17:52:08.689 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Content-Length: 0\r\n Nov 18 17:52:08.690 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << \r\n Nov 18 17:52:08.690 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Connection #0 to host 127.0.0.1 left intact Nov 18 17:52:08.690 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << HTTP/1.1 301 Moved Permanently\r\n Nov 18 17:52:08.690 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n Nov 18 17:52:08.691 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Date: Sun, 18 Nov 2018 17:52:08 GMT\r\n Nov 18 17:52:08.691 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Location: /1\r\n Nov 18 17:52:08.691 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Content-Length: 0\r\n Nov 18 17:52:08.691 INFO [stderr] DEBUG 2018-11-18T17:52:08Z: chttp::internal::request: preparing for redirect to Some("/1") Nov 18 17:52:08.692 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << \r\n Nov 18 17:52:08.692 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Connection #1 to host 127.0.0.1 left intact Nov 18 17:52:08.692 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Issue another request to this URL: 'http://127.0.0.1:35965/1' Nov 18 17:52:08.692 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fc9f800ff60 [can pipeline] Nov 18 17:52:08.693 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Could pipeline, but not asked to! Nov 18 17:52:08.693 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Re-using existing connection! (#1) with host 127.0.0.1 Nov 18 17:52:08.693 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 35965 (#1) Nov 18 17:52:08.693 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: >> GET /1 HTTP/1.1\r\nHost: 127.0.0.1:35965\r\nAccept: */*\r\n\r\n Nov 18 17:52:08.694 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << HTTP/1.1 301 Moved Permanently\r\n Nov 18 17:52:08.694 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n Nov 18 17:52:08.694 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Date: Sun, 18 Nov 2018 17:52:08 GMT\r\n Nov 18 17:52:08.694 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Location: /b\r\n Nov 18 17:52:08.694 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Content-Length: 0\r\n Nov 18 17:52:08.694 INFO [stderr] DEBUG 2018-11-18T17:52:08Z: chttp::internal::request: preparing for redirect to Some("/b") Nov 18 17:52:08.694 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << \r\n Nov 18 17:52:08.694 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Connection #2 to host 127.0.0.1 left intact Nov 18 17:52:08.694 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Issue another request to this URL: 'http://127.0.0.1:38725/b' Nov 18 17:52:08.694 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fc9f800ff60 [can pipeline] Nov 18 17:52:08.694 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Could pipeline, but not asked to! Nov 18 17:52:08.694 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Re-using existing connection! (#2) with host 127.0.0.1 Nov 18 17:52:08.694 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 38725 (#2) Nov 18 17:52:08.694 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: >> GET /b HTTP/1.1\r\nHost: 127.0.0.1:38725\r\nAccept: */*\r\n\r\n Nov 18 17:52:08.694 INFO [stderr] DEBUG 2018-11-18T17:52:08Z: chttp::internal::agent: request with token 0 completed Nov 18 17:52:08.694 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: polling with timeout of 200ms Nov 18 17:52:08.697 INFO [stdout] test response_301_no_follow ... ok Nov 18 17:52:08.711 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << HTTP/1.1 200 OK\r\n Nov 18 17:52:08.711 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n Nov 18 17:52:08.711 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Date: Sun, 18 Nov 2018 17:52:08 GMT\r\n Nov 18 17:52:08.711 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Content-Type: text/plain; charset=utf8\r\n Nov 18 17:52:08.711 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Content-Length: 2\r\n Nov 18 17:52:08.711 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << \r\n Nov 18 17:52:08.711 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << ok Nov 18 17:52:08.711 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: received 2 bytes of data Nov 18 17:52:08.711 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Connection #2 to host 127.0.0.1 left intact Nov 18 17:52:08.711 INFO [stderr] DEBUG 2018-11-18T17:52:08Z: chttp::internal::agent: request with token 2 completed Nov 18 17:52:08.711 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: polling with timeout of 200ms Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: received read request for 32 bytes Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: read buffer contains 2 bytes, consuming 2 bytes Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: received read request for 30 bytes Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: request is closed, satisfying read request with EOF Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << HTTP/1.1 301 Moved Permanently\r\n Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Date: Sun, 18 Nov 2018 17:52:08 GMT\r\n Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Location: /2\r\n Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Content-Length: 0\r\n Nov 18 17:52:08.719 INFO [stderr] DEBUG 2018-11-18T17:52:08Z: chttp::internal::request: preparing for redirect to Some("/2") Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << \r\n Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Connection #1 to host 127.0.0.1 left intact Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Issue another request to this URL: 'http://127.0.0.1:35965/2' Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fc9f800ff60 [can pipeline] Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Could pipeline, but not asked to! Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Re-using existing connection! (#1) with host 127.0.0.1 Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 35965 (#1) Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: >> GET /2 HTTP/1.1\r\nHost: 127.0.0.1:35965\r\nAccept: */*\r\n\r\n Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: polling with timeout of 200ms Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << HTTP/1.1 301 Moved Permanently\r\n Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Date: Sun, 18 Nov 2018 17:52:08 GMT\r\n Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Location: /3\r\n Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Content-Length: 0\r\n Nov 18 17:52:08.719 INFO [stderr] DEBUG 2018-11-18T17:52:08Z: chttp::internal::request: preparing for redirect to Some("/3") Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << \r\n Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Connection #1 to host 127.0.0.1 left intact Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Issue another request to this URL: 'http://127.0.0.1:35965/3' Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fc9f800ff60 [can pipeline] Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Could pipeline, but not asked to! Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Re-using existing connection! (#1) with host 127.0.0.1 Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 35965 (#1) Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: >> GET /3 HTTP/1.1\r\nHost: 127.0.0.1:35965\r\nAccept: */*\r\n\r\n Nov 18 17:52:08.719 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: polling with timeout of 200ms Nov 18 17:52:08.719 INFO [stdout] test response_301_auto_follow ... ok Nov 18 17:52:08.727 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << HTTP/1.1 301 Moved Permanently\r\n Nov 18 17:52:08.727 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n Nov 18 17:52:08.727 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Date: Sun, 18 Nov 2018 17:52:08 GMT\r\n Nov 18 17:52:08.727 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Location: /4\r\n Nov 18 17:52:08.727 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Content-Length: 0\r\n Nov 18 17:52:08.727 INFO [stderr] DEBUG 2018-11-18T17:52:08Z: chttp::internal::request: preparing for redirect to Some("/4") Nov 18 17:52:08.727 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << \r\n Nov 18 17:52:08.727 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Connection #1 to host 127.0.0.1 left intact Nov 18 17:52:08.727 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Issue another request to this URL: 'http://127.0.0.1:35965/4' Nov 18 17:52:08.727 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fc9f800ff60 [can pipeline] Nov 18 17:52:08.727 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Could pipeline, but not asked to! Nov 18 17:52:08.727 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Re-using existing connection! (#1) with host 127.0.0.1 Nov 18 17:52:08.727 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 35965 (#1) Nov 18 17:52:08.727 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: >> GET /4 HTTP/1.1\r\nHost: 127.0.0.1:35965\r\nAccept: */*\r\n\r\n Nov 18 17:52:08.727 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: polling with timeout of 200ms Nov 18 17:52:08.743 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << HTTP/1.1 301 Moved Permanently\r\n Nov 18 17:52:08.743 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n Nov 18 17:52:08.743 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Date: Sun, 18 Nov 2018 17:52:08 GMT\r\n Nov 18 17:52:08.743 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Location: /5\r\n Nov 18 17:52:08.743 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Content-Length: 0\r\n Nov 18 17:52:08.743 INFO [stderr] DEBUG 2018-11-18T17:52:08Z: chttp::internal::request: preparing for redirect to Some("/5") Nov 18 17:52:08.743 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << \r\n Nov 18 17:52:08.743 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Connection #1 to host 127.0.0.1 left intact Nov 18 17:52:08.743 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Issue another request to this URL: 'http://127.0.0.1:35965/5' Nov 18 17:52:08.743 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fc9f800ff60 [can pipeline] Nov 18 17:52:08.743 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Could pipeline, but not asked to! Nov 18 17:52:08.743 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Re-using existing connection! (#1) with host 127.0.0.1 Nov 18 17:52:08.743 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 35965 (#1) Nov 18 17:52:08.743 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: >> GET /5 HTTP/1.1\r\nHost: 127.0.0.1:35965\r\nAccept: */*\r\n\r\n Nov 18 17:52:08.743 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: polling with timeout of 200ms Nov 18 17:52:08.751 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << HTTP/1.1 301 Moved Permanently\r\n Nov 18 17:52:08.751 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n Nov 18 17:52:08.751 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Date: Sun, 18 Nov 2018 17:52:08 GMT\r\n Nov 18 17:52:08.755 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Location: /6\r\n Nov 18 17:52:08.755 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Content-Length: 0\r\n Nov 18 17:52:08.755 INFO [stderr] DEBUG 2018-11-18T17:52:08Z: chttp::internal::request: preparing for redirect to Some("/6") Nov 18 17:52:08.755 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << \r\n Nov 18 17:52:08.755 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Connection #1 to host 127.0.0.1 left intact Nov 18 17:52:08.755 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Maximum (5) redirects followed Nov 18 17:52:08.755 INFO [stderr] DEBUG 2018-11-18T17:52:08Z: chttp::internal::agent: curl error: [47] Number of redirects hit maximum amount Nov 18 17:52:08.755 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: polling with timeout of 100ms Nov 18 17:52:08.759 INFO [stdout] test redirect_limit_is_respected ... ok Nov 18 17:52:08.759 INFO [stdout] Nov 18 17:52:08.759 INFO [stdout] test result: ok. 3 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out Nov 18 17:52:08.759 INFO [stdout] Nov 18 17:52:08.759 INFO [stderr] Running /target/debug/deps/response-3d3cf531b03f3532 Nov 18 17:52:08.767 INFO [stdout] Nov 18 17:52:08.767 INFO [stdout] running 2 tests Nov 18 17:52:08.775 INFO [stderr] DEBUG 2018-11-18T17:52:08Z: chttp::internal::agent: agent ready Nov 18 17:52:08.787 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: received message from agent handle: BeginRequest(CurlRequest(Easy { handle: 0x7fcb08001e10, handler: 0x7fcb08001e10 })) Nov 18 17:52:08.787 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: received message from agent handle: BeginRequest(CurlRequest(Easy { handle: 0x7fcb180037f0, handler: 0x7fcb180037f0 })) Nov 18 17:52:08.787 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Trying 127.0.0.1... Nov 18 17:52:08.787 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 35883 (#0) Nov 18 17:52:08.787 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: >> GET / HTTP/1.1\r\nHost: 127.0.0.1:35883\r\nAccept: */*\r\n\r\n Nov 18 17:52:08.787 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fcb14023590 [serially] Nov 18 17:52:08.787 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Server doesn't support multi-use (yet) Nov 18 17:52:08.787 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Trying 127.0.0.1... Nov 18 17:52:08.787 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 44317 (#1) Nov 18 17:52:08.787 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: >> GET / HTTP/1.1\r\nHost: 127.0.0.1:44317\r\nAccept: */*\r\n\r\n Nov 18 17:52:08.787 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: polling with timeout of 200ms Nov 18 17:52:08.787 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: woke up from notify fd Nov 18 17:52:08.787 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: polling with timeout of 200ms Nov 18 17:52:08.795 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << HTTP/1.1 200 OK\r\n Nov 18 17:52:08.795 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n Nov 18 17:52:08.811 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Date: Sun, 18 Nov 2018 17:52:08 GMT\r\n Nov 18 17:52:08.811 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Content-Type: text/plain; charset=utf8\r\n Nov 18 17:52:08.811 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Content-Length: 13000\r\n Nov 18 17:52:08.811 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: received read request for 32 bytes Nov 18 17:52:08.811 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: buffer is empty, read is pending Nov 18 17:52:08.811 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << \r\n Nov 18 17:52:08.811 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: polling with timeout of 200ms Nov 18 17:52:08.811 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: woke up from notify fd Nov 18 17:52:08.811 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: received message from agent handle: UnpauseWrite(1) Nov 18 17:52:08.811 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: polling with timeout of 200ms Nov 18 17:52:08.819 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << HTTP/1.1 200 OK\r\n Nov 18 17:52:08.819 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n Nov 18 17:52:08.819 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Date: Sun, 18 Nov 2018 17:52:08 GMT\r\n Nov 18 17:52:08.819 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Content-Type: text/plain; charset=utf8\r\n Nov 18 17:52:08.819 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << Content-Length: 11\r\n Nov 18 17:52:08.819 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: received read request for 32 bytes Nov 18 17:52:08.819 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: buffer is empty, read is pending Nov 18 17:52:08.819 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << \r\n Nov 18 17:52:08.819 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << hello world Nov 18 17:52:08.819 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: received 11 bytes of data Nov 18 17:52:08.819 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: received read request for 32 bytes Nov 18 17:52:08.819 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: read buffer contains 11 bytes, consuming 11 bytes Nov 18 17:52:08.819 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: received read request for 21 bytes Nov 18 17:52:08.819 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: buffer is empty, read is pending Nov 18 17:52:08.819 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Connection #0 to host 127.0.0.1 left intact Nov 18 17:52:08.819 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wo Nov 18 17:52:08.819 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: received 8192 bytes of data Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: received read request for 32 bytes Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: read buffer contains 8192 bytes, consuming 32 bytes Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: received read request for 32 bytes Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: read buffer contains 8160 bytes, consuming 32 bytes Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: received read request for 64 bytes Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: read buffer contains 8128 bytes, consuming 64 bytes Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: received read request for 128 bytes Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: read buffer contains 8064 bytes, consuming 128 bytes Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: received read request for 256 bytes Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: read buffer contains 7936 bytes, consuming 256 bytes Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: received read request for 512 bytes Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: read buffer contains 7680 bytes, consuming 512 bytes Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: received read request for 1024 bytes Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: read buffer contains 7168 bytes, consuming 1024 bytes Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: received read request for 2048 bytes Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: read buffer contains 6144 bytes, consuming 2048 bytes Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: received read request for 4096 bytes Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: read buffer contains 4096 bytes, consuming 4096 bytes Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: received read request for 8192 bytes Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: buffer is empty, read is pending Nov 18 17:52:08.820 INFO [stderr] DEBUG 2018-11-18T17:52:08Z: chttp::internal::agent: request with token 0 completed Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: received read request for 21 bytes Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: request is closed, satisfying read request with EOF Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: polling with timeout of 200ms Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: woke up from notify fd Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: received message from agent handle: UnpauseWrite(0) Nov 18 17:52:08.820 INFO [stderr] WARN 2018-11-18T17:52:08Z: chttp::internal::agent: received unpause request for unknown request token: 0 Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: received message from agent handle: UnpauseWrite(0) Nov 18 17:52:08.820 INFO [stderr] WARN 2018-11-18T17:52:08Z: chttp::internal::agent: received unpause request for unknown request token: 0 Nov 18 17:52:08.820 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: received message from agent handle: UnpauseWrite(1) Nov 18 17:52:08.827 INFO [stdout] test simple_response_body ... ok Nov 18 17:52:08.831 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: << w so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large Nov 18 17:52:08.831 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: received 4808 bytes of data Nov 18 17:52:08.831 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: received read request for 8192 bytes Nov 18 17:52:08.831 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: read buffer contains 4808 bytes, consuming 4808 bytes Nov 18 17:52:08.831 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: received read request for 3384 bytes Nov 18 17:52:08.831 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: buffer is empty, read is pending Nov 18 17:52:08.831 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Connection #1 to host 127.0.0.1 left intact Nov 18 17:52:08.831 INFO [stderr] DEBUG 2018-11-18T17:52:08Z: chttp::internal::agent: request with token 1 completed Nov 18 17:52:08.831 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: received read request for 3384 bytes Nov 18 17:52:08.831 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: request is closed, satisfying read request with EOF Nov 18 17:52:08.831 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: polling with timeout of 100ms Nov 18 17:52:08.831 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: woke up from notify fd Nov 18 17:52:08.831 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: received message from agent handle: UnpauseWrite(1) Nov 18 17:52:08.831 INFO [stderr] WARN 2018-11-18T17:52:08Z: chttp::internal::agent: received unpause request for unknown request token: 1 Nov 18 17:52:08.831 INFO [stdout] test large_response_body ... ok Nov 18 17:52:08.831 INFO [stdout] Nov 18 17:52:08.831 INFO [stdout] test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out Nov 18 17:52:08.831 INFO [stdout] Nov 18 17:52:08.843 INFO [stderr] Running /target/debug/deps/timeouts-2724485521cda3de Nov 18 17:52:08.855 INFO [stdout] Nov 18 17:52:08.855 INFO [stdout] running 1 test Nov 18 17:52:08.855 INFO [stderr] DEBUG 2018-11-18T17:52:08Z: chttp::internal::agent: agent ready Nov 18 17:52:08.855 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: received message from agent handle: BeginRequest(CurlRequest(Easy { handle: 0x7f8bbc025f50, handler: 0x7f8bbc025f50 })) Nov 18 17:52:08.855 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Trying 127.0.0.1... Nov 18 17:52:08.855 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 33493 (#0) Nov 18 17:52:08.855 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::request: >> POST / HTTP/1.1\r\nHost: 127.0.0.1:33493\r\nAccept: */*\r\nContent-Length: 11\r\nExpect: 100-continue\r\n\r\n Nov 18 17:52:08.863 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: polling with timeout of 200ms Nov 18 17:52:08.863 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: woke up from notify fd Nov 18 17:52:08.863 INFO [stderr] TRACE 2018-11-18T17:52:08Z: chttp::internal::agent: polling with timeout of 200ms Nov 18 17:52:09.067 INFO [stderr] TRACE 2018-11-18T17:52:09Z: chttp::internal::request: Done waiting for 100-continue Nov 18 17:52:09.067 INFO [stderr] TRACE 2018-11-18T17:52:09Z: chttp::internal::agent: polling with timeout of 1s Nov 18 17:52:09.067 INFO [stderr] TRACE 2018-11-18T17:52:09Z: chttp::internal::request: >> hello world Nov 18 17:52:09.067 INFO [stderr] TRACE 2018-11-18T17:52:09Z: chttp::internal::request: We are completely uploaded and fine Nov 18 17:52:09.067 INFO [stderr] TRACE 2018-11-18T17:52:09Z: chttp::internal::agent: polling with timeout of 1s Nov 18 17:52:10.067 INFO [stderr] TRACE 2018-11-18T17:52:10Z: chttp::internal::request: Operation timed out after 2000 milliseconds with 0 bytes received Nov 18 17:52:10.067 INFO [stdout] test request_errors_if_read_timeout_is_reached ... ok Nov 18 17:52:10.067 INFO [stderr] TRACE 2018-11-18T17:52:10Z: chttp::internal::request: Closing connection 0 Nov 18 17:52:10.067 INFO [stdout] Nov 18 17:52:10.067 INFO [stderr] DEBUG 2018-11-18T17:52:10Z: chttp::internal::agent: curl error: [28] Timeout was reached Nov 18 17:52:10.067 INFO [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out Nov 18 17:52:10.067 INFO [stderr] TRACE 2018-11-18T17:52:10Z: chttp::internal::agent: polling with timeout of 100ms Nov 18 17:52:10.067 INFO [stdout] Nov 18 17:52:10.067 INFO [stderr] Doc-tests chttp Nov 18 17:52:16.433 INFO [stdout] Nov 18 17:52:16.433 INFO [stdout] running 6 tests Nov 18 17:52:43.051 INFO [stdout] test src/client.rs - client::ClientBuilder (line 17) ... ok Nov 18 17:52:43.859 INFO [stdout] test src/lib.rs - (line 53) ... ok Nov 18 17:52:45.503 INFO [stdout] test src/lib.rs - (line 74) ... ok Nov 18 17:52:45.614 INFO [stdout] test src/lib.rs - (line 26) ... ok Nov 18 17:52:46.083 INFO [stdout] test src/lib.rs - (line 11) ... ok Nov 18 17:52:46.547 INFO [stdout] test src/lib.rs - (line 37) ... ok Nov 18 17:52:46.547 INFO [stdout] Nov 18 17:52:46.547 INFO [stdout] test result: ok. 6 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out Nov 18 17:52:46.547 INFO [stdout] Nov 18 17:52:46.579 INFO [stderr] su: No module specific data is present Nov 18 17:52:47.687 INFO running `"docker" "inspect" "fef1fec4e360dee3b7d9686d5ea0b43b42e4f4f76050da26a141480706da9c99"` Nov 18 17:52:48.003 INFO running `"docker" "rm" "-f" "fef1fec4e360dee3b7d9686d5ea0b43b42e4f4f76050da26a141480706da9c99"` Nov 18 17:52:48.375 INFO [stdout] fef1fec4e360dee3b7d9686d5ea0b43b42e4f4f76050da26a141480706da9c99