Dec 06 18:00:10.369 INFO testing vigil-reporter-1.0.3 against try#6eb0fd3ac58f9b16bddb9924a17c3b6c156aa468 for pr-56514
Dec 06 18:00:10.369 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56514/worker-3/try#6eb0fd3ac58f9b16bddb9924a17c3b6c156aa468:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-3/pr-56514/try#6eb0fd3ac58f9b16bddb9924a17c3b6c156aa468:/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 +6eb0fd3ac58f9b16bddb9924a17c3b6c156aa468-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:10.928 INFO [stdout] d6ddea62a76b5fd182166bb3583198679aefc35a33486c7a61e366c62849333e
Dec 06 18:00:10.930 INFO running `"docker" "start" "-a" "d6ddea62a76b5fd182166bb3583198679aefc35a33486c7a61e366c62849333e"`
Dec 06 18:00:11.817 INFO [stderr] usermod: no changes
Dec 06 18:00:12.076 INFO [stderr]    Compiling sys-info v0.5.6
Dec 06 18:00:12.084 INFO [stderr]    Compiling hyper v0.11.27
Dec 06 18:00:26.709 INFO [stderr]    Compiling hyper-tls v0.1.4
Dec 06 18:00:31.416 INFO [stderr]    Compiling reqwest v0.8.8
Dec 06 18:00:42.514 INFO [stderr]    Compiling vigil-reporter v1.0.3 (/source)
Dec 06 18:00:48.711 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 36.86s
Dec 06 18:00:48.740 INFO [stderr] su: No module specific data is present
Dec 06 18:00:49.434 INFO running `"docker" "inspect" "d6ddea62a76b5fd182166bb3583198679aefc35a33486c7a61e366c62849333e"`
Dec 06 18:00:49.708 INFO running `"docker" "rm" "-f" "d6ddea62a76b5fd182166bb3583198679aefc35a33486c7a61e366c62849333e"`
Dec 06 18:00:50.054 INFO [stdout] d6ddea62a76b5fd182166bb3583198679aefc35a33486c7a61e366c62849333e
Dec 06 18:00:50.057 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56514/worker-3/try#6eb0fd3ac58f9b16bddb9924a17c3b6c156aa468:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-3/pr-56514/try#6eb0fd3ac58f9b16bddb9924a17c3b6c156aa468:/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 +6eb0fd3ac58f9b16bddb9924a17c3b6c156aa468-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:50.496 INFO [stdout] e88996922cab1d4273b2cf3df0cc394400f88f5cbb06cf1bf4c7316adc032858
Dec 06 18:00:50.504 INFO running `"docker" "start" "-a" "e88996922cab1d4273b2cf3df0cc394400f88f5cbb06cf1bf4c7316adc032858"`
Dec 06 18:00:51.460 INFO [stderr] usermod: no changes
Dec 06 18:00:51.713 INFO [stderr]    Compiling vigil-reporter v1.0.3 (/source)
Dec 06 18:01:02.864 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 11.38s
Dec 06 18:01:02.881 INFO [stderr] su: No module specific data is present
Dec 06 18:01:03.260 INFO running `"docker" "inspect" "e88996922cab1d4273b2cf3df0cc394400f88f5cbb06cf1bf4c7316adc032858"`
Dec 06 18:01:03.387 INFO running `"docker" "rm" "-f" "e88996922cab1d4273b2cf3df0cc394400f88f5cbb06cf1bf4c7316adc032858"`
Dec 06 18:01:03.493 INFO [stdout] e88996922cab1d4273b2cf3df0cc394400f88f5cbb06cf1bf4c7316adc032858
Dec 06 18:01:03.497 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56514/worker-3/try#6eb0fd3ac58f9b16bddb9924a17c3b6c156aa468:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-3/pr-56514/try#6eb0fd3ac58f9b16bddb9924a17c3b6c156aa468:/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 +6eb0fd3ac58f9b16bddb9924a17c3b6c156aa468-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:03.780 INFO [stdout] 7b5b8022f9db0b52b0e3d23b50ef2b3051b2fa223d7dfbcb1d1563e1eb1f5c86
Dec 06 18:01:03.782 INFO running `"docker" "start" "-a" "7b5b8022f9db0b52b0e3d23b50ef2b3051b2fa223d7dfbcb1d1563e1eb1f5c86"`
Dec 06 18:01:04.320 INFO [stderr] usermod: no changes
Dec 06 18:01:04.529 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.19s
Dec 06 18:01:04.546 INFO [stderr]      Running /target/debug/deps/vigil_reporter-9a8e888d1fa248f7
Dec 06 18:01:04.550 INFO [stderr]      Running /target/debug/deps/report-e76c827bbac9356f
Dec 06 18:01:04.550 INFO [stdout] 
Dec 06 18:01:04.550 INFO [stdout] running 0 tests
Dec 06 18:01:04.550 INFO [stdout] 
Dec 06 18:01:04.550 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 06 18:01:04.550 INFO [stdout] 
Dec 06 18:01:04.555 INFO [stdout] 
Dec 06 18:01:04.555 INFO [stdout] running 5 tests
Dec 06 18:01:04.557 INFO [stdout] test initialize_valid ... ok
Dec 06 18:01:04.557 INFO [stderr] DEBUG 2018-12-06T18:01:04Z: vigil_reporter: Vigil Reporter: Will run using URL: http://status.example.com.local
Dec 06 18:01:04.567 INFO [stderr] TRACE 2018-12-06T18:01:04Z: mio::poll: registering with poller
Dec 06 18:01:04.567 INFO [stderr] TRACE 2018-12-06T18:01:04Z: mio::poll: registering with poller
Dec 06 18:01:04.567 INFO [stderr] TRACE 2018-12-06T18:01:04Z: mio::poll: registering with poller
Dec 06 18:01:04.567 INFO [stderr] TRACE 2018-12-06T18:01:04Z: mio::poll: registering with poller
Dec 06 18:01:04.568 INFO [stderr] TRACE 2018-12-06T18:01:04Z: mio::poll: registering with poller
Dec 06 18:01:04.568 INFO [stderr] TRACE 2018-12-06T18:01:04Z: mio::poll: registering with poller
Dec 06 18:01:04.568 INFO [stderr] TRACE 2018-12-06T18:01:04Z: mio::poll: registering with poller
Dec 06 18:01:04.568 INFO [stderr] TRACE 2018-12-06T18:01:04Z: mio::poll: registering with poller
Dec 06 18:01:04.569 INFO [stderr] TRACE 2018-12-06T18:01:04Z: tokio_threadpool::builder: build; num-workers=8
Dec 06 18:01:04.569 INFO [stderr] TRACE 2018-12-06T18:01:04Z: mio::poll: registering with poller
Dec 06 18:01:04.572 INFO [stderr] DEBUG 2018-12-06T18:01:04Z: tokio_core::reactor: consuming notification queue
Dec 06 18:01:04.572 INFO [stderr] DEBUG 2018-12-06T18:01:04Z: tokio_core::reactor: loop poll - 64.813µs
Dec 06 18:01:04.572 INFO [stderr] DEBUG 2018-12-06T18:01:04Z: tokio_core::reactor: loop time - Instant { tv_sec: 5792321, tv_nsec: 901782996 }
Dec 06 18:01:04.572 INFO [stderr] DEBUG 2018-12-06T18:01:04Z: tokio_core::reactor: loop process, 48.149µs
Dec 06 18:01:04.578 INFO [stderr] DEBUG 2018-12-06T18:01:04Z: tokio_reactor::background: starting background reactor
Dec 06 18:01:04.579 INFO [stderr] DEBUG 2018-12-06T18:01:04Z: vigil_reporter: Vigil Reporter: Now running
Dec 06 18:01:04.644 INFO [stdout] test initialize_invalid_replica_id ... ok
Dec 06 18:01:04.644 INFO [stdout] test initialize_invalid_node_id ... ok
Dec 06 18:01:04.644 INFO [stdout] test initialize_invalid_probe_id ... ok
Dec 06 18:01:14.579 INFO [stderr] DEBUG 2018-12-06T18:01:14Z: vigil_reporter: Vigil Reporter: Will dispatch request
Dec 06 18:01:14.580 INFO [stderr] DEBUG 2018-12-06T18:01:14Z: 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.975, ram: 0.15382105 } }
Dec 06 18:01:14.580 INFO [stderr] DEBUG 2018-12-06T18:01:14Z: tokio_core::reactor: loop poll - 10.010198723s
Dec 06 18:01:14.580 INFO [stderr] DEBUG 2018-12-06T18:01:14Z: tokio_core::reactor: loop time - Instant { tv_sec: 5792331, tv_nsec: 912052458 }
Dec 06 18:01:14.580 INFO [stderr] DEBUG 2018-12-06T18:01:14Z: tokio_core::reactor: loop process, 106.322µs
Dec 06 18:01:14.581 INFO [stderr] TRACE 2018-12-06T18:01:14Z: hyper::client::pool: park; waiting for idle connection: "http://status.example.com.local"
Dec 06 18:01:14.581 INFO [stderr] TRACE 2018-12-06T18:01:14Z: hyper::client::connect: Http::connect("http://status.example.com.local/reporter/relay/socket-client/")
Dec 06 18:01:14.581 INFO [stderr] DEBUG 2018-12-06T18:01:14Z: tokio_core::reactor: loop poll - 273.293µs
Dec 06 18:01:14.581 INFO [stderr] DEBUG 2018-12-06T18:01:14Z: tokio_core::reactor: loop time - Instant { tv_sec: 5792331, tv_nsec: 912769375 }
Dec 06 18:01:14.581 INFO [stderr] DEBUG 2018-12-06T18:01:14Z: tokio_core::reactor: loop process, 44.09µs
Dec 06 18:01:14.581 INFO [stderr] DEBUG 2018-12-06T18:01:14Z: hyper::client::dns: resolving host="status.example.com.local", port=80
Dec 06 18:01:14.583 INFO [stderr] DEBUG 2018-12-06T18:01:14Z: tokio_core::reactor: loop poll - 1.652902ms
Dec 06 18:01:14.583 INFO [stderr] DEBUG 2018-12-06T18:01:14Z: tokio_core::reactor: loop time - Instant { tv_sec: 5792331, tv_nsec: 914492800 }
Dec 06 18:01:14.583 INFO [stderr] DEBUG 2018-12-06T18:01:14Z: tokio_core::reactor: loop process, 216.922µs
Dec 06 18:01:14.583 INFO [stderr] ERROR 2018-12-06T18:01:14Z: 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:14.583 INFO [stderr]  WARN 2018-12-06T18:01:14Z: vigil_reporter: Vigil Reporter: Last report failed, trying again sooner than usual
Dec 06 18:01:19.584 INFO [stdout] test run_and_end_valid ... ok
Dec 06 18:01:19.584 INFO [stdout] 
Dec 06 18:01:19.584 INFO [stdout] test result: ok. 5 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 06 18:01:19.584 INFO [stdout] 
Dec 06 18:01:19.596 INFO [stderr]    Doc-tests vigil_reporter
Dec 06 18:01:32.428 INFO [stdout] 
Dec 06 18:01:32.428 INFO [stdout] running 0 tests
Dec 06 18:01:32.428 INFO [stdout] 
Dec 06 18:01:32.428 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 06 18:01:32.428 INFO [stdout] 
Dec 06 18:01:32.448 INFO [stderr] su: No module specific data is present
Dec 06 18:01:33.555 INFO running `"docker" "inspect" "7b5b8022f9db0b52b0e3d23b50ef2b3051b2fa223d7dfbcb1d1563e1eb1f5c86"`
Dec 06 18:01:33.954 INFO running `"docker" "rm" "-f" "7b5b8022f9db0b52b0e3d23b50ef2b3051b2fa223d7dfbcb1d1563e1eb1f5c86"`
Dec 06 18:01:34.364 INFO [stdout] 7b5b8022f9db0b52b0e3d23b50ef2b3051b2fa223d7dfbcb1d1563e1eb1f5c86