Dec 14 22:36:41.426 INFO testing rs_lockfree-0.1.1 against master#bd47d6825bf4090517549d33cfef10d3300b4a75 for pr-56550
Dec 14 22:36:41.426 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-7/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-7/pr-56550/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/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 +bd47d6825bf4090517549d33cfef10d3300b4a75-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 14 22:36:41.848 INFO [stdout] ab2a54095b37e5b92c1ce64e0afc8ccbe56d6cf758bbcd774628b4641bb5b95d
Dec 14 22:36:41.859 INFO running `"docker" "start" "-a" "ab2a54095b37e5b92c1ce64e0afc8ccbe56d6cf758bbcd774628b4641bb5b95d"`
Dec 14 22:36:43.442 INFO [stderr] usermod: no changes
Dec 14 22:36:43.521 INFO [stderr]    Compiling rs_lockfree v0.1.1 (/source)
Dec 14 22:36:44.780 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 1.31s
Dec 14 22:36:44.791 INFO [stderr] su: No module specific data is present
Dec 14 22:36:46.000 INFO running `"docker" "inspect" "ab2a54095b37e5b92c1ce64e0afc8ccbe56d6cf758bbcd774628b4641bb5b95d"`
Dec 14 22:36:46.387 INFO running `"docker" "rm" "-f" "ab2a54095b37e5b92c1ce64e0afc8ccbe56d6cf758bbcd774628b4641bb5b95d"`
Dec 14 22:36:46.687 INFO [stdout] ab2a54095b37e5b92c1ce64e0afc8ccbe56d6cf758bbcd774628b4641bb5b95d
Dec 14 22:36:46.693 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-7/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-7/pr-56550/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/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 +bd47d6825bf4090517549d33cfef10d3300b4a75-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 14 22:36:47.052 INFO [stdout] b882bdbb5f744f70218489f367d3a10b639dee15768fc3a5e9074a400bf60b20
Dec 14 22:36:47.057 INFO running `"docker" "start" "-a" "b882bdbb5f744f70218489f367d3a10b639dee15768fc3a5e9074a400bf60b20"`
Dec 14 22:36:48.263 INFO [stderr] usermod: no changes
Dec 14 22:36:48.383 INFO [stderr]    Compiling core_affinity v0.5.9
Dec 14 22:36:49.219 INFO [stderr]    Compiling rs_lockfree v0.1.1 (/source)
Dec 14 22:36:59.549 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 11.26s
Dec 14 22:36:59.560 INFO [stderr] su: No module specific data is present
Dec 14 22:37:00.409 INFO running `"docker" "inspect" "b882bdbb5f744f70218489f367d3a10b639dee15768fc3a5e9074a400bf60b20"`
Dec 14 22:37:00.661 INFO running `"docker" "rm" "-f" "b882bdbb5f744f70218489f367d3a10b639dee15768fc3a5e9074a400bf60b20"`
Dec 14 22:37:00.882 INFO [stdout] b882bdbb5f744f70218489f367d3a10b639dee15768fc3a5e9074a400bf60b20
Dec 14 22:37:00.883 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-7/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-7/pr-56550/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/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 +bd47d6825bf4090517549d33cfef10d3300b4a75-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 14 22:37:01.252 INFO [stdout] 9ca751805b9a6ce2683dd3111ec11440ffab08bdbe08d86af660227730641217
Dec 14 22:37:01.256 INFO running `"docker" "start" "-a" "9ca751805b9a6ce2683dd3111ec11440ffab08bdbe08d86af660227730641217"`
Dec 14 22:37:02.670 INFO [stderr] usermod: no changes
Dec 14 22:37:02.823 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.12s
Dec 14 22:37:02.839 INFO [stderr]      Running /target/debug/deps/rs_lockfree-8832152c810d5061
Dec 14 22:37:02.842 INFO [stdout] 
Dec 14 22:37:02.842 INFO [stdout] running 7 tests
Dec 14 22:37:02.867 INFO [stdout] test error::test::test_base ... ok
Dec 14 22:37:02.867 INFO [stdout] test lockfree_queue::test::test_base ... ok
Dec 14 22:37:02.867 INFO [stdout] test lockfree_queue::test::test_memory_leak ... ok
Dec 14 22:37:02.867 INFO [stdout] test spin_lock::test::test_spin_lock ... ok
Dec 14 22:37:02.867 INFO [stdout] test spin_rwlock::test::test_rwlock ... ok
Dec 14 22:37:02.867 INFO [stdout] test lockfree_stack::test::test_memory_leak ... ok
Dec 14 22:37:02.867 INFO [stdout] test lockfree_stack::test::test_base ... ok
Dec 14 22:37:02.867 INFO [stdout] 
Dec 14 22:37:02.867 INFO [stdout] test result: ok. 7 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 14 22:37:02.867 INFO [stdout] 
Dec 14 22:37:02.867 INFO [stderr]      Running /target/debug/deps/test_hazard_epoch-b85927ebae740746
Dec 14 22:37:02.870 INFO [stdout] 
Dec 14 22:37:02.870 INFO [stdout] running 2 tests
Dec 14 22:37:02.870 INFO [stdout] test test_base ... ok
Dec 14 22:37:02.875 INFO [stdout] set_cpu_affinity 2 2
Dec 14 22:37:02.875 INFO [stdout] set_cpu_affinity 3 3
Dec 14 22:37:02.875 INFO [stdout] hazard_waiting_count=195
Dec 14 22:37:02.875 INFO [stdout] set_cpu_affinity 4 4
Dec 14 22:37:02.878 INFO [stdout] set_cpu_affinity 5 5
Dec 14 22:37:02.878 INFO [stdout] set_cpu_affinity 9 1
Dec 14 22:37:02.882 INFO [stdout] set_cpu_affinity 6 6
Dec 14 22:37:02.882 INFO [stdout] set_cpu_affinity 7 7
Dec 14 22:37:02.882 INFO [stdout] set_cpu_affinity 8 0
Dec 14 22:37:03.879 INFO [stdout] hazard_waiting_count=24003
Dec 14 22:37:04.903 INFO [stdout] hazard_waiting_count=16099
Dec 14 22:37:05.959 INFO [stdout] hazard_waiting_count=49706
Dec 14 22:37:06.967 INFO [stdout] hazard_waiting_count=6362
Dec 14 22:37:07.975 INFO [stdout] hazard_waiting_count=264
Dec 14 22:37:08.967 INFO [stdout] hazard_waiting_count=98
Dec 14 22:37:09.991 INFO [stdout] hazard_waiting_count=513
Dec 14 22:37:10.991 INFO [stdout] hazard_waiting_count=33164
Dec 14 22:37:11.995 INFO [stdout] hazard_waiting_count=47798
Dec 14 22:37:12.995 INFO [stdout] hazard_waiting_count=7781
Dec 14 22:37:13.999 INFO [stdout] hazard_waiting_count=23217
Dec 14 22:37:14.999 INFO [stdout] hazard_waiting_count=49697
Dec 14 22:37:15.997 INFO [stdout] hazard_waiting_count=2170
Dec 14 22:37:17.003 INFO [stdout] hazard_waiting_count=7209
Dec 14 22:37:18.007 INFO [stdout] hazard_waiting_count=91548
Dec 14 22:37:19.007 INFO [stdout] hazard_waiting_count=37223
Dec 14 22:37:20.019 INFO [stdout] hazard_waiting_count=3928
Dec 14 22:37:21.023 INFO [stdout] hazard_waiting_count=731249
Dec 14 22:37:22.019 INFO [stdout] hazard_waiting_count=212328
Dec 14 22:37:23.039 INFO [stdout] hazard_waiting_count=116562
Dec 14 22:37:24.043 INFO [stdout] hazard_waiting_count=93183
Dec 14 22:37:25.039 INFO [stdout] hazard_waiting_count=211613
Dec 14 22:37:26.059 INFO [stdout] hazard_waiting_count=234349
Dec 14 22:37:27.071 INFO [stdout] hazard_waiting_count=154056
Dec 14 22:37:28.073 INFO [stdout] hazard_waiting_count=472
Dec 14 22:37:29.070 INFO [stdout] test test_multi_thread ... ok
Dec 14 22:37:29.070 INFO [stdout] 
Dec 14 22:37:29.070 INFO [stdout] test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 14 22:37:29.070 INFO [stdout] 
Dec 14 22:37:29.072 INFO [stderr]      Running /target/debug/deps/test_lockfree_queue-da97026ccf1a232a
Dec 14 22:37:29.074 INFO [stdout] 
Dec 14 22:37:29.074 INFO [stdout] running 1 test
Dec 14 22:37:29.075 INFO [stdout] set_cpu_affinity 1 1
Dec 14 22:37:29.075 INFO [stdout] set_cpu_affinity 4 4
Dec 14 22:37:29.081 INFO [stdout] set_cpu_affinity 2 2
Dec 14 22:37:29.087 INFO [stdout] set_cpu_affinity 3 3
Dec 14 22:37:29.095 INFO [stdout] set_cpu_affinity 5 5
Dec 14 22:37:29.099 INFO [stdout] debug_thread produced 8707 consumed 7168
Dec 14 22:37:29.099 INFO [stdout] set_cpu_affinity 6 6
Dec 14 22:37:29.099 INFO [stdout] set_cpu_affinity 7 7
Dec 14 22:37:29.120 INFO [stdout] set_cpu_affinity 8 0
Dec 14 22:37:30.109 INFO [stdout] debug_thread produced 587780 consumed 482304
Dec 14 22:37:31.123 INFO [stdout] debug_thread produced 1159684 consumed 1003520
Dec 14 22:37:32.135 INFO [stdout] debug_thread produced 1787908 consumed 1587712
Dec 14 22:37:33.151 INFO [stdout] debug_thread produced 2309124 consumed 2240512
Dec 14 22:37:34.155 INFO [stdout] debug_thread produced 2784772 consumed 2777088
Dec 14 22:37:35.151 INFO [stdout] debug_thread produced 3269636 consumed 3265024
Dec 14 22:37:36.153 INFO [stdout] debug_thread produced 3767812 consumed 3735040
Dec 14 22:37:37.179 INFO [stdout] debug_thread produced 4391940 consumed 4322304
Dec 14 22:37:38.171 INFO [stdout] debug_thread produced 4858372 consumed 4796928
Dec 14 22:37:39.175 INFO [stdout] debug_thread produced 5366276 consumed 5326336
Dec 14 22:37:40.174 INFO [stdout] debug_thread produced 5880836 consumed 5873152
Dec 14 22:37:41.179 INFO [stdout] debug_thread produced 6321156 consumed 6306304
Dec 14 22:37:42.182 INFO [stdout] debug_thread produced 6969860 consumed 6809600
Dec 14 22:37:43.205 INFO [stdout] debug_thread produced 7532548 consumed 7225856
Dec 14 22:37:44.207 INFO [stdout] debug_thread produced 8131588 consumed 8023040
Dec 14 22:37:45.211 INFO [stdout] debug_thread produced 8826884 consumed 8801792
Dec 14 22:37:46.211 INFO [stdout] debug_thread produced 9541974 consumed 9308672
Dec 14 22:37:47.207 INFO [stdout] debug_thread produced 10013526 consumed 10013184
Dec 14 22:37:48.211 INFO [stdout] debug_thread produced 10404182 consumed 10403328
Dec 14 22:37:49.216 INFO [stdout] debug_thread produced 10807295 consumed 10806272
Dec 14 22:37:50.221 INFO [stdout] debug_thread produced 11113983 consumed 11113984
Dec 14 22:37:51.226 INFO [stdout] test test_multi_threads ... ok
Dec 14 22:37:51.226 INFO [stderr]      Running /target/debug/deps/test_lockfree_stack-1d45fef0525866ce
Dec 14 22:37:51.226 INFO [stdout] 
Dec 14 22:37:51.226 INFO [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 14 22:37:51.226 INFO [stdout] 
Dec 14 22:37:51.230 INFO [stdout] 
Dec 14 22:37:51.231 INFO [stdout] running 1 test
Dec 14 22:37:51.234 INFO [stdout] set_cpu_affinity 6 6
Dec 14 22:37:51.234 INFO [stdout] set_cpu_affinity 1 1
Dec 14 22:37:51.234 INFO [stdout] set_cpu_affinity 7 7
Dec 14 22:37:51.235 INFO [stdout] debug_thread produced 1 consumed 0
Dec 14 22:37:51.235 INFO [stdout] set_cpu_affinity 4 4
Dec 14 22:37:51.235 INFO [stdout] set_cpu_affinity 5 5
Dec 14 22:37:51.238 INFO [stdout] set_cpu_affinity 2 2
Dec 14 22:37:51.242 INFO [stdout] set_cpu_affinity 3 3
Dec 14 22:37:51.258 INFO [stdout] set_cpu_affinity 8 0
Dec 14 22:37:52.235 INFO [stdout] debug_thread produced 545796 consumed 516608
Dec 14 22:37:53.263 INFO [stdout] debug_thread produced 1039876 consumed 1034752
Dec 14 22:37:54.262 INFO [stdout] debug_thread produced 1671684 consumed 1671168
Dec 14 22:37:55.280 INFO [stdout] debug_thread produced 2283012 consumed 2274816
Dec 14 22:37:56.295 INFO [stdout] debug_thread produced 3081220 consumed 3079680
Dec 14 22:37:57.287 INFO [stdout] debug_thread produced 3856388 consumed 3846656
Dec 14 22:37:58.294 INFO [stdout] debug_thread produced 4504068 consumed 4469760
Dec 14 22:37:59.338 INFO [stdout] debug_thread produced 5064708 consumed 5064704
Dec 14 22:38:00.338 INFO [stdout] debug_thread produced 5671940 consumed 5587968
Dec 14 22:38:01.339 INFO [stdout] debug_thread produced 6138884 consumed 6133760
Dec 14 22:38:02.351 INFO [stdout] debug_thread produced 6650372 consumed 6646272
Dec 14 22:38:03.351 INFO [stdout] debug_thread produced 7444484 consumed 7344640
Dec 14 22:38:04.373 INFO [stdout] debug_thread produced 8286212 consumed 8286208
Dec 14 22:38:05.367 INFO [stdout] debug_thread produced 9361412 consumed 9247232
Dec 14 22:38:06.387 INFO [stdout] debug_thread produced 10167126 consumed 10153984
Dec 14 22:38:07.394 INFO [stdout] debug_thread produced 10615638 consumed 10615296
Dec 14 22:38:08.393 INFO [stdout] debug_thread produced 11141119 consumed 11140096
Dec 14 22:38:09.399 INFO [stdout] test test_multi_threads ... ok
Dec 14 22:38:09.399 INFO [stdout] 
Dec 14 22:38:09.399 INFO [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 14 22:38:09.399 INFO [stdout] 
Dec 14 22:38:09.434 INFO [stderr]    Doc-tests rs_lockfree
Dec 14 22:38:10.439 INFO [stdout] 
Dec 14 22:38:10.439 INFO [stdout] running 8 tests
Dec 14 22:38:13.059 INFO [stdout] test src/hazard_pointer.rs - hazard_pointer::HazardNodeT::get_base_hazard_node (line 95) ... ok
Dec 14 22:38:13.971 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::add_node (line 193) ... ok
Dec 14 22:38:13.984 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::new_in_stack (line 82) ... ok
Dec 14 22:38:14.093 INFO [stdout] test src/lockfree_queue.rs - lockfree_queue::LockFreeQueue (line 58) ... ok
Dec 14 22:38:14.275 INFO [stdout] test src/lockfree_stack.rs - lockfree_stack::LockFreeStack (line 58) ... ok
Dec 14 22:38:14.394 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::acquire (line 263) ... ok
Dec 14 22:38:14.414 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::retire (line 157) ... ok
Dec 14 22:38:14.617 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::new_in_heap (line 119) ... ok
Dec 14 22:38:14.617 INFO [stdout] 
Dec 14 22:38:14.617 INFO [stdout] test result: ok. 8 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 14 22:38:14.617 INFO [stdout] 
Dec 14 22:38:14.639 INFO [stderr] su: No module specific data is present
Dec 14 22:38:15.001 INFO running `"docker" "inspect" "9ca751805b9a6ce2683dd3111ec11440ffab08bdbe08d86af660227730641217"`
Dec 14 22:38:15.084 INFO running `"docker" "rm" "-f" "9ca751805b9a6ce2683dd3111ec11440ffab08bdbe08d86af660227730641217"`
Dec 14 22:38:15.215 INFO [stdout] 9ca751805b9a6ce2683dd3111ec11440ffab08bdbe08d86af660227730641217