Dec 06 18:00:19.200 INFO testing vigil-reporter-1.0.3 against master#906deae0790bd18681b937fe9a141a3c26cf1855 for pr-56514
Dec 06 18:00:19.200 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56514/worker-6/master#906deae0790bd18681b937fe9a141a3c26cf1855:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-6/pr-56514/master#906deae0790bd18681b937fe9a141a3c26cf1855:/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 +906deae0790bd18681b937fe9a141a3c26cf1855-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 06 18:00:19.712 INFO [stdout] e665859dc1d7c8a8160c75caa0004fb61dc418fad6d2af70879427e7221c3423
Dec 06 18:00:19.720 INFO running `"docker" "start" "-a" "e665859dc1d7c8a8160c75caa0004fb61dc418fad6d2af70879427e7221c3423"`
Dec 06 18:00:20.880 INFO [stderr] usermod: no changes
Dec 06 18:00:21.232 INFO [stderr]    Compiling sys-info v0.5.6
Dec 06 18:00:21.279 INFO [stderr]    Compiling hyper v0.11.27
Dec 06 18:00:35.709 INFO [stderr]    Compiling hyper-tls v0.1.4
Dec 06 18:00:40.256 INFO [stderr]    Compiling reqwest v0.8.8
Dec 06 18:00:50.609 INFO [stderr]    Compiling vigil-reporter v1.0.3 (/source)
Dec 06 18:00:56.104 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 35.18s
Dec 06 18:00:56.116 INFO [stderr] su: No module specific data is present
Dec 06 18:00:56.484 INFO running `"docker" "inspect" "e665859dc1d7c8a8160c75caa0004fb61dc418fad6d2af70879427e7221c3423"`
Dec 06 18:00:56.758 INFO running `"docker" "rm" "-f" "e665859dc1d7c8a8160c75caa0004fb61dc418fad6d2af70879427e7221c3423"`
Dec 06 18:00:56.912 INFO [stdout] e665859dc1d7c8a8160c75caa0004fb61dc418fad6d2af70879427e7221c3423
Dec 06 18:00:56.914 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56514/worker-6/master#906deae0790bd18681b937fe9a141a3c26cf1855:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-6/pr-56514/master#906deae0790bd18681b937fe9a141a3c26cf1855:/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 +906deae0790bd18681b937fe9a141a3c26cf1855-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 06 18:00:57.100 INFO [stdout] 9e3d20d89a0befb589ddf397e6f010ec0e370d98df797177303bff92b1f4e89c
Dec 06 18:00:57.102 INFO running `"docker" "start" "-a" "9e3d20d89a0befb589ddf397e6f010ec0e370d98df797177303bff92b1f4e89c"`
Dec 06 18:00:58.180 INFO [stderr] usermod: no changes
Dec 06 18:00:58.507 INFO [stderr]    Compiling vigil-reporter v1.0.3 (/source)
Dec 06 18:01:10.354 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 12.13s
Dec 06 18:01:10.369 INFO [stderr] su: No module specific data is present
Dec 06 18:01:10.882 INFO running `"docker" "inspect" "9e3d20d89a0befb589ddf397e6f010ec0e370d98df797177303bff92b1f4e89c"`
Dec 06 18:01:11.050 INFO running `"docker" "rm" "-f" "9e3d20d89a0befb589ddf397e6f010ec0e370d98df797177303bff92b1f4e89c"`
Dec 06 18:01:11.145 INFO [stdout] 9e3d20d89a0befb589ddf397e6f010ec0e370d98df797177303bff92b1f4e89c
Dec 06 18:01:11.147 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56514/worker-6/master#906deae0790bd18681b937fe9a141a3c26cf1855:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-6/pr-56514/master#906deae0790bd18681b937fe9a141a3c26cf1855:/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 +906deae0790bd18681b937fe9a141a3c26cf1855-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 06 18:01:11.300 INFO [stdout] e850b27f4ad031b0e970ed11506f7317d02e34922910fb5dd6027c545d01088a
Dec 06 18:01:11.302 INFO running `"docker" "start" "-a" "e850b27f4ad031b0e970ed11506f7317d02e34922910fb5dd6027c545d01088a"`
Dec 06 18:01:11.724 INFO [stderr] usermod: no changes
Dec 06 18:01:11.973 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.23s
Dec 06 18:01:11.981 INFO [stderr]      Running /target/debug/deps/vigil_reporter-ff5307cfea840a70
Dec 06 18:01:11.984 INFO [stdout] 
Dec 06 18:01:11.984 INFO [stdout] running 0 tests
Dec 06 18:01:11.984 INFO [stdout] 
Dec 06 18:01:11.984 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 06 18:01:11.984 INFO [stdout] 
Dec 06 18:01:11.984 INFO [stderr]      Running /target/debug/deps/report-6160435093f11600
Dec 06 18:01:11.988 INFO [stdout] 
Dec 06 18:01:11.988 INFO [stdout] running 5 tests
Dec 06 18:01:12.033 INFO [stdout] test initialize_valid ... ok
Dec 06 18:01:12.042 INFO [stderr] DEBUG 2018-12-06T18:01:12Z: vigil_reporter: Vigil Reporter: Will run using URL: http://status.example.com.local
Dec 06 18:01:12.101 INFO [stderr] TRACE 2018-12-06T18:01:12Z: mio::poll: registering with poller
Dec 06 18:01:12.101 INFO [stderr] TRACE 2018-12-06T18:01:12Z: mio::poll: registering with poller
Dec 06 18:01:12.101 INFO [stderr] TRACE 2018-12-06T18:01:12Z: mio::poll: registering with poller
Dec 06 18:01:12.101 INFO [stderr] TRACE 2018-12-06T18:01:12Z: mio::poll: registering with poller
Dec 06 18:01:12.101 INFO [stderr] TRACE 2018-12-06T18:01:12Z: mio::poll: registering with poller
Dec 06 18:01:12.101 INFO [stderr] TRACE 2018-12-06T18:01:12Z: mio::poll: registering with poller
Dec 06 18:01:12.102 INFO [stderr] TRACE 2018-12-06T18:01:12Z: mio::poll: registering with poller
Dec 06 18:01:12.102 INFO [stderr] TRACE 2018-12-06T18:01:12Z: mio::poll: registering with poller
Dec 06 18:01:12.106 INFO [stderr] TRACE 2018-12-06T18:01:12Z: tokio_threadpool::builder: build; num-workers=8
Dec 06 18:01:12.112 INFO [stderr] TRACE 2018-12-06T18:01:12Z: mio::poll: registering with poller
Dec 06 18:01:12.132 INFO [stderr] DEBUG 2018-12-06T18:01:12Z: tokio_reactor::background: starting background reactor
Dec 06 18:01:12.133 INFO [stderr] DEBUG 2018-12-06T18:01:12Z: tokio_core::reactor: consuming notification queue
Dec 06 18:01:12.133 INFO [stderr] DEBUG 2018-12-06T18:01:12Z: tokio_core::reactor: loop poll - 199.24µs
Dec 06 18:01:12.133 INFO [stderr] DEBUG 2018-12-06T18:01:12Z: tokio_core::reactor: loop time - Instant { tv_sec: 5792329, tv_nsec: 464835276 }
Dec 06 18:01:12.142 INFO [stderr] DEBUG 2018-12-06T18:01:12Z: tokio_core::reactor: loop process, 8.765895ms
Dec 06 18:01:12.142 INFO [stderr] DEBUG 2018-12-06T18:01:12Z: vigil_reporter: Vigil Reporter: Now running
Dec 06 18:01:12.238 INFO [stdout] test initialize_invalid_probe_id ... ok
Dec 06 18:01:12.238 INFO [stdout] test initialize_invalid_replica_id ... ok
Dec 06 18:01:12.238 INFO [stdout] test initialize_invalid_node_id ... ok
Dec 06 18:01:22.142 INFO [stderr] DEBUG 2018-12-06T18:01:22Z: vigil_reporter: Vigil Reporter: Will dispatch request
Dec 06 18:01:22.144 INFO [stderr] DEBUG 2018-12-06T18:01:22Z: 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: 3.96125, ram: 0.09795892 } }
Dec 06 18:01:22.145 INFO [stderr] DEBUG 2018-12-06T18:01:22Z: tokio_core::reactor: loop poll - 10.002529785s
Dec 06 18:01:22.145 INFO [stderr] DEBUG 2018-12-06T18:01:22Z: tokio_core::reactor: loop time - Instant { tv_sec: 5792339, tv_nsec: 476464498 }
Dec 06 18:01:22.145 INFO [stderr] DEBUG 2018-12-06T18:01:22Z: tokio_core::reactor: loop process, 587.693µs
Dec 06 18:01:22.146 INFO [stderr] TRACE 2018-12-06T18:01:22Z: hyper::client::pool: park; waiting for idle connection: "http://status.example.com.local"
Dec 06 18:01:22.146 INFO [stderr] TRACE 2018-12-06T18:01:22Z: hyper::client::connect: Http::connect("http://status.example.com.local/reporter/relay/socket-client/")
Dec 06 18:01:22.146 INFO [stderr] DEBUG 2018-12-06T18:01:22Z: tokio_core::reactor: loop poll - 799.893µs
Dec 06 18:01:22.147 INFO [stderr] DEBUG 2018-12-06T18:01:22Z: tokio_core::reactor: loop time - Instant { tv_sec: 5792339, tv_nsec: 478451900 }
Dec 06 18:01:22.147 INFO [stderr] DEBUG 2018-12-06T18:01:22Z: tokio_core::reactor: loop process, 592.035µs
Dec 06 18:01:22.147 INFO [stderr] DEBUG 2018-12-06T18:01:22Z: hyper::client::dns: resolving host="status.example.com.local", port=80
Dec 06 18:01:22.149 INFO [stderr] DEBUG 2018-12-06T18:01:22Z: tokio_core::reactor: loop poll - 2.061073ms
Dec 06 18:01:22.150 INFO [stderr] DEBUG 2018-12-06T18:01:22Z: tokio_core::reactor: loop time - Instant { tv_sec: 5792339, tv_nsec: 481370833 }
Dec 06 18:01:22.150 INFO [stderr] DEBUG 2018-12-06T18:01:22Z: tokio_core::reactor: loop process, 493.081µs
Dec 06 18:01:22.150 INFO [stderr] ERROR 2018-12-06T18:01:22Z: 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 06 18:01:22.150 INFO [stderr]  WARN 2018-12-06T18:01:22Z: vigil_reporter: Vigil Reporter: Last report failed, trying again sooner than usual
Dec 06 18:01:27.133 INFO [stdout] test run_and_end_valid ... ok
Dec 06 18:01:27.133 INFO [stdout] 
Dec 06 18:01:27.133 INFO [stdout] test result: ok. 5 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 06 18:01:27.133 INFO [stdout] 
Dec 06 18:01:27.140 INFO [stderr]    Doc-tests vigil_reporter
Dec 06 18:01:37.903 INFO [stdout] 
Dec 06 18:01:37.903 INFO [stdout] running 0 tests
Dec 06 18:01:37.903 INFO [stdout] 
Dec 06 18:01:37.903 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 06 18:01:37.903 INFO [stdout] 
Dec 06 18:01:37.916 INFO [stderr] su: No module specific data is present
Dec 06 18:01:38.628 INFO running `"docker" "inspect" "e850b27f4ad031b0e970ed11506f7317d02e34922910fb5dd6027c545d01088a"`
Dec 06 18:01:38.880 INFO running `"docker" "rm" "-f" "e850b27f4ad031b0e970ed11506f7317d02e34922910fb5dd6027c545d01088a"`
Dec 06 18:01:39.336 INFO [stdout] e850b27f4ad031b0e970ed11506f7317d02e34922910fb5dd6027c545d01088a