Nov 18 01:17:57.387 INFO testing rs_lockfree-0.1.1 against try#2e026d6e5d7621634147ad4c8074f1d964dbb1be for pr-55982
Nov 18 01:17:57.387 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-55982/worker-1/try#2e026d6e5d7621634147ad4c8074f1d964dbb1be:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-1/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 18 01:17:57.757 INFO [stdout] 3a3d71dd24158686f0c38a747af958b40919b404b20607b1961e1fe3e5d7f529
Nov 18 01:17:57.761 INFO running `"docker" "start" "-a" "3a3d71dd24158686f0c38a747af958b40919b404b20607b1961e1fe3e5d7f529"`
Nov 18 01:17:58.727 INFO [stderr] usermod: no changes
Nov 18 01:17:58.859 INFO [stderr]    Compiling rs_lockfree v0.1.1 (/source)
Nov 18 01:17:59.943 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 1.18s
Nov 18 01:17:59.947 INFO [stderr] su: No module specific data is present
Nov 18 01:18:00.743 INFO running `"docker" "inspect" "3a3d71dd24158686f0c38a747af958b40919b404b20607b1961e1fe3e5d7f529"`
Nov 18 01:18:01.020 INFO running `"docker" "rm" "-f" "3a3d71dd24158686f0c38a747af958b40919b404b20607b1961e1fe3e5d7f529"`
Nov 18 01:18:01.246 INFO [stdout] 3a3d71dd24158686f0c38a747af958b40919b404b20607b1961e1fe3e5d7f529
Nov 18 01:18:01.248 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-55982/worker-1/try#2e026d6e5d7621634147ad4c8074f1d964dbb1be:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-1/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 18 01:18:01.663 INFO [stdout] 28e135f95ea815205088cbba19138b2bcb4acf29a587e424127985c700378627
Nov 18 01:18:01.665 INFO running `"docker" "start" "-a" "28e135f95ea815205088cbba19138b2bcb4acf29a587e424127985c700378627"`
Nov 18 01:18:03.210 INFO [stderr] usermod: no changes
Nov 18 01:18:03.402 INFO [stderr]    Compiling core_affinity v0.5.9
Nov 18 01:18:04.021 INFO [stderr]    Compiling rs_lockfree v0.1.1 (/source)
Nov 18 01:18:15.904 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 12.67s
Nov 18 01:18:15.911 INFO [stderr] su: No module specific data is present
Nov 18 01:18:16.289 INFO running `"docker" "inspect" "28e135f95ea815205088cbba19138b2bcb4acf29a587e424127985c700378627"`
Nov 18 01:18:16.501 INFO running `"docker" "rm" "-f" "28e135f95ea815205088cbba19138b2bcb4acf29a587e424127985c700378627"`
Nov 18 01:18:16.738 INFO [stdout] 28e135f95ea815205088cbba19138b2bcb4acf29a587e424127985c700378627
Nov 18 01:18:16.743 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-55982/worker-1/try#2e026d6e5d7621634147ad4c8074f1d964dbb1be:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-1/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 18 01:18:17.051 INFO [stdout] 45eea24a6e2cd1fd39f70c8c599b209297ceabdda86a9c85438f702ff1c70312
Nov 18 01:18:17.051 INFO running `"docker" "start" "-a" "45eea24a6e2cd1fd39f70c8c599b209297ceabdda86a9c85438f702ff1c70312"`
Nov 18 01:18:17.655 INFO [stderr] usermod: no changes
Nov 18 01:18:17.719 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.04s
Nov 18 01:18:17.723 INFO [stderr]      Running /target/debug/deps/rs_lockfree-40148ab00d3b3a1f
Nov 18 01:18:17.726 INFO [stdout] 
Nov 18 01:18:17.726 INFO [stdout] running 7 tests
Nov 18 01:18:17.727 INFO [stdout] test error::test::test_base ... ok
Nov 18 01:18:17.727 INFO [stdout] test lockfree_queue::test::test_memory_leak ... ok
Nov 18 01:18:17.727 INFO [stdout] test lockfree_stack::test::test_base ... ok
Nov 18 01:18:17.728 INFO [stdout] test spin_lock::test::test_spin_lock ... ok
Nov 18 01:18:17.728 INFO [stdout] test lockfree_stack::test::test_memory_leak ... ok
Nov 18 01:18:17.728 INFO [stdout] test lockfree_queue::test::test_base ... ok
Nov 18 01:18:17.728 INFO [stdout] test spin_rwlock::test::test_rwlock ... ok
Nov 18 01:18:17.728 INFO [stdout] 
Nov 18 01:18:17.728 INFO [stdout] test result: ok. 7 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 18 01:18:17.728 INFO [stdout] 
Nov 18 01:18:17.728 INFO [stderr]      Running /target/debug/deps/test_hazard_epoch-127d041467ed05b7
Nov 18 01:18:17.731 INFO [stdout] 
Nov 18 01:18:17.731 INFO [stdout] running 2 tests
Nov 18 01:18:17.731 INFO [stdout] hazard_waiting_count=0
Nov 18 01:18:17.735 INFO [stdout] set_cpu_affinity 1 1
Nov 18 01:18:17.736 INFO [stdout] test test_base ... ok
Nov 18 01:18:17.736 INFO [stdout] set_cpu_affinity 4 4
Nov 18 01:18:17.737 INFO [stdout] set_cpu_affinity 3 3
Nov 18 01:18:17.737 INFO [stdout] set_cpu_affinity 7 7
Nov 18 01:18:17.739 INFO [stdout] set_cpu_affinity 5 5
Nov 18 01:18:17.748 INFO [stdout] set_cpu_affinity 8 0
Nov 18 01:18:17.748 INFO [stdout] set_cpu_affinity 9 1
Nov 18 01:18:17.748 INFO [stdout] set_cpu_affinity 6 6
Nov 18 01:18:18.731 INFO [stdout] hazard_waiting_count=36164
Nov 18 01:18:19.739 INFO [stdout] hazard_waiting_count=12033
Nov 18 01:18:20.731 INFO [stdout] hazard_waiting_count=19383
Nov 18 01:18:21.735 INFO [stdout] hazard_waiting_count=298056
Nov 18 01:18:22.743 INFO [stdout] hazard_waiting_count=32696
Nov 18 01:18:23.741 INFO [stdout] hazard_waiting_count=5624
Nov 18 01:18:24.739 INFO [stdout] hazard_waiting_count=611657
Nov 18 01:18:25.747 INFO [stdout] hazard_waiting_count=267856
Nov 18 01:18:26.769 INFO [stdout] hazard_waiting_count=31029
Nov 18 01:18:27.743 INFO [stdout] hazard_waiting_count=82829
Nov 18 01:18:28.747 INFO [stdout] hazard_waiting_count=5706
Nov 18 01:18:29.755 INFO [stdout] hazard_waiting_count=100205
Nov 18 01:18:30.754 INFO [stdout] hazard_waiting_count=10060
Nov 18 01:18:31.755 INFO [stdout] hazard_waiting_count=12741
Nov 18 01:18:32.763 INFO [stdout] hazard_waiting_count=2050
Nov 18 01:18:33.771 INFO [stdout] hazard_waiting_count=0
Nov 18 01:18:34.771 INFO [stdout] hazard_waiting_count=506
Nov 18 01:18:35.775 INFO [stdout] hazard_waiting_count=0
Nov 18 01:18:36.771 INFO [stdout] hazard_waiting_count=0
Nov 18 01:18:37.779 INFO [stdout] test test_multi_thread ... ok
Nov 18 01:18:37.779 INFO [stdout] 
Nov 18 01:18:37.779 INFO [stdout] test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 18 01:18:37.779 INFO [stdout] 
Nov 18 01:18:37.784 INFO [stderr]      Running /target/debug/deps/test_lockfree_queue-30e06b76dcd67ce0
Nov 18 01:18:37.786 INFO [stdout] 
Nov 18 01:18:37.786 INFO [stdout] running 1 test
Nov 18 01:18:37.786 INFO [stdout] debug_thread produced 0 consumed 0
Nov 18 01:18:37.786 INFO [stdout] set_cpu_affinity 1 1
Nov 18 01:18:37.791 INFO [stdout] set_cpu_affinity 3 3
Nov 18 01:18:37.795 INFO [stdout] set_cpu_affinity 4 4
Nov 18 01:18:37.795 INFO [stdout] set_cpu_affinity 5 5
Nov 18 01:18:37.799 INFO [stdout] set_cpu_affinity 2 2
Nov 18 01:18:37.803 INFO [stdout] set_cpu_affinity 6 6
Nov 18 01:18:37.803 INFO [stdout] set_cpu_affinity 8 0
Nov 18 01:18:37.807 INFO [stdout] set_cpu_affinity 7 7
Nov 18 01:18:38.795 INFO [stdout] debug_thread produced 450564 consumed 417792
Nov 18 01:18:39.807 INFO [stdout] debug_thread produced 915972 consumed 817152
Nov 18 01:18:40.823 INFO [stdout] debug_thread produced 1388548 consumed 1222656
Nov 18 01:18:41.831 INFO [stdout] debug_thread produced 1824260 consumed 1621504
Nov 18 01:18:42.851 INFO [stdout] debug_thread produced 2298884 consumed 2044416
Nov 18 01:18:43.867 INFO [stdout] debug_thread produced 2728964 consumed 2467328
Nov 18 01:18:44.875 INFO [stdout] debug_thread produced 3279876 consumed 2933760
Nov 18 01:18:45.879 INFO [stdout] debug_thread produced 3864068 consumed 3572224
Nov 18 01:18:46.883 INFO [stdout] debug_thread produced 4352004 consumed 4350464
Nov 18 01:18:47.895 INFO [stdout] debug_thread produced 4881412 consumed 4876800
Nov 18 01:18:48.892 INFO [stdout] debug_thread produced 5374468 consumed 5362688
Nov 18 01:18:49.903 INFO [stdout] debug_thread produced 5969924 consumed 5890048
Nov 18 01:18:50.915 INFO [stdout] debug_thread produced 6570500 consumed 6416896
Nov 18 01:18:51.949 INFO [stdout] debug_thread produced 7252996 consumed 6983680
Nov 18 01:18:52.951 INFO [stdout] debug_thread produced 7886340 consumed 7644160
Nov 18 01:18:53.951 INFO [stdout] debug_thread produced 8498180 consumed 8402944
Nov 18 01:18:54.967 INFO [stdout] debug_thread produced 9328644 consumed 9328640
Nov 18 01:18:55.963 INFO [stdout] debug_thread produced 9911126 consumed 9910784
Nov 18 01:18:56.963 INFO [stdout] debug_thread produced 10750294 consumed 10749952
Nov 18 01:18:57.963 INFO [stdout] debug_thread produced 11125759 consumed 11120128
Nov 18 01:18:58.963 INFO [stdout] test test_multi_threads ... ok
Nov 18 01:18:58.964 INFO [stdout] 
Nov 18 01:18:58.964 INFO [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 18 01:18:58.964 INFO [stdout] 
Nov 18 01:18:58.973 INFO [stdout] 
Nov 18 01:18:58.973 INFO [stderr]      Running /target/debug/deps/test_lockfree_stack-03354ec39a89ed29
Nov 18 01:18:58.973 INFO [stdout] running 1 test
Nov 18 01:18:58.975 INFO [stdout] set_cpu_affinity 1 1
Nov 18 01:18:58.987 INFO [stdout] set_cpu_affinity 4 4
Nov 18 01:18:58.987 INFO [stdout] debug_thread produced 2 consumed 0
Nov 18 01:18:58.987 INFO [stdout] set_cpu_affinity 6 6
Nov 18 01:18:58.988 INFO [stdout] set_cpu_affinity 2 2
Nov 18 01:18:58.988 INFO [stdout] set_cpu_affinity 5 5
Nov 18 01:18:58.988 INFO [stdout] set_cpu_affinity 7 7
Nov 18 01:18:58.990 INFO [stdout] set_cpu_affinity 3 3
Nov 18 01:18:58.995 INFO [stdout] set_cpu_affinity 8 0
Nov 18 01:18:59.983 INFO [stdout] debug_thread produced 942596 consumed 881664
Nov 18 01:19:01.035 INFO [stdout] debug_thread produced 1854468 consumed 1783808
Nov 18 01:19:02.007 INFO [stdout] debug_thread produced 2282500 consumed 2281984
Nov 18 01:19:03.039 INFO [stdout] debug_thread produced 2700804 consumed 2698240
Nov 18 01:19:04.051 INFO [stdout] debug_thread produced 3196420 consumed 3191296
Nov 18 01:19:05.083 INFO [stdout] debug_thread produced 3873796 consumed 3867136
Nov 18 01:19:06.083 INFO [stdout] debug_thread produced 4548100 consumed 4410880
Nov 18 01:19:07.079 INFO [stdout] debug_thread produced 5261316 consumed 5072896
Nov 18 01:19:08.083 INFO [stdout] debug_thread produced 5958148 consumed 5776896
Nov 18 01:19:09.101 INFO [stdout] debug_thread produced 6734340 consumed 6435840
Nov 18 01:19:10.111 INFO [stdout] debug_thread produced 7483396 consumed 7284224
Nov 18 01:19:11.115 INFO [stdout] debug_thread produced 8346116 consumed 8107520
Nov 18 01:19:12.131 INFO [stdout] debug_thread produced 9158660 consumed 8910848
Nov 18 01:19:13.132 INFO [stdout] debug_thread produced 9928708 consumed 9842176
Nov 18 01:19:14.138 INFO [stdout] debug_thread produced 10586454 consumed 10511360
Nov 18 01:19:15.147 INFO [stdout] debug_thread produced 10898943 consumed 10897920
Nov 18 01:19:16.146 INFO [stdout] debug_thread produced 11109375 consumed 11108864
Nov 18 01:19:17.151 INFO [stdout] test test_multi_threads ... ok
Nov 18 01:19:17.151 INFO [stdout] 
Nov 18 01:19:17.151 INFO [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 18 01:19:17.152 INFO [stdout] 
Nov 18 01:19:17.159 INFO [stderr]    Doc-tests rs_lockfree
Nov 18 01:19:17.814 INFO [stdout] 
Nov 18 01:19:17.814 INFO [stdout] running 8 tests
Nov 18 01:19:20.195 INFO [stdout] test src/lockfree_stack.rs - lockfree_stack::LockFreeStack (line 58) ... ok
Nov 18 01:19:22.680 INFO [stdout] test src/hazard_pointer.rs - hazard_pointer::HazardNodeT::get_base_hazard_node (line 95) ... ok
Nov 18 01:19:22.775 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::new_in_heap (line 119) ... ok
Nov 18 01:19:22.987 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::acquire (line 263) ... ok
Nov 18 01:19:23.143 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::new_in_stack (line 82) ... ok
Nov 18 01:19:23.355 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::retire (line 157) ... ok
Nov 18 01:19:23.383 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::add_node (line 193) ... ok
Nov 18 01:19:23.401 INFO [stdout] test src/lockfree_queue.rs - lockfree_queue::LockFreeQueue (line 58) ... ok
Nov 18 01:19:23.401 INFO [stdout] 
Nov 18 01:19:23.401 INFO [stdout] test result: ok. 8 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 18 01:19:23.401 INFO [stdout] 
Nov 18 01:19:23.426 INFO [stderr] su: No module specific data is present
Nov 18 01:19:24.063 INFO running `"docker" "inspect" "45eea24a6e2cd1fd39f70c8c599b209297ceabdda86a9c85438f702ff1c70312"`
Nov 18 01:19:24.277 INFO running `"docker" "rm" "-f" "45eea24a6e2cd1fd39f70c8c599b209297ceabdda86a9c85438f702ff1c70312"`
Nov 18 01:19:24.479 INFO [stdout] 45eea24a6e2cd1fd39f70c8c599b209297ceabdda86a9c85438f702ff1c70312