Dec 14 22:36:35.535 INFO testing rs_lockfree-0.1.1 against try#aa49d8ef14939ddec0e34b346b60174a5673d48f for pr-56550
Dec 14 22:36:35.535 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-3/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-3/pr-56550/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/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 +aa49d8ef14939ddec0e34b346b60174a5673d48f-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:35.921 INFO [stdout] 7c441b3d8caf8c5b35fc906ff3364fc956d679406f8a571c1494d0a659b3c9e6
Dec 14 22:36:35.923 INFO running `"docker" "start" "-a" "7c441b3d8caf8c5b35fc906ff3364fc956d679406f8a571c1494d0a659b3c9e6"`
Dec 14 22:36:37.810 INFO [stderr] usermod: no changes
Dec 14 22:36:37.939 INFO [stderr]    Compiling rs_lockfree v0.1.1 (/source)
Dec 14 22:36:39.272 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 1.44s
Dec 14 22:36:39.283 INFO [stderr] su: No module specific data is present
Dec 14 22:36:40.700 INFO running `"docker" "inspect" "7c441b3d8caf8c5b35fc906ff3364fc956d679406f8a571c1494d0a659b3c9e6"`
Dec 14 22:36:41.029 INFO running `"docker" "rm" "-f" "7c441b3d8caf8c5b35fc906ff3364fc956d679406f8a571c1494d0a659b3c9e6"`
Dec 14 22:36:41.295 INFO [stdout] 7c441b3d8caf8c5b35fc906ff3364fc956d679406f8a571c1494d0a659b3c9e6
Dec 14 22:36:41.300 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-3/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-3/pr-56550/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/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 +aa49d8ef14939ddec0e34b346b60174a5673d48f-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:41.722 INFO [stdout] b4124ee874a9d1921cdb73ee6becbe065297405b06a93dbeff4d63b6710b64cb
Dec 14 22:36:41.727 INFO running `"docker" "start" "-a" "b4124ee874a9d1921cdb73ee6becbe065297405b06a93dbeff4d63b6710b64cb"`
Dec 14 22:36:43.066 INFO [stderr] usermod: no changes
Dec 14 22:36:43.174 INFO [stderr]    Compiling core_affinity v0.5.9
Dec 14 22:36:44.058 INFO [stderr]    Compiling rs_lockfree v0.1.1 (/source)
Dec 14 22:36:55.006 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 11.92s
Dec 14 22:36:55.012 INFO [stderr] su: No module specific data is present
Dec 14 22:36:55.618 INFO running `"docker" "inspect" "b4124ee874a9d1921cdb73ee6becbe065297405b06a93dbeff4d63b6710b64cb"`
Dec 14 22:36:55.867 INFO running `"docker" "rm" "-f" "b4124ee874a9d1921cdb73ee6becbe065297405b06a93dbeff4d63b6710b64cb"`
Dec 14 22:36:56.143 INFO [stdout] b4124ee874a9d1921cdb73ee6becbe065297405b06a93dbeff4d63b6710b64cb
Dec 14 22:36:56.144 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-3/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-3/pr-56550/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/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 +aa49d8ef14939ddec0e34b346b60174a5673d48f-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:36:56.500 INFO [stdout] f761195ebd6c6292b4b54a9bde97e43b1f7ce898a697edb15e73238b7a1457ae
Dec 14 22:36:56.502 INFO running `"docker" "start" "-a" "f761195ebd6c6292b4b54a9bde97e43b1f7ce898a697edb15e73238b7a1457ae"`
Dec 14 22:36:57.239 INFO [stderr] usermod: no changes
Dec 14 22:36:57.307 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.05s
Dec 14 22:36:57.321 INFO [stderr]      Running /target/debug/deps/rs_lockfree-4f9e41a815995d95
Dec 14 22:36:57.327 INFO [stdout] 
Dec 14 22:36:57.327 INFO [stdout] running 7 tests
Dec 14 22:36:57.327 INFO [stdout] test error::test::test_base ... ok
Dec 14 22:36:57.327 INFO [stdout] test lockfree_queue::test::test_base ... ok
Dec 14 22:36:57.327 INFO [stdout] test lockfree_queue::test::test_memory_leak ... ok
Dec 14 22:36:57.327 INFO [stdout] test spin_rwlock::test::test_rwlock ... ok
Dec 14 22:36:57.327 INFO [stdout] test lockfree_stack::test::test_memory_leak ... ok
Dec 14 22:36:57.327 INFO [stdout] test spin_lock::test::test_spin_lock ... ok
Dec 14 22:36:57.327 INFO [stdout] test lockfree_stack::test::test_base ... ok
Dec 14 22:36:57.327 INFO [stdout] 
Dec 14 22:36:57.327 INFO [stdout] test result: ok. 7 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 14 22:36:57.327 INFO [stdout] 
Dec 14 22:36:57.327 INFO [stdout] 
Dec 14 22:36:57.327 INFO [stdout] running 2 tests
Dec 14 22:36:57.327 INFO [stderr]      Running /target/debug/deps/test_hazard_epoch-27ca688415edf855
Dec 14 22:36:57.331 INFO [stdout] test test_base ... ok
Dec 14 22:36:57.331 INFO [stdout] set_cpu_affinity 7 7
Dec 14 22:36:57.331 INFO [stdout] set_cpu_affinity 3 3
Dec 14 22:36:57.331 INFO [stdout] set_cpu_affinity 5 5
Dec 14 22:36:57.335 INFO [stdout] set_cpu_affinity 2 2
Dec 14 22:36:57.335 INFO [stdout] set_cpu_affinity 4 4
Dec 14 22:36:57.344 INFO [stdout] set_cpu_affinity 6 6
Dec 14 22:36:57.395 INFO [stdout] set_cpu_affinity 9 1
Dec 14 22:36:57.399 INFO [stdout] set_cpu_affinity 8 0
Dec 14 22:36:57.399 INFO [stdout] hazard_waiting_count=594
Dec 14 22:36:58.418 INFO [stdout] hazard_waiting_count=39692
Dec 14 22:36:59.423 INFO [stdout] hazard_waiting_count=30972
Dec 14 22:37:00.423 INFO [stdout] hazard_waiting_count=338265
Dec 14 22:37:01.422 INFO [stdout] hazard_waiting_count=273509
Dec 14 22:37:02.431 INFO [stdout] hazard_waiting_count=429967
Dec 14 22:37:03.467 INFO [stdout] hazard_waiting_count=405597
Dec 14 22:37:04.459 INFO [stdout] hazard_waiting_count=217704
Dec 14 22:37:05.471 INFO [stdout] hazard_waiting_count=22979
Dec 14 22:37:06.463 INFO [stdout] hazard_waiting_count=14857
Dec 14 22:37:07.475 INFO [stdout] hazard_waiting_count=221249
Dec 14 22:37:08.471 INFO [stdout] hazard_waiting_count=39110
Dec 14 22:37:09.503 INFO [stdout] hazard_waiting_count=112186
Dec 14 22:37:10.499 INFO [stdout] hazard_waiting_count=299494
Dec 14 22:37:11.539 INFO [stdout] hazard_waiting_count=25938
Dec 14 22:37:12.550 INFO [stdout] hazard_waiting_count=86146
Dec 14 22:37:13.548 INFO [stdout] hazard_waiting_count=519
Dec 14 22:37:14.567 INFO [stdout] hazard_waiting_count=4082
Dec 14 22:37:15.575 INFO [stdout] hazard_waiting_count=19802
Dec 14 22:37:16.591 INFO [stdout] hazard_waiting_count=24990
Dec 14 22:37:17.603 INFO [stdout] hazard_waiting_count=258066
Dec 14 22:37:18.599 INFO [stdout] hazard_waiting_count=1
Dec 14 22:37:19.601 INFO [stdout] hazard_waiting_count=1
Dec 14 22:37:20.604 INFO [stdout] test test_multi_thread ... ok
Dec 14 22:37:20.604 INFO [stdout] 
Dec 14 22:37:20.604 INFO [stdout] test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 14 22:37:20.604 INFO [stdout] 
Dec 14 22:37:20.604 INFO [stderr]      Running /target/debug/deps/test_lockfree_queue-9bb753ae7c2098e9
Dec 14 22:37:20.606 INFO [stdout] 
Dec 14 22:37:20.606 INFO [stdout] running 1 test
Dec 14 22:37:20.615 INFO [stdout] set_cpu_affinity 1 1
Dec 14 22:37:20.623 INFO [stdout] debug_thread produced 1 consumed 0
Dec 14 22:37:20.643 INFO [stdout] set_cpu_affinity 2 2
Dec 14 22:37:20.651 INFO [stdout] set_cpu_affinity 3 3
Dec 14 22:37:20.683 INFO [stdout] set_cpu_affinity 4 4
Dec 14 22:37:20.711 INFO [stdout] set_cpu_affinity 5 5
Dec 14 22:37:20.739 INFO [stdout] set_cpu_affinity 6 6
Dec 14 22:37:20.799 INFO [stdout] set_cpu_affinity 7 7
Dec 14 22:37:20.811 INFO [stdout] set_cpu_affinity 8 0
Dec 14 22:37:21.635 INFO [stdout] debug_thread produced 461316 consumed 438272
Dec 14 22:37:22.635 INFO [stdout] debug_thread produced 865796 consumed 865280
Dec 14 22:37:23.663 INFO [stdout] debug_thread produced 1316868 consumed 1307136
Dec 14 22:37:24.667 INFO [stdout] debug_thread produced 1750020 consumed 1719808
Dec 14 22:37:25.695 INFO [stdout] debug_thread produced 2243076 consumed 2243072
Dec 14 22:37:26.691 INFO [stdout] debug_thread produced 2787844 consumed 2713088
Dec 14 22:37:27.695 INFO [stdout] debug_thread produced 3342852 consumed 3343360
Dec 14 22:37:28.695 INFO [stdout] debug_thread produced 4034564 consumed 4034560
Dec 14 22:37:29.695 INFO [stdout] debug_thread produced 4667908 consumed 4559872
Dec 14 22:37:30.695 INFO [stdout] debug_thread produced 5189636 consumed 5057024
Dec 14 22:37:31.731 INFO [stdout] debug_thread produced 5776900 consumed 5473792
Dec 14 22:37:32.739 INFO [stdout] debug_thread produced 6372356 consumed 6040576
Dec 14 22:37:33.743 INFO [stdout] debug_thread produced 6915076 consumed 6561792
Dec 14 22:37:34.743 INFO [stdout] debug_thread produced 7537668 consumed 7119360
Dec 14 22:37:35.747 INFO [stdout] debug_thread produced 8094212 consumed 7668224
Dec 14 22:37:36.755 INFO [stdout] debug_thread produced 8699908 consumed 8236032
Dec 14 22:37:37.783 INFO [stdout] debug_thread produced 9388548 consumed 8658432
Dec 14 22:37:38.794 INFO [stdout] debug_thread produced 9925124 consumed 9142272
Dec 14 22:37:39.791 INFO [stdout] debug_thread produced 10242390 consumed 9746432
Dec 14 22:37:40.795 INFO [stdout] debug_thread produced 10477055 consumed 10404352
Dec 14 22:37:41.797 INFO [stdout] debug_thread produced 10617855 consumed 10616832
Dec 14 22:37:42.807 INFO [stdout] debug_thread produced 10845183 consumed 10842624
Dec 14 22:37:43.807 INFO [stdout] debug_thread produced 11097599 consumed 11097088
Dec 14 22:37:44.819 INFO [stdout] test test_multi_threads ... ok
Dec 14 22:37:44.819 INFO [stderr]      Running /target/debug/deps/test_lockfree_stack-5a02c19c97f33ef7
Dec 14 22:37:44.819 INFO [stdout] 
Dec 14 22:37:44.819 INFO [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 14 22:37:44.819 INFO [stdout] 
Dec 14 22:37:44.839 INFO [stdout] 
Dec 14 22:37:44.839 INFO [stdout] running 1 test
Dec 14 22:37:44.841 INFO [stdout] debug_thread produced 0 consumed 0
Dec 14 22:37:44.842 INFO [stdout] set_cpu_affinity 2 2
Dec 14 22:37:44.843 INFO [stdout] set_cpu_affinity 1 1
Dec 14 22:37:44.851 INFO [stdout] set_cpu_affinity 3 3
Dec 14 22:37:44.863 INFO [stdout] set_cpu_affinity 4 4
Dec 14 22:37:44.863 INFO [stdout] set_cpu_affinity 5 5
Dec 14 22:37:44.875 INFO [stdout] set_cpu_affinity 6 6
Dec 14 22:37:44.919 INFO [stdout] set_cpu_affinity 7 7
Dec 14 22:37:44.935 INFO [stdout] set_cpu_affinity 8 0
Dec 14 22:37:45.841 INFO [stdout] debug_thread produced 568836 consumed 546816
Dec 14 22:37:46.841 INFO [stdout] debug_thread produced 1371652 consumed 1368064
Dec 14 22:37:47.843 INFO [stdout] debug_thread produced 2097668 consumed 2096640
Dec 14 22:37:48.859 INFO [stdout] debug_thread produced 2737156 consumed 2727424
Dec 14 22:37:49.874 INFO [stdout] debug_thread produced 3332100 consumed 3332096
Dec 14 22:37:50.907 INFO [stdout] debug_thread produced 3977732 consumed 3977216
Dec 14 22:37:51.907 INFO [stdout] debug_thread produced 4571652 consumed 4545024
Dec 14 22:37:52.931 INFO [stdout] debug_thread produced 5081604 consumed 5029376
Dec 14 22:37:53.934 INFO [stdout] debug_thread produced 5761028 consumed 5571072
Dec 14 22:37:54.949 INFO [stdout] debug_thread produced 6420484 consumed 6192128
Dec 14 22:37:55.955 INFO [stdout] debug_thread produced 7064580 consumed 6868992
Dec 14 22:37:56.963 INFO [stdout] debug_thread produced 7835309 consumed 7782400
Dec 14 22:37:57.970 INFO [stdout] debug_thread produced 8499885 consumed 8447488
Dec 14 22:37:58.971 INFO [stdout] debug_thread produced 9152173 consumed 9151488
Dec 14 22:37:59.974 INFO [stdout] debug_thread produced 9622189 consumed 9621504
Dec 14 22:38:00.983 INFO [stdout] debug_thread produced 10027181 consumed 10024960
Dec 14 22:38:01.987 INFO [stdout] debug_thread produced 10539693 consumed 10525184
Dec 14 22:38:03.008 INFO [stdout] debug_thread produced 11120982 consumed 11120128
Dec 14 22:38:04.007 INFO [stdout] test test_multi_threads ... ok
Dec 14 22:38:04.007 INFO [stdout] 
Dec 14 22:38:04.008 INFO [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 14 22:38:04.008 INFO [stdout] 
Dec 14 22:38:04.010 INFO [stderr]    Doc-tests rs_lockfree
Dec 14 22:38:05.244 INFO [stdout] 
Dec 14 22:38:05.244 INFO [stdout] running 8 tests
Dec 14 22:38:08.259 INFO [stdout] test src/hazard_pointer.rs - hazard_pointer::HazardNodeT::get_base_hazard_node (line 95) ... ok
Dec 14 22:38:09.334 INFO [stdout] test src/lockfree_queue.rs - lockfree_queue::LockFreeQueue (line 58) ... ok
Dec 14 22:38:09.491 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::new_in_heap (line 119) ... ok
Dec 14 22:38:09.614 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::add_node (line 193) ... ok
Dec 14 22:38:09.622 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::acquire (line 263) ... ok
Dec 14 22:38:09.701 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::retire (line 157) ... ok
Dec 14 22:38:09.810 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::new_in_stack (line 82) ... ok
Dec 14 22:38:09.901 INFO [stdout] test src/lockfree_stack.rs - lockfree_stack::LockFreeStack (line 58) ... ok
Dec 14 22:38:09.901 INFO [stdout] 
Dec 14 22:38:09.901 INFO [stdout] test result: ok. 8 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 14 22:38:09.902 INFO [stdout] 
Dec 14 22:38:09.921 INFO [stderr] su: No module specific data is present
Dec 14 22:38:10.292 INFO running `"docker" "inspect" "f761195ebd6c6292b4b54a9bde97e43b1f7ce898a697edb15e73238b7a1457ae"`
Dec 14 22:38:10.425 INFO running `"docker" "rm" "-f" "f761195ebd6c6292b4b54a9bde97e43b1f7ce898a697edb15e73238b7a1457ae"`
Dec 14 22:38:10.609 INFO [stdout] f761195ebd6c6292b4b54a9bde97e43b1f7ce898a697edb15e73238b7a1457ae