Dec 01 22:06:54.415 INFO testing casey/tokio-by-hand against 1.30.1 for beta-1.31-5
Dec 01 22:06:54.415 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.31-5/worker-7/1.30.1:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-7/beta-1.31-5/1.30.1:/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 +1.30.1 build --frozen" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 01 22:06:54.980 INFO [stdout] f2fd833ffb7d994a15e01a9e5c54e0f422ea88d0495865386b415724afb1e26a
Dec 01 22:06:54.983 INFO running `"docker" "start" "-a" "f2fd833ffb7d994a15e01a9e5c54e0f422ea88d0495865386b415724afb1e26a"`
Dec 01 22:06:56.459 INFO [stderr] usermod: no changes
Dec 01 22:06:56.676 INFO [stderr]    Compiling tokio-io v0.1.3
Dec 01 22:06:58.301 INFO [stderr]    Compiling tokio-core v0.1.10
Dec 01 22:07:01.834 INFO [stderr]    Compiling tokio-by-hand v0.0.0 (/source)
Dec 01 22:07:03.510 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 7.02s
Dec 01 22:07:03.514 INFO [stderr] su: No module specific data is present
Dec 01 22:07:04.077 INFO running `"docker" "inspect" "f2fd833ffb7d994a15e01a9e5c54e0f422ea88d0495865386b415724afb1e26a"`
Dec 01 22:07:04.415 INFO running `"docker" "rm" "-f" "f2fd833ffb7d994a15e01a9e5c54e0f422ea88d0495865386b415724afb1e26a"`
Dec 01 22:07:04.707 INFO [stdout] f2fd833ffb7d994a15e01a9e5c54e0f422ea88d0495865386b415724afb1e26a
Dec 01 22:07:04.713 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.31-5/worker-7/1.30.1:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-7/beta-1.31-5/1.30.1:/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 +1.30.1 test --frozen --no-run" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 01 22:07:05.217 INFO [stdout] 67d760d2ff236ca72179de0bbdcfa0cba15b5213f8eaff77060c450cee044a7b
Dec 01 22:07:05.219 INFO running `"docker" "start" "-a" "67d760d2ff236ca72179de0bbdcfa0cba15b5213f8eaff77060c450cee044a7b"`
Dec 01 22:07:06.576 INFO [stderr] usermod: no changes
Dec 01 22:07:06.736 INFO [stderr]    Compiling tokio-by-hand v0.0.0 (/source)
Dec 01 22:07:10.862 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 4.26s
Dec 01 22:07:10.873 INFO [stderr] su: No module specific data is present
Dec 01 22:07:11.789 INFO running `"docker" "inspect" "67d760d2ff236ca72179de0bbdcfa0cba15b5213f8eaff77060c450cee044a7b"`
Dec 01 22:07:12.145 INFO running `"docker" "rm" "-f" "67d760d2ff236ca72179de0bbdcfa0cba15b5213f8eaff77060c450cee044a7b"`
Dec 01 22:07:12.419 INFO [stdout] 67d760d2ff236ca72179de0bbdcfa0cba15b5213f8eaff77060c450cee044a7b
Dec 01 22:07:12.425 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.31-5/worker-7/1.30.1:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-7/beta-1.31-5/1.30.1:/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 +1.30.1 test --frozen" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 01 22:07:12.819 INFO [stdout] 7a84f227761a73790787d7d998f1202867d8d0f734a567d73218d994b3a70b7d
Dec 01 22:07:12.823 INFO running `"docker" "start" "-a" "7a84f227761a73790787d7d998f1202867d8d0f734a567d73218d994b3a70b7d"`
Dec 01 22:07:14.015 INFO [stderr] usermod: no changes
Dec 01 22:07:14.107 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.04s
Dec 01 22:07:14.107 INFO [stderr]      Running /target/debug/deps/tokio_by_hand-e94a395c7334ba85
Dec 01 22:07:14.111 INFO [stdout] 
Dec 01 22:07:14.111 INFO [stdout] running 29 tests
Dec 01 22:07:15.113 INFO [stdout] test extended::delayed::tests::consumer_completes_in_about_one_second ... ok
Dec 01 22:07:15.113 INFO [stdout] test extended::instant::tests::consumer_completes_quickly ... ok
Dec 01 22:07:15.115 INFO [stdout] test extended::delayed::tests::producer_completes_in_about_one_second ... ok
Dec 01 22:07:15.203 INFO [stdout] test extended::instant::tests::producer_completes_quickly ... ok
Dec 01 22:07:15.397 INFO [stdout] test extended::instant::tests::producer_returns_all_values ... ok
Dec 01 22:07:15.517 INFO [stdout] test extended::instant_series::tests::producer_returns_all_values ... ok
Dec 01 22:07:15.563 INFO [stdout] test extended::instant_series::tests::forward_to_consumer ... ok
Dec 01 22:07:16.523 INFO [stdout] test extended::sleeper::tests::with_core ... ok
Dec 01 22:07:16.611 INFO [stdout] test extended::sleeper::tests::with_wait ... ok
Dec 01 22:07:16.759 INFO [stdout] test extended::delayed::tests::producer_returns_all_values ... ok
Dec 01 22:07:17.859 INFO [stdout] test standard::delayed::tests::consumer_completes_in_about_one_second ... ok
Dec 01 22:07:18.023 INFO [stdout] test standard::delayed::tests::producer_completes_in_about_one_second ... ok
Dec 01 22:07:19.327 INFO [stdout] test extended::delayed_series::tests::values_take_one_second_to_consume ... ok
Dec 01 22:07:19.979 INFO [stdout] test extended::delayed_series::tests::values_take_one_second_to_produce ... FAILED
Dec 01 22:07:20.299 INFO [stdout] test extended::buffered::tests::production_and_consumption_are_concurrent ... ok
Dec 01 22:07:20.327 INFO [stdout] test standard::delayed::tests::producer_returns_all_values ... ok
Dec 01 22:07:20.328 INFO [stdout] test standard::instant::tests::consumer_completes_quickly ... ok
Dec 01 22:07:20.450 INFO [stdout] test standard::instant::tests::producer_completes_quickly ... ok
Dec 01 22:07:20.471 INFO [stdout] test standard::instant::tests::producer_returns_all_values ... ok
Dec 01 22:07:20.511 INFO [stdout] test standard::instant_series::tests::producer_returns_all_values ... ok
Dec 01 22:07:20.511 INFO [stdout] test standard::instant_series::tests::forward_to_consumer ... ok
Dec 01 22:07:20.752 INFO [stdout] test extended::delayed_series::tests::production_and_consumption_are_concurrent ... FAILED
Dec 01 22:07:21.511 INFO [stdout] test standard::sleeper::tests::with_wait ... ok
Dec 01 22:07:21.519 INFO [stdout] test standard::sleeper::tests::with_core ... ok
Dec 01 22:07:22.525 INFO [stdout] test standard::buffered::tests::production_and_consumption_are_concurrent ... ok
Dec 01 22:07:24.207 INFO [stdout] test standard::delayed_series::tests::production_and_consumption_are_concurrent ... ok
Dec 01 22:07:24.515 INFO [stdout] test standard::delayed_series::tests::values_take_one_second_to_consume ... ok
Dec 01 22:07:24.986 INFO [stdout] test standard::delayed_series::tests::values_take_one_second_to_produce ... ok
Dec 01 22:07:31.235 INFO [stdout] test extended::adapter::tests::basic ... ok
Dec 01 22:07:31.235 INFO [stdout] 
Dec 01 22:07:31.235 INFO [stdout] failures:
Dec 01 22:07:31.235 INFO [stdout] 
Dec 01 22:07:31.235 INFO [stdout] ---- extended::delayed_series::tests::values_take_one_second_to_produce stdout ----
Dec 01 22:07:31.235 INFO [stdout] thread 'extended::delayed_series::tests::values_take_one_second_to_produce' panicked at 'assertion failed: elapsed < Duration::new(5, 500000000)', src/extended/delayed_series.rs:101:5
Dec 01 22:07:31.235 INFO [stdout] stack backtrace:
Dec 01 22:07:31.235 INFO [stdout]    0:     0x563eafbd35de - std::sys::unix::backtrace::tracing::imp::unwind_backtrace::h15749a98198ba25f
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/sys/unix/backtrace/tracing/gcc_s.rs:49
Dec 01 22:07:31.235 INFO [stdout]    1:     0x563eafbc6576 - std::sys_common::backtrace::print::h0ba65c811294dbf0
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/sys_common/backtrace.rs:71
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/sys_common/backtrace.rs:59
Dec 01 22:07:31.235 INFO [stdout]    2:     0x563eafbc486d - std::panicking::default_hook::{{closure}}::h42bb31757f0fee64
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/panicking.rs:211
Dec 01 22:07:31.235 INFO [stdout]    3:     0x563eafbc457b - std::panicking::default_hook::hebc8848d7aa7dbd9
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/panicking.rs:221
Dec 01 22:07:31.235 INFO [stdout]    4:     0x563eafbc4f1c - std::panicking::rust_panic_with_hook::h86e619a638415243
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/panicking.rs:477
Dec 01 22:07:31.235 INFO [stdout]    5:     0x563eafba237f - std::panicking::begin_panic::hd197e13ad21c30a0
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/panicking.rs:411
Dec 01 22:07:31.235 INFO [stdout]    6:     0x563eafb00d77 - tokio_by_hand::extended::delayed_series::tests::values_take_one_second_to_produce::h697ff04f1347ecb2
Dec 01 22:07:31.235 INFO [stdout]                                at src/extended/delayed_series.rs:101
Dec 01 22:07:31.235 INFO [stdout]    7:     0x563eafb00b99 - tokio_by_hand::extended::delayed_series::tests::values_take_one_second_to_produce::{{closure}}::h6fa192f1b137efc1
Dec 01 22:07:31.235 INFO [stdout]                                at src/extended/delayed_series.rs:93
Dec 01 22:07:31.235 INFO [stdout]    8:     0x563eafb2072d - core::ops::function::FnOnce::call_once::hb8053a9e467de5d3
Dec 01 22:07:31.235 INFO [stdout]                                at libcore/ops/function.rs:238
Dec 01 22:07:31.235 INFO [stdout]    9:     0x563eafb2b2de - <F as alloc::boxed::FnBox<A>>::call_box::hbea525814fa423cc
Dec 01 22:07:31.235 INFO [stdout]                                at libtest/lib.rs:1461
Dec 01 22:07:31.235 INFO [stdout]                                at libcore/ops/function.rs:238
Dec 01 22:07:31.235 INFO [stdout]                                at liballoc/boxed.rs:646
Dec 01 22:07:31.235 INFO [stdout]   10:     0x563eafbe21e9 - __rust_maybe_catch_panic
Dec 01 22:07:31.235 INFO [stdout]                                at libpanic_unwind/lib.rs:103
Dec 01 22:07:31.235 INFO [stdout]   11:     0x563eafb36c3d - std::sys_common::backtrace::__rust_begin_short_backtrace::h0ff507d7422944d3
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/panicking.rs:289
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/panic.rs:392
Dec 01 22:07:31.235 INFO [stdout]                                at libtest/lib.rs:1416
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/sys_common/backtrace.rs:136
Dec 01 22:07:31.235 INFO [stdout]   12:     0x563eafb4f274 - std::panicking::try::do_call::hba0bdcc3670471cc
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/thread/mod.rs:409
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/panic.rs:313
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/panicking.rs:310
Dec 01 22:07:31.235 INFO [stdout]   13:     0x563eafbe21e9 - __rust_maybe_catch_panic
Dec 01 22:07:31.235 INFO [stdout]                                at libpanic_unwind/lib.rs:103
Dec 01 22:07:31.235 INFO [stdout]   14:     0x563eafb3fb46 - <F as alloc::boxed::FnBox<A>>::call_box::hdac52587b00591af
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/panicking.rs:289
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/panic.rs:392
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/thread/mod.rs:408
Dec 01 22:07:31.235 INFO [stdout]                                at liballoc/boxed.rs:646
Dec 01 22:07:31.235 INFO [stdout]   15:     0x563eafbd4eea - std::sys_common::thread::start_thread::h75d887c7d2cc4479
Dec 01 22:07:31.235 INFO [stdout]                                at liballoc/boxed.rs:656
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/sys_common/thread.rs:24
Dec 01 22:07:31.235 INFO [stdout]   16:     0x563eafbc5685 - std::sys::unix::thread::Thread::new::thread_start::h8414caee632bf9ed
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/sys/unix/thread.rs:90
Dec 01 22:07:31.235 INFO [stdout]   17:     0x7f57a71786b9 - start_thread
Dec 01 22:07:31.235 INFO [stdout]   18:     0x7f57a6c9841c - clone
Dec 01 22:07:31.235 INFO [stdout]   19:                0x0 - <unknown>
Dec 01 22:07:31.235 INFO [stdout] 
Dec 01 22:07:31.235 INFO [stdout] ---- extended::delayed_series::tests::production_and_consumption_are_concurrent stdout ----
Dec 01 22:07:31.235 INFO [stdout] thread 'extended::delayed_series::tests::production_and_consumption_are_concurrent' panicked at 'assertion failed: elapsed < Duration::new(6, 500000000)', src/extended/delayed_series.rs:130:5
Dec 01 22:07:31.235 INFO [stdout] stack backtrace:
Dec 01 22:07:31.235 INFO [stdout]    0:     0x563eafbd35de - std::sys::unix::backtrace::tracing::imp::unwind_backtrace::h15749a98198ba25f
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/sys/unix/backtrace/tracing/gcc_s.rs:49
Dec 01 22:07:31.235 INFO [stdout]    1:     0x563eafbc6576 - std::sys_common::backtrace::print::h0ba65c811294dbf0
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/sys_common/backtrace.rs:71
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/sys_common/backtrace.rs:59
Dec 01 22:07:31.235 INFO [stdout]    2:     0x563eafbc486d - std::panicking::default_hook::{{closure}}::h42bb31757f0fee64
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/panicking.rs:211
Dec 01 22:07:31.235 INFO [stdout]    3:     0x563eafbc457b - std::panicking::default_hook::hebc8848d7aa7dbd9
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/panicking.rs:221
Dec 01 22:07:31.235 INFO [stdout]    4:     0x563eafbc4f1c - std::panicking::rust_panic_with_hook::h86e619a638415243
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/panicking.rs:477
Dec 01 22:07:31.235 INFO [stdout]    5:     0x563eafba237f - std::panicking::begin_panic::hd197e13ad21c30a0
Dec 01 22:07:31.235 INFO [stdout]                                at libstd/panicking.rs:411
Dec 01 22:07:31.235 INFO [stdout]    6:     0x563eafb0129e - tokio_by_hand::extended::delayed_series::tests::production_and_consumption_are_concurrent::h84e5fc245f2c433c
Dec 01 22:07:31.235 INFO [stdout]                                at src/extended/delayed_series.rs:130
Dec 01 22:07:31.236 INFO [stdout]    7:     0x563eafb010a9 - tokio_by_hand::extended::delayed_series::tests::production_and_consumption_are_concurrent::{{closure}}::h8402df8be2f58d53
Dec 01 22:07:31.236 INFO [stdout]                                at src/extended/delayed_series.rs:121
Dec 01 22:07:31.236 INFO [stdout]    8:     0x563eafb1f6bd - core::ops::function::FnOnce::call_once::h00af0063823d8389
Dec 01 22:07:31.236 INFO [stdout]                                at libcore/ops/function.rs:238
Dec 01 22:07:31.236 INFO [stdout]    9:     0x563eafb2b2de - <F as alloc::boxed::FnBox<A>>::call_box::hbea525814fa423cc
Dec 01 22:07:31.236 INFO [stdout]                                at libtest/lib.rs:1461
Dec 01 22:07:31.236 INFO [stdout]                                at libcore/ops/function.rs:238
Dec 01 22:07:31.236 INFO [stdout]                                at liballoc/boxed.rs:646
Dec 01 22:07:31.236 INFO [stdout]   10:     0x563eafbe21e9 - __rust_maybe_catch_panic
Dec 01 22:07:31.236 INFO [stdout]                                at libpanic_unwind/lib.rs:103
Dec 01 22:07:31.236 INFO [stdout]   11:     0x563eafb36c3d - std::sys_common::backtrace::__rust_begin_short_backtrace::h0ff507d7422944d3
Dec 01 22:07:31.236 INFO [stdout]                                at libstd/panicking.rs:289
Dec 01 22:07:31.236 INFO [stdout]                                at libstd/panic.rs:392
Dec 01 22:07:31.236 INFO [stdout]                                at libtest/lib.rs:1416
Dec 01 22:07:31.236 INFO [stdout]                                at libstd/sys_common/backtrace.rs:136
Dec 01 22:07:31.236 INFO [stdout]   12:     0x563eafb4f274 - std::panicking::try::do_call::hba0bdcc3670471cc
Dec 01 22:07:31.236 INFO [stdout]                                at libstd/thread/mod.rs:409
Dec 01 22:07:31.236 INFO [stdout]                                at libstd/panic.rs:313
Dec 01 22:07:31.236 INFO [stdout]                                at libstd/panicking.rs:310
Dec 01 22:07:31.236 INFO [stdout]   13:     0x563eafbe21e9 - __rust_maybe_catch_panic
Dec 01 22:07:31.236 INFO [stdout]                                at libpanic_unwind/lib.rs:103
Dec 01 22:07:31.236 INFO [stdout]   14:     0x563eafb3fb46 - <F as alloc::boxed::FnBox<A>>::call_box::hdac52587b00591af
Dec 01 22:07:31.236 INFO [stdout]                                at libstd/panicking.rs:289
Dec 01 22:07:31.236 INFO [stdout]                                at libstd/panic.rs:392
Dec 01 22:07:31.236 INFO [stdout]                                at libstd/thread/mod.rs:408
Dec 01 22:07:31.236 INFO [stdout]                                at liballoc/boxed.rs:646
Dec 01 22:07:31.236 INFO [stdout]   15:     0x563eafbd4eea - std::sys_common::thread::start_thread::h75d887c7d2cc4479
Dec 01 22:07:31.236 INFO [stdout]                                at liballoc/boxed.rs:656
Dec 01 22:07:31.236 INFO [stdout]                                at libstd/sys_common/thread.rs:24
Dec 01 22:07:31.236 INFO [stdout]   16:     0x563eafbc5685 - std::sys::unix::thread::Thread::new::thread_start::h8414caee632bf9ed
Dec 01 22:07:31.236 INFO [stdout]                                at libstd/sys/unix/thread.rs:90
Dec 01 22:07:31.236 INFO [stdout]   17:     0x7f57a71786b9 - start_thread
Dec 01 22:07:31.236 INFO [stdout]   18:     0x7f57a6c9841c - clone
Dec 01 22:07:31.236 INFO [stdout]   19:                0x0 - <unknown>
Dec 01 22:07:31.236 INFO [stdout] 
Dec 01 22:07:31.236 INFO [stdout] 
Dec 01 22:07:31.236 INFO [stdout] failures:
Dec 01 22:07:31.236 INFO [stdout]     extended::delayed_series::tests::production_and_consumption_are_concurrent
Dec 01 22:07:31.236 INFO [stdout]     extended::delayed_series::tests::values_take_one_second_to_produce
Dec 01 22:07:31.236 INFO [stdout] 
Dec 01 22:07:31.236 INFO [stdout] test result: FAILED. 27 passed; 2 failed; 0 ignored; 0 measured; 0 filtered out
Dec 01 22:07:31.236 INFO [stdout] 
Dec 01 22:07:31.236 INFO [stderr] error: test failed, to rerun pass '--lib'
Dec 01 22:07:31.243 INFO [stderr] su: No module specific data is present
Dec 01 22:07:31.848 INFO running `"docker" "inspect" "7a84f227761a73790787d7d998f1202867d8d0f734a567d73218d994b3a70b7d"`
Dec 01 22:07:32.025 INFO running `"docker" "rm" "-f" "7a84f227761a73790787d7d998f1202867d8d0f734a567d73218d994b3a70b7d"`
Dec 01 22:07:32.435 INFO [stdout] 7a84f227761a73790787d7d998f1202867d8d0f734a567d73218d994b3a70b7d
