Dec 14 14:37:52.172 INFO testing vigil-reporter-1.0.3 against try#aa49d8ef14939ddec0e34b346b60174a5673d48f for pr-56550
Dec 14 14:37:52.172 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-4/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-4/pr-56550/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/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 +aa49d8ef14939ddec0e34b346b60174a5673d48f-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"`
Dec 14 14:37:52.685 INFO [stdout] d17235a6207f008a7e430f48038e296e68e19426f20a30593090c2860eb678d7
Dec 14 14:37:52.689 INFO running `"docker" "start" "-a" "d17235a6207f008a7e430f48038e296e68e19426f20a30593090c2860eb678d7"`
Dec 14 14:37:53.908 INFO [stderr] usermod: no changes
Dec 14 14:37:54.222 INFO [stderr]    Compiling sys-info v0.5.6
Dec 14 14:37:54.228 INFO [stderr]    Compiling hyper v0.11.27
Dec 14 14:37:54.228 INFO [stderr]    Compiling tokio-tls v0.1.4
Dec 14 14:38:08.140 INFO [stderr]    Compiling hyper-tls v0.1.4
Dec 14 14:38:12.309 INFO [stderr]    Compiling reqwest v0.8.8
Dec 14 14:38:21.665 INFO [stderr]    Compiling vigil-reporter v1.0.3 (/source)
Dec 14 14:38:27.469 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 33.52s
Dec 14 14:38:27.482 INFO [stderr] su: No module specific data is present
Dec 14 14:38:28.052 INFO running `"docker" "inspect" "d17235a6207f008a7e430f48038e296e68e19426f20a30593090c2860eb678d7"`
Dec 14 14:38:28.193 INFO running `"docker" "rm" "-f" "d17235a6207f008a7e430f48038e296e68e19426f20a30593090c2860eb678d7"`
Dec 14 14:38:28.399 INFO [stdout] d17235a6207f008a7e430f48038e296e68e19426f20a30593090c2860eb678d7
Dec 14 14:38:28.405 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-4/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-4/pr-56550/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/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 +aa49d8ef14939ddec0e34b346b60174a5673d48f-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"`
Dec 14 14:38:28.790 INFO [stdout] d4cfb2e4693c83c5d280a7c492fbc7369311adcc19845ac314fe660282ab0caa
Dec 14 14:38:28.792 INFO running `"docker" "start" "-a" "d4cfb2e4693c83c5d280a7c492fbc7369311adcc19845ac314fe660282ab0caa"`
Dec 14 14:38:29.487 INFO [stderr] usermod: no changes
Dec 14 14:38:29.771 INFO [stderr]    Compiling vigil-reporter v1.0.3 (/source)
Dec 14 14:38:41.579 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 12.07s
Dec 14 14:38:41.606 INFO [stderr] su: No module specific data is present
Dec 14 14:38:42.235 INFO running `"docker" "inspect" "d4cfb2e4693c83c5d280a7c492fbc7369311adcc19845ac314fe660282ab0caa"`
Dec 14 14:38:42.461 INFO running `"docker" "rm" "-f" "d4cfb2e4693c83c5d280a7c492fbc7369311adcc19845ac314fe660282ab0caa"`
Dec 14 14:38:42.643 INFO [stdout] d4cfb2e4693c83c5d280a7c492fbc7369311adcc19845ac314fe660282ab0caa
Dec 14 14:38:42.649 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-4/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-4/pr-56550/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/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 +aa49d8ef14939ddec0e34b346b60174a5673d48f-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"`
Dec 14 14:38:42.889 INFO [stdout] 4fb509309a5057fbec60e6620539483ec928824feb85457f7790cddb8430e9df
Dec 14 14:38:42.893 INFO running `"docker" "start" "-a" "4fb509309a5057fbec60e6620539483ec928824feb85457f7790cddb8430e9df"`
Dec 14 14:38:43.779 INFO [stderr] usermod: no changes
Dec 14 14:38:44.002 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.20s
Dec 14 14:38:44.023 INFO [stderr]      Running /target/debug/deps/vigil_reporter-34fc9373de3c83cc
Dec 14 14:38:44.027 INFO [stdout] 
Dec 14 14:38:44.027 INFO [stdout] running 0 tests
Dec 14 14:38:44.027 INFO [stdout] 
Dec 14 14:38:44.027 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 14 14:38:44.027 INFO [stdout] 
Dec 14 14:38:44.028 INFO [stderr]      Running /target/debug/deps/report-6c326b1c579b010c
Dec 14 14:38:44.038 INFO [stdout] 
Dec 14 14:38:44.038 INFO [stdout] running 5 tests
Dec 14 14:38:44.048 INFO [stdout] test initialize_valid ... ok
Dec 14 14:38:44.066 INFO [stderr] DEBUG 2018-12-14T14:38:44Z: vigil_reporter: Vigil Reporter: Will run using URL: http://status.example.com.local
Dec 14 14:38:44.111 INFO [stderr] TRACE 2018-12-14T14:38:44Z: mio::poll: registering with poller
Dec 14 14:38:44.111 INFO [stderr] TRACE 2018-12-14T14:38:44Z: mio::poll: registering with poller
Dec 14 14:38:44.111 INFO [stderr] TRACE 2018-12-14T14:38:44Z: mio::poll: registering with poller
Dec 14 14:38:44.111 INFO [stderr] TRACE 2018-12-14T14:38:44Z: mio::poll: registering with poller
Dec 14 14:38:44.111 INFO [stderr] TRACE 2018-12-14T14:38:44Z: mio::poll: registering with poller
Dec 14 14:38:44.111 INFO [stderr] TRACE 2018-12-14T14:38:44Z: mio::poll: registering with poller
Dec 14 14:38:44.111 INFO [stderr] TRACE 2018-12-14T14:38:44Z: mio::poll: registering with poller
Dec 14 14:38:44.111 INFO [stderr] TRACE 2018-12-14T14:38:44Z: mio::poll: registering with poller
Dec 14 14:38:44.111 INFO [stderr] TRACE 2018-12-14T14:38:44Z: tokio_threadpool::builder: build; num-workers=8
Dec 14 14:38:44.111 INFO [stderr] TRACE 2018-12-14T14:38:44Z: mio::poll: registering with poller
Dec 14 14:38:44.111 INFO [stderr] DEBUG 2018-12-14T14:38:44Z: tokio_core::reactor: consuming notification queue
Dec 14 14:38:44.111 INFO [stderr] DEBUG 2018-12-14T14:38:44Z: tokio_core::reactor: loop poll - 69.796µs
Dec 14 14:38:44.111 INFO [stderr] DEBUG 2018-12-14T14:38:44Z: tokio_core::reactor: loop time - Instant { tv_sec: 6471499, tv_nsec: 990794167 }
Dec 14 14:38:44.111 INFO [stderr] DEBUG 2018-12-14T14:38:44Z: tokio_core::reactor: loop process, 50.129µs
Dec 14 14:38:44.135 INFO [stderr] DEBUG 2018-12-14T14:38:44Z: tokio_reactor::background: starting background reactor
Dec 14 14:38:44.135 INFO [stderr] DEBUG 2018-12-14T14:38:44Z: vigil_reporter: Vigil Reporter: Now running
Dec 14 14:38:44.251 INFO [stdout] test initialize_invalid_node_id ... ok
Dec 14 14:38:44.251 INFO [stdout] test initialize_invalid_probe_id ... ok
Dec 14 14:38:44.251 INFO [stdout] test initialize_invalid_replica_id ... ok
Dec 14 14:38:54.131 INFO [stderr] DEBUG 2018-12-14T14:38:54Z: vigil_reporter: Vigil Reporter: Will dispatch request
Dec 14 14:38:54.135 INFO [stderr] DEBUG 2018-12-14T14:38:54Z: vigil_reporter: Vigil Reporter: Will send request to URL: http://status.example.com.local/reporter/relay/socket-client/ with payload: ReportPayload { replica: "192.168.1.10", interval: 30, load: ReportPayloadLoad { cpu: 4.195, ram: 0.1456042 } }
Dec 14 14:38:54.135 INFO [stderr] DEBUG 2018-12-14T14:38:54Z: tokio_core::reactor: loop poll - 10.022991481s
Dec 14 14:38:54.135 INFO [stderr] DEBUG 2018-12-14T14:38:54Z: tokio_core::reactor: loop time - Instant { tv_sec: 6471510, tv_nsec: 13862929 }
Dec 14 14:38:54.135 INFO [stderr] DEBUG 2018-12-14T14:38:54Z: tokio_core::reactor: loop process, 56.909µs
Dec 14 14:38:54.135 INFO [stderr] TRACE 2018-12-14T14:38:54Z: hyper::client::pool: park; waiting for idle connection: "http://status.example.com.local"
Dec 14 14:38:54.135 INFO [stderr] TRACE 2018-12-14T14:38:54Z: hyper::client::connect: Http::connect("http://status.example.com.local/reporter/relay/socket-client/")
Dec 14 14:38:54.135 INFO [stderr] DEBUG 2018-12-14T14:38:54Z: tokio_core::reactor: loop poll - 240.822µs
Dec 14 14:38:54.135 INFO [stderr] DEBUG 2018-12-14T14:38:54Z: tokio_core::reactor: loop time - Instant { tv_sec: 6471510, tv_nsec: 14468738 }
Dec 14 14:38:54.135 INFO [stderr] DEBUG 2018-12-14T14:38:54Z: tokio_core::reactor: loop process, 40.807µs
Dec 14 14:38:54.135 INFO [stderr] DEBUG 2018-12-14T14:38:54Z: hyper::client::dns: resolving host="status.example.com.local", port=80
Dec 14 14:38:54.136 INFO [stderr] DEBUG 2018-12-14T14:38:54Z: tokio_core::reactor: loop poll - 2.589142ms
Dec 14 14:38:54.136 INFO [stderr] DEBUG 2018-12-14T14:38:54Z: tokio_core::reactor: loop time - Instant { tv_sec: 6471510, tv_nsec: 17124978 }
Dec 14 14:38:54.136 INFO [stderr] DEBUG 2018-12-14T14:38:54Z: tokio_core::reactor: loop process, 74.491µs
Dec 14 14:38:54.136 INFO [stderr] ERROR 2018-12-14T14:38:54Z: vigil_reporter: Vigil Reporter: Failed dispatching request: http://status.example.com.local/reporter/relay/socket-client/: failed to lookup address information: Temporary failure in name resolution
Dec 14 14:38:54.136 INFO [stderr]  WARN 2018-12-14T14:38:54Z: vigil_reporter: Vigil Reporter: Last report failed, trying again sooner than usual
Dec 14 14:38:59.127 INFO [stdout] test run_and_end_valid ... ok
Dec 14 14:38:59.127 INFO [stdout] 
Dec 14 14:38:59.128 INFO [stdout] test result: ok. 5 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 14 14:38:59.128 INFO [stdout] 
Dec 14 14:38:59.133 INFO [stderr]    Doc-tests vigil_reporter
Dec 14 14:39:09.175 INFO [stdout] 
Dec 14 14:39:09.175 INFO [stdout] running 0 tests
Dec 14 14:39:09.175 INFO [stdout] 
Dec 14 14:39:09.175 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 14 14:39:09.175 INFO [stdout] 
Dec 14 14:39:09.189 INFO [stderr] su: No module specific data is present
Dec 14 14:39:10.021 INFO running `"docker" "inspect" "4fb509309a5057fbec60e6620539483ec928824feb85457f7790cddb8430e9df"`
Dec 14 14:39:10.203 INFO running `"docker" "rm" "-f" "4fb509309a5057fbec60e6620539483ec928824feb85457f7790cddb8430e9df"`
Dec 14 14:39:10.367 INFO [stdout] 4fb509309a5057fbec60e6620539483ec928824feb85457f7790cddb8430e9df