Dec 14 14:37:57.196 INFO testing vigil-reporter-1.0.3 against master#bd47d6825bf4090517549d33cfef10d3300b4a75 for pr-56550
Dec 14 14:37:57.196 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-1/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-1/pr-56550/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/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 +bd47d6825bf4090517549d33cfef10d3300b4a75-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:57.743 INFO [stdout] 796fcbe6fbc36a77326c3fe38163297e85dceb7a7db03f1efa8674eff61462bf
Dec 14 14:37:57.747 INFO running `"docker" "start" "-a" "796fcbe6fbc36a77326c3fe38163297e85dceb7a7db03f1efa8674eff61462bf"`
Dec 14 14:37:58.918 INFO [stderr] usermod: no changes
Dec 14 14:37:59.395 INFO [stderr]    Compiling hyper v0.11.27
Dec 14 14:38:11.248 INFO [stderr]    Compiling hyper-tls v0.1.4
Dec 14 14:38:15.433 INFO [stderr]    Compiling reqwest v0.8.8
Dec 14 14:38:25.953 INFO [stderr]    Compiling vigil-reporter v1.0.3 (/source)
Dec 14 14:38:31.706 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 32.74s
Dec 14 14:38:31.725 INFO [stderr] su: No module specific data is present
Dec 14 14:38:32.332 INFO running `"docker" "inspect" "796fcbe6fbc36a77326c3fe38163297e85dceb7a7db03f1efa8674eff61462bf"`
Dec 14 14:38:32.457 INFO running `"docker" "rm" "-f" "796fcbe6fbc36a77326c3fe38163297e85dceb7a7db03f1efa8674eff61462bf"`
Dec 14 14:38:32.599 INFO [stdout] 796fcbe6fbc36a77326c3fe38163297e85dceb7a7db03f1efa8674eff61462bf
Dec 14 14:38:32.599 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-1/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-1/pr-56550/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/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 +bd47d6825bf4090517549d33cfef10d3300b4a75-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:32.825 INFO [stdout] e665541da0b5c8de7b26989734beec8a03b9f070e2635f6bfa9621aa2de84333
Dec 14 14:38:32.827 INFO running `"docker" "start" "-a" "e665541da0b5c8de7b26989734beec8a03b9f070e2635f6bfa9621aa2de84333"`
Dec 14 14:38:33.237 INFO [stderr] usermod: no changes
Dec 14 14:38:33.450 INFO [stderr]    Compiling vigil-reporter v1.0.3 (/source)
Dec 14 14:38:48.280 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 15.02s
Dec 14 14:38:48.297 INFO [stderr] su: No module specific data is present
Dec 14 14:38:48.741 INFO running `"docker" "inspect" "e665541da0b5c8de7b26989734beec8a03b9f070e2635f6bfa9621aa2de84333"`
Dec 14 14:38:48.851 INFO running `"docker" "rm" "-f" "e665541da0b5c8de7b26989734beec8a03b9f070e2635f6bfa9621aa2de84333"`
Dec 14 14:38:48.960 INFO [stdout] e665541da0b5c8de7b26989734beec8a03b9f070e2635f6bfa9621aa2de84333
Dec 14 14:38:48.962 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-1/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-1/pr-56550/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/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 +bd47d6825bf4090517549d33cfef10d3300b4a75-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:49.225 INFO [stdout] cef4665279b189c70896263c93ef716486fa0a832a2fd58197d0eabea9e34a97
Dec 14 14:38:49.228 INFO running `"docker" "start" "-a" "cef4665279b189c70896263c93ef716486fa0a832a2fd58197d0eabea9e34a97"`
Dec 14 14:38:51.621 INFO [stderr] usermod: no changes
Dec 14 14:38:51.908 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.26s
Dec 14 14:38:51.917 INFO [stderr]      Running /target/debug/deps/vigil_reporter-b505bf842317b6bb
Dec 14 14:38:51.925 INFO [stdout] 
Dec 14 14:38:51.925 INFO [stdout] running 0 tests
Dec 14 14:38:51.925 INFO [stdout] 
Dec 14 14:38:51.925 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 14 14:38:51.925 INFO [stdout] 
Dec 14 14:38:51.943 INFO [stderr]      Running /target/debug/deps/report-4dacd155df7c8573
Dec 14 14:38:51.965 INFO [stdout] 
Dec 14 14:38:51.965 INFO [stdout] running 5 tests
Dec 14 14:38:51.995 INFO [stdout] test initialize_valid ... ok
Dec 14 14:38:52.027 INFO [stderr] DEBUG 2018-12-14T14:38:52Z: vigil_reporter: Vigil Reporter: Will run using URL: http://status.example.com.local
Dec 14 14:38:52.051 INFO [stderr] TRACE 2018-12-14T14:38:52Z: mio::poll: registering with poller
Dec 14 14:38:52.051 INFO [stderr] TRACE 2018-12-14T14:38:52Z: mio::poll: registering with poller
Dec 14 14:38:52.052 INFO [stderr] TRACE 2018-12-14T14:38:52Z: mio::poll: registering with poller
Dec 14 14:38:52.052 INFO [stderr] TRACE 2018-12-14T14:38:52Z: mio::poll: registering with poller
Dec 14 14:38:52.052 INFO [stderr] TRACE 2018-12-14T14:38:52Z: mio::poll: registering with poller
Dec 14 14:38:52.052 INFO [stderr] TRACE 2018-12-14T14:38:52Z: mio::poll: registering with poller
Dec 14 14:38:52.053 INFO [stderr] TRACE 2018-12-14T14:38:52Z: mio::poll: registering with poller
Dec 14 14:38:52.053 INFO [stderr] TRACE 2018-12-14T14:38:52Z: mio::poll: registering with poller
Dec 14 14:38:52.059 INFO [stderr] TRACE 2018-12-14T14:38:52Z: tokio_threadpool::builder: build; num-workers=8
Dec 14 14:38:52.095 INFO [stderr] TRACE 2018-12-14T14:38:52Z: mio::poll: registering with poller
Dec 14 14:38:52.103 INFO [stderr] DEBUG 2018-12-14T14:38:52Z: tokio_reactor::background: starting background reactor
Dec 14 14:38:52.147 INFO [stderr] DEBUG 2018-12-14T14:38:52Z: tokio_core::reactor: consuming notification queue
Dec 14 14:38:52.147 INFO [stderr] DEBUG 2018-12-14T14:38:52Z: tokio_core::reactor: loop poll - 316.883µs
Dec 14 14:38:52.147 INFO [stderr] DEBUG 2018-12-14T14:38:52Z: tokio_core::reactor: loop time - Instant { tv_sec: 6471508, tv_nsec: 28619250 }
Dec 14 14:38:52.147 INFO [stderr] DEBUG 2018-12-14T14:38:52Z: tokio_core::reactor: loop process, 143.472µs
Dec 14 14:38:52.179 INFO [stderr] DEBUG 2018-12-14T14:38:52Z: vigil_reporter: Vigil Reporter: Now running
Dec 14 14:38:52.327 INFO [stdout] test initialize_invalid_node_id ... ok
Dec 14 14:38:52.328 INFO [stdout] test initialize_invalid_replica_id ... ok
Dec 14 14:38:52.328 INFO [stdout] test initialize_invalid_probe_id ... ok
Dec 14 14:39:02.187 INFO [stderr] DEBUG 2018-12-14T14:39:02Z: vigil_reporter: Vigil Reporter: Will dispatch request
Dec 14 14:39:02.187 INFO [stderr] DEBUG 2018-12-14T14:39:02Z: 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.18875, ram: 0.125314 } }
Dec 14 14:39:02.187 INFO [stderr] DEBUG 2018-12-14T14:39:02Z: tokio_core::reactor: loop poll - 10.032771538s
Dec 14 14:39:02.187 INFO [stderr] DEBUG 2018-12-14T14:39:02Z: tokio_core::reactor: loop time - Instant { tv_sec: 6471518, tv_nsec: 61594134 }
Dec 14 14:39:02.187 INFO [stderr] DEBUG 2018-12-14T14:39:02Z: tokio_core::reactor: loop process, 58.986µs
Dec 14 14:39:02.187 INFO [stderr] TRACE 2018-12-14T14:39:02Z: hyper::client::pool: park; waiting for idle connection: "http://status.example.com.local"
Dec 14 14:39:02.187 INFO [stderr] TRACE 2018-12-14T14:39:02Z: hyper::client::connect: Http::connect("http://status.example.com.local/reporter/relay/socket-client/")
Dec 14 14:39:02.187 INFO [stderr] DEBUG 2018-12-14T14:39:02Z: hyper::client::dns: resolving host="status.example.com.local", port=80
Dec 14 14:39:02.187 INFO [stderr] DEBUG 2018-12-14T14:39:02Z: tokio_core::reactor: loop poll - 777.362µs
Dec 14 14:39:02.187 INFO [stderr] DEBUG 2018-12-14T14:39:02Z: tokio_core::reactor: loop time - Instant { tv_sec: 6471518, tv_nsec: 62738489 }
Dec 14 14:39:02.187 INFO [stderr] DEBUG 2018-12-14T14:39:02Z: tokio_core::reactor: loop process, 56.179µs
Dec 14 14:39:02.187 INFO [stderr] DEBUG 2018-12-14T14:39:02Z: tokio_core::reactor: loop poll - 965.218µs
Dec 14 14:39:02.187 INFO [stderr] DEBUG 2018-12-14T14:39:02Z: tokio_core::reactor: loop time - Instant { tv_sec: 6471518, tv_nsec: 63791736 }
Dec 14 14:39:02.187 INFO [stderr] ERROR 2018-12-14T14:39:02Z: 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:39:02.187 INFO [stderr] DEBUG 2018-12-14T14:39:02Z: tokio_core::reactor: loop process, 54.735µs
Dec 14 14:39:02.187 INFO [stderr]  WARN 2018-12-14T14:39:02Z: vigil_reporter: Vigil Reporter: Last report failed, trying again sooner than usual
Dec 14 14:39:07.167 INFO [stdout] test run_and_end_valid ... ok
Dec 14 14:39:07.167 INFO [stdout] 
Dec 14 14:39:07.167 INFO [stdout] test result: ok. 5 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 14 14:39:07.167 INFO [stdout] 
Dec 14 14:39:07.171 INFO [stderr]    Doc-tests vigil_reporter
Dec 14 14:39:18.035 INFO [stdout] 
Dec 14 14:39:18.035 INFO [stdout] running 0 tests
Dec 14 14:39:18.035 INFO [stdout] 
Dec 14 14:39:18.035 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 14 14:39:18.035 INFO [stdout] 
Dec 14 14:39:18.038 INFO [stderr] su: No module specific data is present
Dec 14 14:39:18.880 INFO running `"docker" "inspect" "cef4665279b189c70896263c93ef716486fa0a832a2fd58197d0eabea9e34a97"`
Dec 14 14:39:19.133 INFO running `"docker" "rm" "-f" "cef4665279b189c70896263c93ef716486fa0a832a2fd58197d0eabea9e34a97"`
Dec 14 14:39:19.407 INFO [stdout] cef4665279b189c70896263c93ef716486fa0a832a2fd58197d0eabea9e34a97