Nov 18 17:50:40.439 INFO testing chttp-0.2.2 against master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c for pr-55982
Nov 18 17:50:40.441 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-55982/worker-4/master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-4/pr-55982/master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c:/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 +6b9b97bd9b704f85f0184f7a213cc4d62bd9654c-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.948 INFO [stdout] cb8ec77c94cf3437e0a153a1a9249152e0a61b1c7ac4056ec364ad0d9dc280ed
Nov 18 17:50:40.951 INFO running `"docker" "start" "-a" "cb8ec77c94cf3437e0a153a1a9249152e0a61b1c7ac4056ec364ad0d9dc280ed"`
Nov 18 17:50:42.867 INFO [stderr] usermod: no changes
Nov 18 17:50:43.295 INFO [stderr]    Compiling libnghttp2-sys v0.1.0
Nov 18 17:50:43.296 INFO [stderr]    Compiling curl-sys v0.4.15
Nov 18 17:50:43.321 INFO [stderr]    Compiling withers_derive v0.2.0
Nov 18 17:51:05.007 INFO [stderr]    Compiling curl v0.4.19
Nov 18 17:51:08.336 INFO [stderr]    Compiling chttp v0.2.2 (/source)
Nov 18 17:51:16.007 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 33.12s
Nov 18 17:51:16.027 INFO [stderr] su: No module specific data is present
Nov 18 17:51:16.789 INFO running `"docker" "inspect" "cb8ec77c94cf3437e0a153a1a9249152e0a61b1c7ac4056ec364ad0d9dc280ed"`
Nov 18 17:51:17.089 INFO running `"docker" "rm" "-f" "cb8ec77c94cf3437e0a153a1a9249152e0a61b1c7ac4056ec364ad0d9dc280ed"`
Nov 18 17:51:17.373 INFO [stdout] cb8ec77c94cf3437e0a153a1a9249152e0a61b1c7ac4056ec364ad0d9dc280ed
Nov 18 17:51:17.375 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-55982/worker-4/master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-4/pr-55982/master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c:/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 +6b9b97bd9b704f85f0184f7a213cc4d62bd9654c-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.898 INFO [stdout] 5e56b4a1373ac32980e8989e6bdc87a61b52ad9397c3be98dc63b101e1c808f7
Nov 18 17:51:17.907 INFO running `"docker" "start" "-a" "5e56b4a1373ac32980e8989e6bdc87a61b52ad9397c3be98dc63b101e1c808f7"`
Nov 18 17:51:19.085 INFO [stderr] usermod: no changes
Nov 18 17:51:19.459 INFO [stderr]    Compiling buf_redux v0.6.3
Nov 18 17:51:19.463 INFO [stderr]    Compiling twoway v0.1.8
Nov 18 17:51:19.471 INFO [stderr]    Compiling gzip-header v0.2.0
Nov 18 17:51:22.279 INFO [stderr]    Compiling deflate v0.7.19
Nov 18 17:51:22.423 INFO [stderr]    Compiling multipart v0.13.6
Nov 18 17:51:27.005 INFO [stderr]    Compiling rouille v2.2.0
Nov 18 17:51:34.859 INFO [stderr]    Compiling chttp v0.2.2 (/source)
Nov 18 17:52:18.951 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 59.83s
Nov 18 17:52:18.966 INFO [stderr] su: No module specific data is present
Nov 18 17:52:20.395 INFO running `"docker" "inspect" "5e56b4a1373ac32980e8989e6bdc87a61b52ad9397c3be98dc63b101e1c808f7"`
Nov 18 17:52:20.749 INFO running `"docker" "rm" "-f" "5e56b4a1373ac32980e8989e6bdc87a61b52ad9397c3be98dc63b101e1c808f7"`
Nov 18 17:52:20.980 INFO [stdout] 5e56b4a1373ac32980e8989e6bdc87a61b52ad9397c3be98dc63b101e1c808f7
Nov 18 17:52:20.987 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-55982/worker-4/master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-4/pr-55982/master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c:/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 +6b9b97bd9b704f85f0184f7a213cc4d62bd9654c-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:21.477 INFO [stdout] d1ccdc2a11bea06f0057db2c426d55aeb7d5f44811aa0bc648fc0931b3d76804
Nov 18 17:52:21.483 INFO running `"docker" "start" "-a" "d1ccdc2a11bea06f0057db2c426d55aeb7d5f44811aa0bc648fc0931b3d76804"`
Nov 18 17:52:22.795 INFO [stderr] usermod: no changes
Nov 18 17:52:23.073 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.25s
Nov 18 17:52:23.086 INFO [stderr]      Running /target/debug/deps/chttp-25b47500c6fadca1
Nov 18 17:52:23.089 INFO [stderr]      Running /target/debug/deps/redirects-97d1be13eac7fe71
Nov 18 17:52:23.089 INFO [stdout] 
Nov 18 17:52:23.089 INFO [stdout] running 0 tests
Nov 18 17:52:23.089 INFO [stdout] 
Nov 18 17:52:23.089 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 18 17:52:23.089 INFO [stdout] 
Nov 18 17:52:23.097 INFO [stdout] 
Nov 18 17:52:23.098 INFO [stdout] running 3 tests
Nov 18 17:52:23.135 INFO [stderr] DEBUG 2018-11-18T17:52:23Z: chttp::internal::agent: agent ready
Nov 18 17:52:23.135 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: received message from agent handle: BeginRequest(CurlRequest(Easy { handle: 0x7fbb90025f90, handler: 0x7fbb90025f90 }))
Nov 18 17:52:23.135 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request:   Trying 127.0.0.1...
Nov 18 17:52:23.135 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 43695 (#0)
Nov 18 17:52:23.135 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: >> GET /a HTTP/1.1\r\nHost: 127.0.0.1:43695\r\nAccept: */*\r\n\r\n
Nov 18 17:52:23.135 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: polling with timeout of 200ms
Nov 18 17:52:23.135 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: woke up from notify fd
Nov 18 17:52:23.135 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: polling with timeout of 200ms
Nov 18 17:52:23.135 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: woke up from notify fd
Nov 18 17:52:23.135 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: received message from agent handle: BeginRequest(CurlRequest(Easy { handle: 0x7fbb88001e20, handler: 0x7fbb88001e20 }))
Nov 18 17:52:23.135 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fbb7800ff60 [serially]
Nov 18 17:52:23.136 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Server doesn't support multi-use (yet)
Nov 18 17:52:23.136 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request:   Trying 127.0.0.1...
Nov 18 17:52:23.136 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 44827 (#1)
Nov 18 17:52:23.136 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: >> GET /a HTTP/1.1\r\nHost: 127.0.0.1:44827\r\nAccept: */*\r\n\r\n
Nov 18 17:52:23.136 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: polling with timeout of 200ms
Nov 18 17:52:23.147 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: woke up from notify fd
Nov 18 17:52:23.147 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: received message from agent handle: BeginRequest(CurlRequest(Easy { handle: 0x7fbb80002360, handler: 0x7fbb80002360 }))
Nov 18 17:52:23.155 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fbb7800ff60 [serially]
Nov 18 17:52:23.155 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Server doesn't support multi-use (yet)
Nov 18 17:52:23.155 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request:   Trying 127.0.0.1...
Nov 18 17:52:23.155 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 43889 (#2)
Nov 18 17:52:23.155 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: >> GET /0 HTTP/1.1\r\nHost: 127.0.0.1:43889\r\nAccept: */*\r\n\r\n
Nov 18 17:52:23.155 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: polling with timeout of 200ms
Nov 18 17:52:23.219 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << HTTP/1.1 301 Moved Permanently\r\n
Nov 18 17:52:23.219 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n
Nov 18 17:52:23.296 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Date: Sun, 18 Nov 2018 17:52:23 GMT\r\n
Nov 18 17:52:23.296 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Location: /b\r\n
Nov 18 17:52:23.296 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Content-Length: 0\r\n
Nov 18 17:52:23.296 INFO [stderr] DEBUG 2018-11-18T17:52:23Z: chttp::internal::request: preparing for redirect to Some("/b")
Nov 18 17:52:23.296 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << \r\n
Nov 18 17:52:23.296 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Connection #0 to host 127.0.0.1 left intact
Nov 18 17:52:23.296 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Issue another request to this URL: 'http://127.0.0.1:43695/b'
Nov 18 17:52:23.296 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fbb7800ff60 [can pipeline]
Nov 18 17:52:23.296 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Could pipeline, but not asked to!
Nov 18 17:52:23.296 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Re-using existing connection! (#0) with host 127.0.0.1
Nov 18 17:52:23.296 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 43695 (#0)
Nov 18 17:52:23.296 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: >> GET /b HTTP/1.1\r\nHost: 127.0.0.1:43695\r\nAccept: */*\r\n\r\n
Nov 18 17:52:23.296 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << HTTP/1.1 301 Moved Permanently\r\n
Nov 18 17:52:23.296 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n
Nov 18 17:52:23.296 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Date: Sun, 18 Nov 2018 17:52:23 GMT\r\n
Nov 18 17:52:23.296 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Location: /1\r\n
Nov 18 17:52:23.296 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Content-Length: 0\r\n
Nov 18 17:52:23.296 INFO [stderr] DEBUG 2018-11-18T17:52:23Z: chttp::internal::request: preparing for redirect to Some("/1")
Nov 18 17:52:23.297 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << \r\n
Nov 18 17:52:23.297 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Connection #2 to host 127.0.0.1 left intact
Nov 18 17:52:23.297 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Issue another request to this URL: 'http://127.0.0.1:43889/1'
Nov 18 17:52:23.297 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fbb7800ff60 [can pipeline]
Nov 18 17:52:23.297 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Could pipeline, but not asked to!
Nov 18 17:52:23.297 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Re-using existing connection! (#2) with host 127.0.0.1
Nov 18 17:52:23.297 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 43889 (#2)
Nov 18 17:52:23.297 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: >> GET /1 HTTP/1.1\r\nHost: 127.0.0.1:43889\r\nAccept: */*\r\n\r\n
Nov 18 17:52:23.297 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: polling with timeout of 200ms
Nov 18 17:52:23.300 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << HTTP/1.1 301 Moved Permanently\r\n
Nov 18 17:52:23.300 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n
Nov 18 17:52:23.300 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Date: Sun, 18 Nov 2018 17:52:23 GMT\r\n
Nov 18 17:52:23.300 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Location: /b\r\n
Nov 18 17:52:23.300 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Content-Length: 0\r\n
Nov 18 17:52:23.300 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << \r\n
Nov 18 17:52:23.301 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Connection #1 to host 127.0.0.1 left intact
Nov 18 17:52:23.301 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << HTTP/1.1 301 Moved Permanently\r\n
Nov 18 17:52:23.301 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n
Nov 18 17:52:23.301 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Date: Sun, 18 Nov 2018 17:52:23 GMT\r\n
Nov 18 17:52:23.301 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Location: /2\r\n
Nov 18 17:52:23.301 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Content-Length: 0\r\n
Nov 18 17:52:23.301 INFO [stderr] DEBUG 2018-11-18T17:52:23Z: chttp::internal::request: preparing for redirect to Some("/2")
Nov 18 17:52:23.301 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << \r\n
Nov 18 17:52:23.301 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Connection #2 to host 127.0.0.1 left intact
Nov 18 17:52:23.301 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Issue another request to this URL: 'http://127.0.0.1:43889/2'
Nov 18 17:52:23.301 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fbb7800ff60 [can pipeline]
Nov 18 17:52:23.301 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Could pipeline, but not asked to!
Nov 18 17:52:23.301 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Re-using existing connection! (#2) with host 127.0.0.1
Nov 18 17:52:23.301 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 43889 (#2)
Nov 18 17:52:23.301 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: >> GET /2 HTTP/1.1\r\nHost: 127.0.0.1:43889\r\nAccept: */*\r\n\r\n
Nov 18 17:52:23.301 INFO [stderr] DEBUG 2018-11-18T17:52:23Z: chttp::internal::agent: request with token 1 completed
Nov 18 17:52:23.301 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: polling with timeout of 200ms
Nov 18 17:52:23.312 INFO [stdout] test response_301_no_follow ... ok
Nov 18 17:52:23.313 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << HTTP/1.1 200 OK\r\n
Nov 18 17:52:23.313 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n
Nov 18 17:52:23.313 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Date: Sun, 18 Nov 2018 17:52:23 GMT\r\n
Nov 18 17:52:23.313 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Content-Type: text/plain; charset=utf8\r\n
Nov 18 17:52:23.316 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Content-Length: 2\r\n
Nov 18 17:52:23.316 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << \r\n
Nov 18 17:52:23.316 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << ok
Nov 18 17:52:23.316 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: received 2 bytes of data
Nov 18 17:52:23.316 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Connection #0 to host 127.0.0.1 left intact
Nov 18 17:52:23.316 INFO [stderr] DEBUG 2018-11-18T17:52:23Z: chttp::internal::agent: request with token 0 completed
Nov 18 17:52:23.316 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: polling with timeout of 200ms
Nov 18 17:52:23.316 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: received read request for 32 bytes
Nov 18 17:52:23.316 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: read buffer contains 2 bytes, consuming 2 bytes
Nov 18 17:52:23.316 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: received read request for 30 bytes
Nov 18 17:52:23.316 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: request is closed, satisfying read request with EOF
Nov 18 17:52:23.316 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << HTTP/1.1 301 Moved Permanently\r\n
Nov 18 17:52:23.316 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n
Nov 18 17:52:23.316 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Date: Sun, 18 Nov 2018 17:52:23 GMT\r\n
Nov 18 17:52:23.316 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Location: /3\r\n
Nov 18 17:52:23.316 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Content-Length: 0\r\n
Nov 18 17:52:23.317 INFO [stderr] DEBUG 2018-11-18T17:52:23Z: chttp::internal::request: preparing for redirect to Some("/3")
Nov 18 17:52:23.317 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << \r\n
Nov 18 17:52:23.317 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Connection #2 to host 127.0.0.1 left intact
Nov 18 17:52:23.317 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Issue another request to this URL: 'http://127.0.0.1:43889/3'
Nov 18 17:52:23.317 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fbb7800ff60 [can pipeline]
Nov 18 17:52:23.317 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Could pipeline, but not asked to!
Nov 18 17:52:23.317 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Re-using existing connection! (#2) with host 127.0.0.1
Nov 18 17:52:23.317 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 43889 (#2)
Nov 18 17:52:23.317 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: >> GET /3 HTTP/1.1\r\nHost: 127.0.0.1:43889\r\nAccept: */*\r\n\r\n
Nov 18 17:52:23.317 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: polling with timeout of 200ms
Nov 18 17:52:23.323 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << HTTP/1.1 301 Moved Permanently\r\n
Nov 18 17:52:23.323 INFO [stdout] test response_301_auto_follow ... ok
Nov 18 17:52:23.323 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n
Nov 18 17:52:23.324 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Date: Sun, 18 Nov 2018 17:52:23 GMT\r\n
Nov 18 17:52:23.324 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Location: /4\r\n
Nov 18 17:52:23.324 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Content-Length: 0\r\n
Nov 18 17:52:23.324 INFO [stderr] DEBUG 2018-11-18T17:52:23Z: chttp::internal::request: preparing for redirect to Some("/4")
Nov 18 17:52:23.324 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << \r\n
Nov 18 17:52:23.324 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Connection #2 to host 127.0.0.1 left intact
Nov 18 17:52:23.324 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Issue another request to this URL: 'http://127.0.0.1:43889/4'
Nov 18 17:52:23.324 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fbb7800ff60 [can pipeline]
Nov 18 17:52:23.324 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Could pipeline, but not asked to!
Nov 18 17:52:23.324 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Re-using existing connection! (#2) with host 127.0.0.1
Nov 18 17:52:23.324 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 43889 (#2)
Nov 18 17:52:23.324 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: >> GET /4 HTTP/1.1\r\nHost: 127.0.0.1:43889\r\nAccept: */*\r\n\r\n
Nov 18 17:52:23.324 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: polling with timeout of 200ms
Nov 18 17:52:23.343 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << HTTP/1.1 301 Moved Permanently\r\n
Nov 18 17:52:23.343 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n
Nov 18 17:52:23.343 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Date: Sun, 18 Nov 2018 17:52:23 GMT\r\n
Nov 18 17:52:23.343 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Location: /5\r\n
Nov 18 17:52:23.343 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Content-Length: 0\r\n
Nov 18 17:52:23.343 INFO [stderr] DEBUG 2018-11-18T17:52:23Z: chttp::internal::request: preparing for redirect to Some("/5")
Nov 18 17:52:23.343 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << \r\n
Nov 18 17:52:23.343 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Connection #2 to host 127.0.0.1 left intact
Nov 18 17:52:23.343 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Issue another request to this URL: 'http://127.0.0.1:43889/5'
Nov 18 17:52:23.343 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fbb7800ff60 [can pipeline]
Nov 18 17:52:23.343 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Could pipeline, but not asked to!
Nov 18 17:52:23.343 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Re-using existing connection! (#2) with host 127.0.0.1
Nov 18 17:52:23.343 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 43889 (#2)
Nov 18 17:52:23.343 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: >> GET /5 HTTP/1.1\r\nHost: 127.0.0.1:43889\r\nAccept: */*\r\n\r\n
Nov 18 17:52:23.343 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: polling with timeout of 200ms
Nov 18 17:52:23.351 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << HTTP/1.1 301 Moved Permanently\r\n
Nov 18 17:52:23.351 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n
Nov 18 17:52:23.351 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Date: Sun, 18 Nov 2018 17:52:23 GMT\r\n
Nov 18 17:52:23.351 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Location: /6\r\n
Nov 18 17:52:23.351 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Content-Length: 0\r\n
Nov 18 17:52:23.351 INFO [stderr] DEBUG 2018-11-18T17:52:23Z: chttp::internal::request: preparing for redirect to Some("/6")
Nov 18 17:52:23.351 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << \r\n
Nov 18 17:52:23.351 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Connection #2 to host 127.0.0.1 left intact
Nov 18 17:52:23.351 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Maximum (5) redirects followed
Nov 18 17:52:23.351 INFO [stderr] DEBUG 2018-11-18T17:52:23Z: chttp::internal::agent: curl error: [47] Number of redirects hit maximum amount
Nov 18 17:52:23.351 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: polling with timeout of 100ms
Nov 18 17:52:23.355 INFO [stdout] test redirect_limit_is_respected ... ok
Nov 18 17:52:23.355 INFO [stdout] 
Nov 18 17:52:23.355 INFO [stdout] test result: ok. 3 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 18 17:52:23.355 INFO [stdout] 
Nov 18 17:52:23.366 INFO [stderr]      Running /target/debug/deps/response-1aa9f1581e144f02
Nov 18 17:52:23.367 INFO [stdout] 
Nov 18 17:52:23.367 INFO [stdout] running 2 tests
Nov 18 17:52:23.395 INFO [stderr] DEBUG 2018-11-18T17:52:23Z: chttp::internal::agent: agent ready
Nov 18 17:52:23.395 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: received message from agent handle: BeginRequest(CurlRequest(Easy { handle: 0x7fcf9c025680, handler: 0x7fcf9c025680 }))
Nov 18 17:52:23.395 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request:   Trying 127.0.0.1...
Nov 18 17:52:23.395 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 33451 (#0)
Nov 18 17:52:23.395 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: >> GET / HTTP/1.1\r\nHost: 127.0.0.1:33451\r\nAccept: */*\r\n\r\n
Nov 18 17:52:23.395 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: polling with timeout of 200ms
Nov 18 17:52:23.395 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: woke up from notify fd
Nov 18 17:52:23.395 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: polling with timeout of 200ms
Nov 18 17:52:23.395 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: woke up from notify fd
Nov 18 17:52:23.395 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: received message from agent handle: BeginRequest(CurlRequest(Easy { handle: 0x7fcfa40021d0, handler: 0x7fcfa40021d0 }))
Nov 18 17:52:23.395 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fcf9400ff60 [serially]
Nov 18 17:52:23.395 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Server doesn't support multi-use (yet)
Nov 18 17:52:23.395 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request:   Trying 127.0.0.1...
Nov 18 17:52:23.395 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 38221 (#1)
Nov 18 17:52:23.395 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: >> GET / HTTP/1.1\r\nHost: 127.0.0.1:38221\r\nAccept: */*\r\n\r\n
Nov 18 17:52:23.395 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: polling with timeout of 200ms
Nov 18 17:52:23.417 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << HTTP/1.1 200 OK\r\n
Nov 18 17:52:23.417 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n
Nov 18 17:52:23.443 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Date: Sun, 18 Nov 2018 17:52:23 GMT\r\n
Nov 18 17:52:23.443 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Content-Type: text/plain; charset=utf8\r\n
Nov 18 17:52:23.443 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Content-Length: 13000\r\n
Nov 18 17:52:23.443 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << \r\n
Nov 18 17:52:23.443 INFO [stderr] TRACE 2018-11-18T17:52:23Z: 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 
Nov 18 17:52:23.443 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: received 8047 bytes of data
Nov 18 17:52:23.443 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << HTTP/1.1 200 OK\r\n
Nov 18 17:52:23.443 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n
Nov 18 17:52:23.443 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Date: Sun, 18 Nov 2018 17:52:23 GMT\r\n
Nov 18 17:52:23.443 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Content-Type: text/plain; charset=utf8\r\n
Nov 18 17:52:23.443 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << Content-Length: 11\r\n
Nov 18 17:52:23.451 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: received read request for 32 bytes
Nov 18 17:52:23.451 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: buffer is empty, read is pending
Nov 18 17:52:23.451 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: received read request for 32 bytes
Nov 18 17:52:23.451 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: read buffer contains 8047 bytes, consuming 32 bytes
Nov 18 17:52:23.451 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: received read request for 32 bytes
Nov 18 17:52:23.451 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: read buffer contains 8015 bytes, consuming 32 bytes
Nov 18 17:52:23.451 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: received read request for 64 bytes
Nov 18 17:52:23.451 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: read buffer contains 7983 bytes, consuming 64 bytes
Nov 18 17:52:23.451 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: received read request for 128 bytes
Nov 18 17:52:23.451 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: read buffer contains 7919 bytes, consuming 128 bytes
Nov 18 17:52:23.451 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: received read request for 256 bytes
Nov 18 17:52:23.451 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: read buffer contains 7791 bytes, consuming 256 bytes
Nov 18 17:52:23.451 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: received read request for 512 bytes
Nov 18 17:52:23.451 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: read buffer contains 7535 bytes, consuming 512 bytes
Nov 18 17:52:23.451 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: received read request for 1024 bytes
Nov 18 17:52:23.451 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: read buffer contains 7023 bytes, consuming 1024 bytes
Nov 18 17:52:23.451 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: received read request for 2048 bytes
Nov 18 17:52:23.451 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: read buffer contains 5999 bytes, consuming 2048 bytes
Nov 18 17:52:23.451 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: received read request for 4096 bytes
Nov 18 17:52:23.451 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: read buffer contains 3951 bytes, consuming 3951 bytes
Nov 18 17:52:23.451 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: received read request for 145 bytes
Nov 18 17:52:23.451 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: buffer is empty, read is pending
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << \r\n
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: << hello world
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: received 11 bytes of data
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: received read request for 32 bytes
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: read buffer contains 11 bytes, consuming 11 bytes
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: received read request for 21 bytes
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: buffer is empty, read is pending
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Connection #1 to host 127.0.0.1 left intact
Nov 18 17:52:23.459 INFO [stderr] DEBUG 2018-11-18T17:52:23Z: chttp::internal::agent: request with token 1 completed
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: received read request for 21 bytes
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: request is closed, satisfying read request with EOF
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: polling with timeout of 200ms
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: woke up from notify fd
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: received message from agent handle: UnpauseWrite(1)
Nov 18 17:52:23.459 INFO [stderr]  WARN 2018-11-18T17:52:23Z: chttp::internal::agent: received unpause request for unknown request token: 1
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: received message from agent handle: UnpauseWrite(0)
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: received message from agent handle: UnpauseWrite(1)
Nov 18 17:52:23.459 INFO [stderr]  WARN 2018-11-18T17:52:23Z: chttp::internal::agent: received unpause request for unknown request token: 1
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: 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 
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: received 4953 bytes of data
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: received read request for 145 bytes
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: read buffer contains 4953 bytes, consuming 145 bytes
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: received read request for 8192 bytes
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: read buffer contains 4808 bytes, consuming 4808 bytes
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: received read request for 3384 bytes
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: buffer is empty, read is pending
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Connection #0 to host 127.0.0.1 left intact
Nov 18 17:52:23.459 INFO [stderr] DEBUG 2018-11-18T17:52:23Z: chttp::internal::agent: request with token 0 completed
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: received read request for 3384 bytes
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: request is closed, satisfying read request with EOF
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: polling with timeout of 100ms
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: woke up from notify fd
Nov 18 17:52:23.459 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: received message from agent handle: UnpauseWrite(0)
Nov 18 17:52:23.459 INFO [stderr]  WARN 2018-11-18T17:52:23Z: chttp::internal::agent: received unpause request for unknown request token: 0
Nov 18 17:52:23.463 INFO [stdout] test simple_response_body ... ok
Nov 18 17:52:23.494 INFO [stdout] test large_response_body ... ok
Nov 18 17:52:23.494 INFO [stdout] 
Nov 18 17:52:23.494 INFO [stdout] test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 18 17:52:23.494 INFO [stdout] 
Nov 18 17:52:23.494 INFO [stdout] 
Nov 18 17:52:23.494 INFO [stdout] running 1 test
Nov 18 17:52:23.494 INFO [stderr]      Running /target/debug/deps/timeouts-b168e1c5934c1ede
Nov 18 17:52:23.515 INFO [stderr] DEBUG 2018-11-18T17:52:23Z: chttp::internal::agent: agent ready
Nov 18 17:52:23.515 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: received message from agent handle: BeginRequest(CurlRequest(Easy { handle: 0x7f46fc025f50, handler: 0x7f46fc025f50 }))
Nov 18 17:52:23.515 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request:   Trying 127.0.0.1...
Nov 18 17:52:23.515 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 36895 (#0)
Nov 18 17:52:23.515 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::request: >> POST / HTTP/1.1\r\nHost: 127.0.0.1:36895\r\nAccept: */*\r\nContent-Length: 11\r\nExpect: 100-continue\r\n\r\n
Nov 18 17:52:23.515 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: polling with timeout of 200ms
Nov 18 17:52:23.515 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: woke up from notify fd
Nov 18 17:52:23.515 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: polling with timeout of 200ms
Nov 18 17:52:23.711 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: polling with timeout of 200ms
Nov 18 17:52:23.919 INFO [stderr] TRACE 2018-11-18T17:52:23Z: chttp::internal::agent: polling with timeout of 200ms
Nov 18 17:52:24.127 INFO [stderr] TRACE 2018-11-18T17:52:24Z: chttp::internal::request: Done waiting for 100-continue
Nov 18 17:52:24.127 INFO [stderr] TRACE 2018-11-18T17:52:24Z: chttp::internal::agent: polling with timeout of 1s
Nov 18 17:52:24.127 INFO [stderr] TRACE 2018-11-18T17:52:24Z: chttp::internal::request: >> hello world
Nov 18 17:52:24.127 INFO [stderr] TRACE 2018-11-18T17:52:24Z: chttp::internal::request: We are completely uploaded and fine
Nov 18 17:52:24.127 INFO [stderr] TRACE 2018-11-18T17:52:24Z: chttp::internal::agent: polling with timeout of 1s
Nov 18 17:52:25.126 INFO [stderr] TRACE 2018-11-18T17:52:25Z: chttp::internal::request: Operation timed out after 2000 milliseconds with 0 bytes received
Nov 18 17:52:25.126 INFO [stderr] TRACE 2018-11-18T17:52:25Z: chttp::internal::request: Closing connection 0
Nov 18 17:52:25.126 INFO [stderr] DEBUG 2018-11-18T17:52:25Z: chttp::internal::agent: curl error: [28] Timeout was reached
Nov 18 17:52:25.126 INFO [stderr] TRACE 2018-11-18T17:52:25Z: chttp::internal::agent: polling with timeout of 100ms
Nov 18 17:52:25.126 INFO [stdout] test request_errors_if_read_timeout_is_reached ... ok
Nov 18 17:52:25.126 INFO [stdout] 
Nov 18 17:52:25.126 INFO [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 18 17:52:25.126 INFO [stdout] 
Nov 18 17:52:25.141 INFO [stderr]    Doc-tests chttp
Nov 18 17:52:31.879 INFO [stdout] 
Nov 18 17:52:31.879 INFO [stdout] running 6 tests
Nov 18 17:53:02.723 INFO [stdout] test src/lib.rs -  (line 53) ... ok
Nov 18 17:53:03.423 INFO [stdout] test src/lib.rs -  (line 74) ... ok
Nov 18 17:53:05.159 INFO [stdout] test src/client.rs - client::ClientBuilder (line 17) ... ok
Nov 18 17:53:05.648 INFO [stdout] test src/lib.rs -  (line 11) ... ok
Nov 18 17:53:05.806 INFO [stdout] test src/lib.rs -  (line 26) ... ok
Nov 18 17:53:05.896 INFO [stdout] test src/lib.rs -  (line 37) ... ok
Nov 18 17:53:05.896 INFO [stdout] 
Nov 18 17:53:05.897 INFO [stdout] test result: ok. 6 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 18 17:53:05.897 INFO [stdout] 
Nov 18 17:53:05.935 INFO [stderr] su: No module specific data is present
Nov 18 17:53:06.719 INFO running `"docker" "inspect" "d1ccdc2a11bea06f0057db2c426d55aeb7d5f44811aa0bc648fc0931b3d76804"`
Nov 18 17:53:07.138 INFO running `"docker" "rm" "-f" "d1ccdc2a11bea06f0057db2c426d55aeb7d5f44811aa0bc648fc0931b3d76804"`
Nov 18 17:53:07.471 INFO [stdout] d1ccdc2a11bea06f0057db2c426d55aeb7d5f44811aa0bc648fc0931b3d76804