Nov 17 18:14:19.734 INFO testing wemo-0.0.12 against try#2e026d6e5d7621634147ad4c8074f1d964dbb1be for pr-55982
Nov 17 18:14:19.734 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-55982/worker-6/try#2e026d6e5d7621634147ad4c8074f1d964dbb1be:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-6/pr-55982/try#2e026d6e5d7621634147ad4c8074f1d964dbb1be:/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 +2e026d6e5d7621634147ad4c8074f1d964dbb1be-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"`
Nov 17 18:14:19.935 INFO [stdout] 3c78e6ba40f57947bfa01f98b25c3206cbe44d846636ce3d57c1612b06741975
Nov 17 18:14:19.936 INFO running `"docker" "start" "-a" "3c78e6ba40f57947bfa01f98b25c3206cbe44d846636ce3d57c1612b06741975"`
Nov 17 18:14:20.877 INFO [stderr] usermod: no changes
Nov 17 18:14:21.127 INFO [stderr]    Compiling c_linked_list v1.1.1
Nov 17 18:14:21.128 INFO [stderr]    Compiling num_cpus v0.2.13
Nov 17 18:14:21.129 INFO [stderr]    Compiling net2 v0.2.33
Nov 17 18:14:21.139 INFO [stderr]    Compiling hpack v0.2.0
Nov 17 18:14:21.139 INFO [stderr]    Compiling url v1.4.1
Nov 17 18:14:21.147 INFO [stderr]    Compiling serde_json v0.8.6
Nov 17 18:14:22.434 INFO [stderr]    Compiling get_if_addrs v0.4.1
Nov 17 18:14:23.652 INFO [stderr]    Compiling miow v0.1.5
Nov 17 18:14:23.779 INFO [stderr]    Compiling solicit v0.4.4
Nov 17 18:14:24.579 INFO [stderr]    Compiling mio v0.5.1
Nov 17 18:14:26.505 INFO [stderr]    Compiling cookie v0.2.5
Nov 17 18:14:28.912 INFO [stderr]    Compiling hyper v0.9.18
Nov 17 18:14:36.899 INFO [stderr]    Compiling iron v0.4.0
Nov 17 18:14:39.496 INFO [stderr]    Compiling persistent v0.2.1
Nov 17 18:14:41.294 INFO [stderr]    Compiling bodyparser v0.4.1
Nov 17 18:14:43.583 INFO [stderr]    Compiling urlencoded v0.4.1
Nov 17 18:14:45.835 INFO [stderr]    Compiling wemo v0.0.12 (/source)
Nov 17 18:14:52.182 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 31.24s
Nov 17 18:14:52.191 INFO [stderr] su: No module specific data is present
Nov 17 18:14:52.929 INFO running `"docker" "inspect" "3c78e6ba40f57947bfa01f98b25c3206cbe44d846636ce3d57c1612b06741975"`
Nov 17 18:14:53.233 INFO running `"docker" "rm" "-f" "3c78e6ba40f57947bfa01f98b25c3206cbe44d846636ce3d57c1612b06741975"`
Nov 17 18:14:53.499 INFO [stdout] 3c78e6ba40f57947bfa01f98b25c3206cbe44d846636ce3d57c1612b06741975
Nov 17 18:14:53.507 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-55982/worker-6/try#2e026d6e5d7621634147ad4c8074f1d964dbb1be:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-6/pr-55982/try#2e026d6e5d7621634147ad4c8074f1d964dbb1be:/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 +2e026d6e5d7621634147ad4c8074f1d964dbb1be-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"`
Nov 17 18:14:53.810 INFO [stdout] b3ea181c7c3934c689cdb393a6aa41a194f126d7d40289d40dcbffe6ab48dc16
Nov 17 18:14:53.813 INFO running `"docker" "start" "-a" "b3ea181c7c3934c689cdb393a6aa41a194f126d7d40289d40dcbffe6ab48dc16"`
Nov 17 18:14:54.747 INFO [stderr] usermod: no changes
Nov 17 18:14:54.919 INFO [stderr]    Compiling wemo v0.0.12 (/source)
Nov 17 18:15:09.836 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 15.07s
Nov 17 18:15:09.847 INFO [stderr] su: No module specific data is present
Nov 17 18:15:10.209 INFO running `"docker" "inspect" "b3ea181c7c3934c689cdb393a6aa41a194f126d7d40289d40dcbffe6ab48dc16"`
Nov 17 18:15:10.369 INFO running `"docker" "rm" "-f" "b3ea181c7c3934c689cdb393a6aa41a194f126d7d40289d40dcbffe6ab48dc16"`
Nov 17 18:15:10.477 INFO [stdout] b3ea181c7c3934c689cdb393a6aa41a194f126d7d40289d40dcbffe6ab48dc16
Nov 17 18:15:10.480 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-55982/worker-6/try#2e026d6e5d7621634147ad4c8074f1d964dbb1be:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-6/pr-55982/try#2e026d6e5d7621634147ad4c8074f1d964dbb1be:/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 +2e026d6e5d7621634147ad4c8074f1d964dbb1be-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"`
Nov 17 18:15:10.643 INFO [stdout] 0f6e96c2b746c4d044bf0c3c7ef3351e1f435a54be1941929f1f9c2e3c162942
Nov 17 18:15:10.645 INFO running `"docker" "start" "-a" "0f6e96c2b746c4d044bf0c3c7ef3351e1f435a54be1941929f1f9c2e3c162942"`
Nov 17 18:15:11.111 INFO [stderr] usermod: no changes
Nov 17 18:15:11.239 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.11s
Nov 17 18:15:11.256 INFO [stderr]      Running /target/debug/deps/wemo-f37c850b8139335a
Nov 17 18:15:11.258 INFO [stdout] 
Nov 17 18:15:11.258 INFO [stdout] running 16 tests
Nov 17 18:15:11.259 INFO [stdout] test device::switch::tests::test_name_without_ip ... ok
Nov 17 18:15:11.259 INFO [stdout] test device::switch::tests::test_name_with_ip_and_port ... ok
Nov 17 18:15:11.261 INFO [stdout] test device::switch::tests::test_name_with_ip ... ok
Nov 17 18:15:11.261 INFO [stdout] test device::switch::tests::test_get_port_with_port_set ... ok
Nov 17 18:15:11.261 INFO [stdout] test device::switch::tests::test_get_ip_address_with_static_ip ... ok
Nov 17 18:15:11.261 INFO [stdout] test device::switch::tests::test_get_ip_address_with_no_ip ... ok
Nov 17 18:15:11.261 INFO [stdout] test device::switch::tests::test_get_ip_address_with_dynamic_ip ... ok
Nov 17 18:15:11.263 INFO [stdout] test device::switch::tests::test_update_location_with_dynamic_ip ... ok
Nov 17 18:15:11.275 INFO [stdout] test device::switch::tests::test_get_port_without_port_set ... ok
Nov 17 18:15:11.275 INFO [stdout] test device::switch::tests::test_update_location_with_static_ip ... ok
Nov 17 18:15:11.280 INFO [stdout] test parsing::tests::switch_notifications ... ok
Nov 17 18:15:11.287 INFO [stdout] test parsing::tests::insight_notifications ... ok
Nov 17 18:15:11.291 INFO [stdout] test subscriptions::tests::test_send_subscribe ... ok
Nov 17 18:15:11.335 INFO [stdout] test xml::tests::test_find_tag_value ... ok
Nov 17 18:15:11.351 INFO [stdout] test xml::tests::test_find_tag_value_failure ... ok
Nov 17 18:15:11.541 INFO [stdout] test subscriptions::tests::test_callback_invocation ... FAILED
Nov 17 18:15:11.541 INFO [stdout] 
Nov 17 18:15:11.541 INFO [stdout] failures:
Nov 17 18:15:11.541 INFO [stdout] 
Nov 17 18:15:11.541 INFO [stdout] ---- subscriptions::tests::test_callback_invocation stdout ----
Nov 17 18:15:11.541 INFO [stdout] thread 'subscriptions::tests::test_callback_invocation' panicked at 'assertion failed: notice.is_some()', src/subscriptions.rs:400:5
Nov 17 18:15:11.541 INFO [stdout] stack backtrace:
Nov 17 18:15:11.541 INFO [stdout]    0:     0x56450befabc3 - std::sys::unix::backtrace::tracing::imp::unwind_backtrace::h26df0f6fdb27c709
Nov 17 18:15:11.541 INFO [stdout]                                at libstd/sys/unix/backtrace/tracing/gcc_s.rs:49
Nov 17 18:15:11.541 INFO [stdout]    1:     0x56450bef4d28 - std::sys_common::backtrace::_print::h84c40fecda6d638e
Nov 17 18:15:11.541 INFO [stdout]                                at libstd/sys_common/backtrace.rs:71
Nov 17 18:15:11.541 INFO [stdout]    2:     0x56450bef9434 - std::panicking::default_hook::{{closure}}::h77e370c0567fc0a7
Nov 17 18:15:11.541 INFO [stdout]                                at libstd/sys_common/backtrace.rs:59
Nov 17 18:15:11.541 INFO [stdout]                                at libstd/panicking.rs:211
Nov 17 18:15:11.541 INFO [stdout]    3:     0x56450bef911c - std::panicking::default_hook::hb9a45c11a33bbcb2
Nov 17 18:15:11.541 INFO [stdout]                                at libstd/panicking.rs:221
Nov 17 18:15:11.541 INFO [stdout]    4:     0x56450bef9b40 - std::panicking::rust_panic_with_hook::ha8d95048d940f754
Nov 17 18:15:11.541 INFO [stdout]                                at libstd/panicking.rs:476
Nov 17 18:15:11.541 INFO [stdout]    5:     0x56450bd5ebd7 - std::panicking::begin_panic::hbd4ef949a879ca58
Nov 17 18:15:11.541 INFO [stdout]                                at /rustc/2e026d6e5d7621634147ad4c8074f1d964dbb1be/src/libstd/panicking.rs:410
Nov 17 18:15:11.542 INFO [stdout]    6:     0x56450bbbb6f9 - wemo::subscriptions::tests::test_callback_invocation::h1e358dfcbf7d32d1
Nov 17 18:15:11.542 INFO [stdout]                                at src/subscriptions.rs:400
Nov 17 18:15:11.542 INFO [stdout]    7:     0x56450bbbb189 - wemo::subscriptions::tests::test_callback_invocation::{{closure}}::hcf9f3bb413c690ec
Nov 17 18:15:11.542 INFO [stdout]                                at src/subscriptions.rs:365
Nov 17 18:15:11.542 INFO [stdout]    8:     0x56450bbb3e6d - core::ops::function::FnOnce::call_once::h11fb678bbb1405c1
Nov 17 18:15:11.542 INFO [stdout]                                at /rustc/2e026d6e5d7621634147ad4c8074f1d964dbb1be/src/libcore/ops/function.rs:238
Nov 17 18:15:11.542 INFO [stdout]    9:     0x56450bc039fe - <F as alloc::boxed::FnBox<A>>::call_box::hae1ea457a0ccd8d5
Nov 17 18:15:11.542 INFO [stdout]                                at libtest/lib.rs:1471
Nov 17 18:15:11.542 INFO [stdout]                                at /rustc/2e026d6e5d7621634147ad4c8074f1d964dbb1be/src/libcore/ops/function.rs:238
Nov 17 18:15:11.542 INFO [stdout]                                at /rustc/2e026d6e5d7621634147ad4c8074f1d964dbb1be/src/liballoc/boxed.rs:673
Nov 17 18:15:11.542 INFO [stdout]   10:     0x56450bf09729 - __rust_maybe_catch_panic
Nov 17 18:15:11.542 INFO [stdout]                                at libpanic_unwind/lib.rs:102
Nov 17 18:15:11.542 INFO [stdout]   11:     0x56450bbfb853 - std::sys_common::backtrace::__rust_begin_short_backtrace::hd0ded23d435d70d0
Nov 17 18:15:11.542 INFO [stdout]                                at /rustc/2e026d6e5d7621634147ad4c8074f1d964dbb1be/src/libstd/panicking.rs:289
Nov 17 18:15:11.542 INFO [stdout]                                at /rustc/2e026d6e5d7621634147ad4c8074f1d964dbb1be/src/libstd/panic.rs:398
Nov 17 18:15:11.542 INFO [stdout]                                at libtest/lib.rs:1426
Nov 17 18:15:11.542 INFO [stdout]                                at /rustc/2e026d6e5d7621634147ad4c8074f1d964dbb1be/src/libstd/sys_common/backtrace.rs:136
Nov 17 18:15:11.542 INFO [stdout]   12:     0x56450bbfc6f4 - std::panicking::try::do_call::h031514fb401b7159
Nov 17 18:15:11.542 INFO [stdout]                                at /rustc/2e026d6e5d7621634147ad4c8074f1d964dbb1be/src/libstd/thread/mod.rs:477
Nov 17 18:15:11.542 INFO [stdout]                                at /rustc/2e026d6e5d7621634147ad4c8074f1d964dbb1be/src/libstd/panic.rs:319
Nov 17 18:15:11.542 INFO [stdout]                                at /rustc/2e026d6e5d7621634147ad4c8074f1d964dbb1be/src/libstd/panicking.rs:310
Nov 17 18:15:11.542 INFO [stdout]   13:     0x56450bf09729 - __rust_maybe_catch_panic
Nov 17 18:15:11.542 INFO [stdout]                                at libpanic_unwind/lib.rs:102
Nov 17 18:15:11.542 INFO [stdout]   14:     0x56450bc038dc - <F as alloc::boxed::FnBox<A>>::call_box::h44700b7a2ec6fd33
Nov 17 18:15:11.542 INFO [stdout]                                at /rustc/2e026d6e5d7621634147ad4c8074f1d964dbb1be/src/libstd/panicking.rs:289
Nov 17 18:15:11.542 INFO [stdout]                                at /rustc/2e026d6e5d7621634147ad4c8074f1d964dbb1be/src/libstd/panic.rs:398
Nov 17 18:15:11.542 INFO [stdout]                                at /rustc/2e026d6e5d7621634147ad4c8074f1d964dbb1be/src/libstd/thread/mod.rs:476
Nov 17 18:15:11.542 INFO [stdout]                                at /rustc/2e026d6e5d7621634147ad4c8074f1d964dbb1be/src/liballoc/boxed.rs:673
Nov 17 18:15:11.542 INFO [stdout]   15:     0x56450befd23d - std::sys::unix::thread::Thread::new::thread_start::h8526625243d2f13b
Nov 17 18:15:11.542 INFO [stdout]                                at /rustc/2e026d6e5d7621634147ad4c8074f1d964dbb1be/src/liballoc/boxed.rs:683
Nov 17 18:15:11.542 INFO [stdout]                                at libstd/sys_common/thread.rs:24
Nov 17 18:15:11.542 INFO [stdout]                                at libstd/sys/unix/thread.rs:90
Nov 17 18:15:11.542 INFO [stdout]   16:     0x7fc4963986b9 - start_thread
Nov 17 18:15:11.542 INFO [stdout]   17:     0x7fc495eb841c - clone
Nov 17 18:15:11.542 INFO [stdout]   18:                0x0 - <unknown>
Nov 17 18:15:11.542 INFO [stdout] 
Nov 17 18:15:11.542 INFO [stdout] 
Nov 17 18:15:11.542 INFO [stdout] failures:
Nov 17 18:15:11.542 INFO [stdout]     subscriptions::tests::test_callback_invocation
Nov 17 18:15:11.542 INFO [stdout] 
Nov 17 18:15:11.542 INFO [stdout] test result: FAILED. 15 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out
Nov 17 18:15:11.542 INFO [stdout] 
Nov 17 18:15:11.550 INFO [stderr] error: test failed, to rerun pass '--lib'
Nov 17 18:15:11.550 INFO [stderr] su: No module specific data is present
Nov 17 18:15:11.885 INFO running `"docker" "inspect" "0f6e96c2b746c4d044bf0c3c7ef3351e1f435a54be1941929f1f9c2e3c162942"`
Nov 17 18:15:11.994 INFO running `"docker" "rm" "-f" "0f6e96c2b746c4d044bf0c3c7ef3351e1f435a54be1941929f1f9c2e3c162942"`
Nov 17 18:15:12.080 INFO [stdout] 0f6e96c2b746c4d044bf0c3c7ef3351e1f435a54be1941929f1f9c2e3c162942