Dec 03 18:13:42.324 INFO testing bip_handshake-0.7.1 against 1.30.1 for beta-1.31-5
Dec 03 18:13:42.324 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 03 18:13:42.632 INFO [stdout] 68ab3345e09dd8c07b8d33c1352b82b43a36852a23b7c16ea0212282ada38b98
Dec 03 18:13:42.634 INFO running `"docker" "start" "-a" "68ab3345e09dd8c07b8d33c1352b82b43a36852a23b7c16ea0212282ada38b98"`
Dec 03 18:13:43.130 INFO [stderr] usermod: no changes
Dec 03 18:13:43.268 INFO [stderr]    Compiling bip_handshake v0.7.1 (/source)
Dec 03 18:13:50.391 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 7.24s
Dec 03 18:13:50.411 INFO [stderr] su: No module specific data is present
Dec 03 18:13:51.294 INFO running `"docker" "inspect" "68ab3345e09dd8c07b8d33c1352b82b43a36852a23b7c16ea0212282ada38b98"`
Dec 03 18:13:51.505 INFO running `"docker" "rm" "-f" "68ab3345e09dd8c07b8d33c1352b82b43a36852a23b7c16ea0212282ada38b98"`
Dec 03 18:13:51.694 INFO [stdout] 68ab3345e09dd8c07b8d33c1352b82b43a36852a23b7c16ea0212282ada38b98
Dec 03 18:13:51.701 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 03 18:13:52.115 INFO [stdout] 63d51d8faf8b77b9799648269029f8a2faaf5a2d9d1fb3bce829c300bddd8b91
Dec 03 18:13:52.121 INFO running `"docker" "start" "-a" "63d51d8faf8b77b9799648269029f8a2faaf5a2d9d1fb3bce829c300bddd8b91"`
Dec 03 18:13:53.434 INFO [stderr] usermod: no changes
Dec 03 18:13:53.599 INFO [stderr]    Compiling bip_handshake v0.7.1 (/source)
Dec 03 18:14:19.306 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 25.84s
Dec 03 18:14:19.319 INFO [stderr] su: No module specific data is present
Dec 03 18:14:19.692 INFO running `"docker" "inspect" "63d51d8faf8b77b9799648269029f8a2faaf5a2d9d1fb3bce829c300bddd8b91"`
Dec 03 18:14:19.924 INFO running `"docker" "rm" "-f" "63d51d8faf8b77b9799648269029f8a2faaf5a2d9d1fb3bce829c300bddd8b91"`
Dec 03 18:14:20.319 INFO [stdout] 63d51d8faf8b77b9799648269029f8a2faaf5a2d9d1fb3bce829c300bddd8b91
Dec 03 18:14:20.321 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 03 18:14:20.764 INFO [stdout] 7e24d68554140accab4cc0ed3ebb6d1108083f7057a57f77fe4c7ecfdd44920f
Dec 03 18:14:20.766 INFO running `"docker" "start" "-a" "7e24d68554140accab4cc0ed3ebb6d1108083f7057a57f77fe4c7ecfdd44920f"`
Dec 03 18:14:22.326 INFO [stderr] usermod: no changes
Dec 03 18:14:22.559 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.19s
Dec 03 18:14:22.575 INFO [stderr]      Running /target/debug/deps/bip_handshake-45f55a5699771293
Dec 03 18:14:22.575 INFO [stdout] 
Dec 03 18:14:22.575 INFO [stdout] running 34 tests
Dec 03 18:14:22.575 INFO [stdout] test bittorrent::framed::tests::positive_read_bytes_after_handshake ... ok
Dec 03 18:14:22.575 INFO [stdout] test bittorrent::framed::tests::positive_read_byte_after_handshake ... ok
Dec 03 18:14:22.576 INFO [stdout] test filter::filters::tests::positive_add_filter ... ok
Dec 03 18:14:22.583 INFO [stdout] test bittorrent::message::tests::positive_decode_zero_bytes_protocol ... ok
Dec 03 18:14:22.583 INFO [stdout] test bittorrent::message::tests::positive_many_bytes_protocol ... ok
Dec 03 18:14:22.583 INFO [stdout] test filter::filters::tests::positive_add_filter_already_present ... ok
Dec 03 18:14:22.583 INFO [stdout] test bittorrent::framed::tests::positive_write_multiple_handshake_messages ... ok
Dec 03 18:14:22.583 INFO [stdout] test bittorrent::framed::tests::positive_read_handshake_message ... ok
Dec 03 18:14:22.587 INFO [stdout] test filter::filters::tests::positive_clear_filters_multiple_present ... ok
Dec 03 18:14:22.587 INFO [stdout] test bittorrent::message::tests::positive_bittorrent_protocol ... ok
Dec 03 18:14:22.587 INFO [stdout] test filter::filters::tests::positive_clear_filters_one_present ... ok
Dec 03 18:14:22.595 INFO [stdout] test bittorrent::framed::tests::positive_write_handshake_message ... ok
Dec 03 18:14:22.595 INFO [stdout] test filter::filters::tests::positive_remove_filter_not_present ... ok
Dec 03 18:14:22.595 INFO [stdout] test filter::filters::tests::positive_remove_filter_multiple_present ... ok
Dec 03 18:14:22.596 INFO [stdout] test filter::filters::tests::positive_clear_filters_none_present ... ok
Dec 03 18:14:22.596 INFO [stdout] test filter::filters::tests::positive_remove_filter ... ok
Dec 03 18:14:22.597 INFO [stdout] test filter::tests::positive_decision_choose_higher ... ok
Dec 03 18:14:22.597 INFO [stdout] test filter::tests::positive_decision_choose_self ... ok
Dec 03 18:14:22.597 INFO [stdout] test handshake::handler::handshaker::tests::positive_initiate_handshake ... ok
Dec 03 18:14:22.597 INFO [stdout] test filter::tests::positive_decision_keep_higher ... ok
Dec 03 18:14:22.597 INFO [stdout] test handshake::handler::handshaker::tests::positive_complete_handshake ... ok
Dec 03 18:14:22.598 INFO [stdout] test handshake::handler::listener::tests::positive_fails_filter ... ok
Dec 03 18:14:22.599 INFO [stdout] test handshake::handler::listener::tests::positive_needs_data_filter ... ok
Dec 03 18:14:22.599 INFO [stdout] test handshake::handler::listener::tests::positive_passes_filter ... ok
Dec 03 18:14:22.619 INFO [stdout] test handshake::handler::timer::tests::positive_finish_before_timeout ... ok
Dec 03 18:14:22.619 INFO [stdout] test handshake::handler::listener::tests::positive_empty_filter ... ok
Dec 03 18:14:22.619 INFO [stdout] test message::extensions::tests::positive_remove_extension_protocol ... ok
Dec 03 18:14:22.619 INFO [stdout] test message::extensions::tests::positive_add_extension_protocol ... ok
Dec 03 18:14:22.704 INFO [stdout] test handshake::handler::initiator::tests::positive_needs_data_filter ... ok
Dec 03 18:14:22.705 INFO [stdout] test handshake::handler::initiator::tests::positive_empty_filter ... ok
Dec 03 18:14:22.719 INFO [stdout] test handshake::handler::initiator::tests::positive_passes_filter ... ok
Dec 03 18:14:22.743 INFO [stdout] test handshake::handler::initiator::tests::positive_fails_filter ... ok
Dec 03 18:14:22.807 INFO [stdout] test handshake::handler::timer::tests::negative_finish_after_timeout ... ok
Dec 03 18:14:22.807 INFO [stdout] test bittorrent::message::tests::negative_create_overflow_protocol ... ok
Dec 03 18:14:22.807 INFO [stdout] 
Dec 03 18:14:22.807 INFO [stdout] test result: ok. 34 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 03 18:14:22.807 INFO [stdout] 
Dec 03 18:14:22.811 INFO [stderr]      Running /target/debug/deps/test-130f9d475d8d7807
Dec 03 18:14:22.811 INFO [stdout] 
Dec 03 18:14:22.811 INFO [stdout] running 7 tests
Dec 03 18:14:22.999 INFO [stdout] test test_bytes_after_handshake::positive_recover_bytes ... ok
Dec 03 18:14:22.999 INFO [stdout] test test_byte_after_handshake::positive_recover_bytes ... ok
Dec 03 18:14:23.019 INFO [stdout] test test_filter_allow_all::test_filter_all ... ok
Dec 03 18:14:23.027 INFO [stdout] test test_connect::positive_connect ... ok
Dec 03 18:14:23.043 INFO [stdout] test test_filter_block_all::test_filter_all ... ok
Dec 03 18:14:23.046 INFO [stdout] test test_filter_whitelist_diff_data::test_filter_whitelist_diff_data ... ok
Dec 03 18:14:23.122 INFO [stdout] test test_filter_whitelist_same_data::test_filter_whitelist_same_data ... FAILED
Dec 03 18:14:23.122 INFO [stdout] 
Dec 03 18:14:23.122 INFO [stdout] failures:
Dec 03 18:14:23.122 INFO [stdout] 
Dec 03 18:14:23.122 INFO [stdout] ---- test_filter_whitelist_same_data::test_filter_whitelist_same_data stdout ----
Dec 03 18:14:23.122 INFO [stdout] thread 'test_filter_whitelist_same_data::test_filter_whitelist_same_data' panicked at 'assertion failed: `(left == right)`
Dec 03 18:14:23.122 INFO [stdout]   left: `GotResult`,
Dec 03 18:14:23.122 INFO [stdout]  right: `TimedOut`', test/test_filter_whitelist_same_data.rs:89:5
Dec 03 18:14:23.122 INFO [stdout] stack backtrace:
Dec 03 18:14:23.122 INFO [stdout]    0:     0x5562c5afb39e - std::sys::unix::backtrace::tracing::imp::unwind_backtrace::h15749a98198ba25f
Dec 03 18:14:23.122 INFO [stdout]                                at libstd/sys/unix/backtrace/tracing/gcc_s.rs:49
Dec 03 18:14:23.122 INFO [stdout]    1:     0x5562c5aed266 - std::sys_common::backtrace::print::h0ba65c811294dbf0
Dec 03 18:14:23.122 INFO [stdout]                                at libstd/sys_common/backtrace.rs:71
Dec 03 18:14:23.122 INFO [stdout]                                at libstd/sys_common/backtrace.rs:59
Dec 03 18:14:23.122 INFO [stdout]    2:     0x5562c5aeb68d - std::panicking::default_hook::{{closure}}::h42bb31757f0fee64
Dec 03 18:14:23.122 INFO [stdout]                                at libstd/panicking.rs:211
Dec 03 18:14:23.122 INFO [stdout]    3:     0x5562c5aeb39b - std::panicking::default_hook::hebc8848d7aa7dbd9
Dec 03 18:14:23.122 INFO [stdout]                                at libstd/panicking.rs:221
Dec 03 18:14:23.122 INFO [stdout]    4:     0x5562c5aebd3c - std::panicking::rust_panic_with_hook::h86e619a638415243
Dec 03 18:14:23.122 INFO [stdout]                                at libstd/panicking.rs:477
Dec 03 18:14:23.122 INFO [stdout]    5:     0x5562c5aeb8f9 - std::panicking::continue_panic_fmt::h2d2d2bfb065a70b2
Dec 03 18:14:23.122 INFO [stdout]                                at libstd/panicking.rs:391
Dec 03 18:14:23.122 INFO [stdout]    6:     0x5562c5aeb85d - std::panicking::begin_panic_fmt::ha5097e2056ef3d5a
Dec 03 18:14:23.122 INFO [stdout]                                at libstd/panicking.rs:346
Dec 03 18:14:23.122 INFO [stdout]    7:     0x5562c58fe78c - test::test_filter_whitelist_same_data::test_filter_whitelist_same_data::h548390625d78c496
Dec 03 18:14:23.122 INFO [stdout]                                at test/test_filter_whitelist_same_data.rs:89
Dec 03 18:14:23.122 INFO [stdout]    8:     0x5562c58fdf09 - test::test_filter_whitelist_same_data::test_filter_whitelist_same_data::{{closure}}::h6c2600a872b07afb
Dec 03 18:14:23.122 INFO [stdout]                                at test/test_filter_whitelist_same_data.rs:44
Dec 03 18:14:23.122 INFO [stdout]    9:     0x5562c58f06bd - core::ops::function::FnOnce::call_once::hcab4708e3e513b50
Dec 03 18:14:23.122 INFO [stdout]                                at libcore/ops/function.rs:238
Dec 03 18:14:23.122 INFO [stdout]   10:     0x5562c590cbbe - <F as alloc::boxed::FnBox<A>>::call_box::hbea525814fa423cc
Dec 03 18:14:23.123 INFO [stdout]                                at libtest/lib.rs:1461
Dec 03 18:14:23.123 INFO [stdout]                                at libcore/ops/function.rs:238
Dec 03 18:14:23.123 INFO [stdout]                                at liballoc/boxed.rs:646
Dec 03 18:14:23.123 INFO [stdout]   11:     0x5562c5b09fa9 - __rust_maybe_catch_panic
Dec 03 18:14:23.123 INFO [stdout]                                at libpanic_unwind/lib.rs:103
Dec 03 18:14:23.123 INFO [stdout]   12:     0x5562c591851d - std::sys_common::backtrace::__rust_begin_short_backtrace::h0ff507d7422944d3
Dec 03 18:14:23.123 INFO [stdout]                                at libstd/panicking.rs:289
Dec 03 18:14:23.123 INFO [stdout]                                at libstd/panic.rs:392
Dec 03 18:14:23.123 INFO [stdout]                                at libtest/lib.rs:1416
Dec 03 18:14:23.123 INFO [stdout]                                at libstd/sys_common/backtrace.rs:136
Dec 03 18:14:23.123 INFO [stdout]   13:     0x5562c5930b54 - std::panicking::try::do_call::hba0bdcc3670471cc
Dec 03 18:14:23.123 INFO [stdout]                                at libstd/thread/mod.rs:409
Dec 03 18:14:23.123 INFO [stdout]                                at libstd/panic.rs:313
Dec 03 18:14:23.123 INFO [stdout]                                at libstd/panicking.rs:310
Dec 03 18:14:23.123 INFO [stdout]   14:     0x5562c5b09fa9 - __rust_maybe_catch_panic
Dec 03 18:14:23.123 INFO [stdout]                                at libpanic_unwind/lib.rs:103
Dec 03 18:14:23.123 INFO [stdout]   15:     0x5562c5921426 - <F as alloc::boxed::FnBox<A>>::call_box::hdac52587b00591af
Dec 03 18:14:23.123 INFO [stdout]                                at libstd/panicking.rs:289
Dec 03 18:14:23.123 INFO [stdout]                                at libstd/panic.rs:392
Dec 03 18:14:23.123 INFO [stdout]                                at libstd/thread/mod.rs:408
Dec 03 18:14:23.123 INFO [stdout]                                at liballoc/boxed.rs:646
Dec 03 18:14:23.123 INFO [stdout]   16:     0x5562c5afccaa - std::sys_common::thread::start_thread::h75d887c7d2cc4479
Dec 03 18:14:23.123 INFO [stdout]                                at liballoc/boxed.rs:656
Dec 03 18:14:23.123 INFO [stdout]                                at libstd/sys_common/thread.rs:24
Dec 03 18:14:23.123 INFO [stdout]   17:     0x5562c5aec4a5 - std::sys::unix::thread::Thread::new::thread_start::h8414caee632bf9ed
Dec 03 18:14:23.123 INFO [stdout]                                at libstd/sys/unix/thread.rs:90
Dec 03 18:14:23.123 INFO [stdout]   18:     0x7f9f1b9536b9 - start_thread
Dec 03 18:14:23.123 INFO [stdout]   19:     0x7f9f1b47341c - clone
Dec 03 18:14:23.123 INFO [stdout]   20:                0x0 - <unknown>
Dec 03 18:14:23.123 INFO [stdout] 
Dec 03 18:14:23.123 INFO [stdout] 
Dec 03 18:14:23.123 INFO [stdout] failures:
Dec 03 18:14:23.123 INFO [stdout]     test_filter_whitelist_same_data::test_filter_whitelist_same_data
Dec 03 18:14:23.123 INFO [stdout] 
Dec 03 18:14:23.123 INFO [stdout] test result: FAILED. 6 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out
Dec 03 18:14:23.123 INFO [stdout] 
Dec 03 18:14:23.128 INFO [stderr] error: test failed, to rerun pass '--test test'
Dec 03 18:14:23.129 INFO [stderr] su: No module specific data is present
Dec 03 18:14:23.971 INFO running `"docker" "inspect" "7e24d68554140accab4cc0ed3ebb6d1108083f7057a57f77fe4c7ecfdd44920f"`
Dec 03 18:14:24.193 INFO running `"docker" "rm" "-f" "7e24d68554140accab4cc0ed3ebb6d1108083f7057a57f77fe4c7ecfdd44920f"`
Dec 03 18:14:24.555 INFO [stdout] 7e24d68554140accab4cc0ed3ebb6d1108083f7057a57f77fe4c7ecfdd44920f
