Nov 18 01:18:12.228 INFO testing rs_lockfree-0.1.1 against master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c for pr-55982
Nov 18 01:18:12.229 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-55982/worker-3/master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-3/pr-55982/master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c:/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 +6b9b97bd9b704f85f0184f7a213cc4d62bd9654c-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:18:12.752 INFO [stdout] 5bafba45cdadacf8997cd9ab146e1923ebb66a6ee77a361f69eeefec1559ebeb
Nov 18 01:18:12.757 INFO running `"docker" "start" "-a" "5bafba45cdadacf8997cd9ab146e1923ebb66a6ee77a361f69eeefec1559ebeb"`
Nov 18 01:18:14.471 INFO [stderr] usermod: no changes
Nov 18 01:18:14.619 INFO [stderr]    Compiling rs_lockfree v0.1.1 (/source)
Nov 18 01:18:15.918 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 1.42s
Nov 18 01:18:15.928 INFO [stderr] su: No module specific data is present
Nov 18 01:18:16.291 INFO running `"docker" "inspect" "5bafba45cdadacf8997cd9ab146e1923ebb66a6ee77a361f69eeefec1559ebeb"`
Nov 18 01:18:16.504 INFO running `"docker" "rm" "-f" "5bafba45cdadacf8997cd9ab146e1923ebb66a6ee77a361f69eeefec1559ebeb"`
Nov 18 01:18:16.719 INFO [stdout] 5bafba45cdadacf8997cd9ab146e1923ebb66a6ee77a361f69eeefec1559ebeb
Nov 18 01:18:16.719 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-55982/worker-3/master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-3/pr-55982/master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c:/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 +6b9b97bd9b704f85f0184f7a213cc4d62bd9654c-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:16.987 INFO [stdout] 32dd5ea22878fa6bff70352e9e467a446acca26ec594d0027ee6865c1741c601
Nov 18 01:18:16.991 INFO running `"docker" "start" "-a" "32dd5ea22878fa6bff70352e9e467a446acca26ec594d0027ee6865c1741c601"`
Nov 18 01:18:17.555 INFO [stderr] usermod: no changes
Nov 18 01:18:17.677 INFO [stderr]    Compiling core_affinity v0.5.9
Nov 18 01:18:18.328 INFO [stderr]    Compiling rs_lockfree v0.1.1 (/source)
Nov 18 01:18:28.079 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 10.49s
Nov 18 01:18:28.095 INFO [stderr] su: No module specific data is present
Nov 18 01:18:28.573 INFO running `"docker" "inspect" "32dd5ea22878fa6bff70352e9e467a446acca26ec594d0027ee6865c1741c601"`
Nov 18 01:18:28.739 INFO running `"docker" "rm" "-f" "32dd5ea22878fa6bff70352e9e467a446acca26ec594d0027ee6865c1741c601"`
Nov 18 01:18:28.923 INFO [stdout] 32dd5ea22878fa6bff70352e9e467a446acca26ec594d0027ee6865c1741c601
Nov 18 01:18:28.925 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-55982/worker-3/master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-3/pr-55982/master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c:/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 +6b9b97bd9b704f85f0184f7a213cc4d62bd9654c-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:29.271 INFO [stdout] 78f9115f39cab08402d8964bbbfe69c3262247f99a647e81581e424de19d66f1
Nov 18 01:18:29.273 INFO running `"docker" "start" "-a" "78f9115f39cab08402d8964bbbfe69c3262247f99a647e81581e424de19d66f1"`
Nov 18 01:18:30.158 INFO [stderr] usermod: no changes
Nov 18 01:18:30.267 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.08s
Nov 18 01:18:30.281 INFO [stderr]      Running /target/debug/deps/rs_lockfree-559db84d127e2e7f
Nov 18 01:18:30.295 INFO [stdout] 
Nov 18 01:18:30.295 INFO [stdout] running 7 tests
Nov 18 01:18:30.295 INFO [stdout] test error::test::test_base ... ok
Nov 18 01:18:30.295 INFO [stdout] test lockfree_stack::test::test_memory_leak ... ok
Nov 18 01:18:30.295 INFO [stdout] test lockfree_queue::test::test_memory_leak ... ok
Nov 18 01:18:30.295 INFO [stdout] test lockfree_stack::test::test_base ... ok
Nov 18 01:18:30.295 INFO [stdout] test lockfree_queue::test::test_base ... ok
Nov 18 01:18:30.299 INFO [stdout] test spin_lock::test::test_spin_lock ... ok
Nov 18 01:18:30.299 INFO [stdout] test spin_rwlock::test::test_rwlock ... ok
Nov 18 01:18:30.299 INFO [stdout] 
Nov 18 01:18:30.299 INFO [stdout] test result: ok. 7 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 18 01:18:30.299 INFO [stdout] 
Nov 18 01:18:30.301 INFO [stderr]      Running /target/debug/deps/test_hazard_epoch-bf0b8ce90f34427e
Nov 18 01:18:30.302 INFO [stdout] 
Nov 18 01:18:30.302 INFO [stdout] running 2 tests
Nov 18 01:18:30.303 INFO [stdout] set_cpu_affinity 2 2
Nov 18 01:18:30.303 INFO [stdout] test test_base ... ok
Nov 18 01:18:30.303 INFO [stdout] set_cpu_affinity 5 5
Nov 18 01:18:30.303 INFO [stdout] hazard_waiting_count=115
Nov 18 01:18:30.307 INFO [stdout] set_cpu_affinity 6 6
Nov 18 01:18:30.307 INFO [stdout] set_cpu_affinity 7 7
Nov 18 01:18:30.307 INFO [stdout] set_cpu_affinity 8 0
Nov 18 01:18:30.307 INFO [stdout] set_cpu_affinity 3 3
Nov 18 01:18:30.315 INFO [stdout] set_cpu_affinity 4 4
Nov 18 01:18:30.347 INFO [stdout] set_cpu_affinity 9 1
Nov 18 01:18:31.315 INFO [stdout] hazard_waiting_count=12365
Nov 18 01:18:32.335 INFO [stdout] hazard_waiting_count=10333
Nov 18 01:18:33.359 INFO [stdout] hazard_waiting_count=25989
Nov 18 01:18:34.359 INFO [stdout] hazard_waiting_count=14281
Nov 18 01:18:35.367 INFO [stdout] hazard_waiting_count=10844
Nov 18 01:18:36.383 INFO [stdout] hazard_waiting_count=3614
Nov 18 01:18:37.391 INFO [stdout] hazard_waiting_count=520
Nov 18 01:18:38.395 INFO [stdout] hazard_waiting_count=44144
Nov 18 01:18:39.407 INFO [stdout] hazard_waiting_count=7032
Nov 18 01:18:40.419 INFO [stdout] hazard_waiting_count=12801
Nov 18 01:18:41.431 INFO [stdout] hazard_waiting_count=12994
Nov 18 01:18:42.455 INFO [stdout] hazard_waiting_count=18385
Nov 18 01:18:43.479 INFO [stdout] hazard_waiting_count=34157
Nov 18 01:18:44.507 INFO [stdout] hazard_waiting_count=76099
Nov 18 01:18:45.507 INFO [stdout] hazard_waiting_count=27481
Nov 18 01:18:46.511 INFO [stdout] hazard_waiting_count=169502
Nov 18 01:18:47.519 INFO [stdout] hazard_waiting_count=331748
Nov 18 01:18:48.515 INFO [stdout] hazard_waiting_count=252421
Nov 18 01:18:49.519 INFO [stdout] hazard_waiting_count=305750
Nov 18 01:18:50.515 INFO [stdout] hazard_waiting_count=12686
Nov 18 01:18:51.523 INFO [stdout] hazard_waiting_count=693
Nov 18 01:18:52.535 INFO [stdout] hazard_waiting_count=10432
Nov 18 01:18:53.531 INFO [stdout] hazard_waiting_count=385
Nov 18 01:18:54.531 INFO [stdout] hazard_waiting_count=385
Nov 18 01:18:55.528 INFO [stdout] hazard_waiting_count=385
Nov 18 01:18:56.531 INFO [stdout] test test_multi_thread ... ok
Nov 18 01:18:56.531 INFO [stdout] 
Nov 18 01:18:56.531 INFO [stdout] test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 18 01:18:56.531 INFO [stdout] 
Nov 18 01:18:56.538 INFO [stderr]      Running /target/debug/deps/test_lockfree_queue-065478706075f85e
Nov 18 01:18:56.543 INFO [stdout] 
Nov 18 01:18:56.543 INFO [stdout] running 1 test
Nov 18 01:18:56.543 INFO [stdout] set_cpu_affinity 4 4
Nov 18 01:18:56.543 INFO [stdout] set_cpu_affinity 1 1
Nov 18 01:18:56.543 INFO [stdout] set_cpu_affinity 2 2
Nov 18 01:18:56.543 INFO [stdout] set_cpu_affinity 3 3
Nov 18 01:18:56.543 INFO [stdout] set_cpu_affinity 6 6
Nov 18 01:18:56.543 INFO [stdout] set_cpu_affinity 5 5
Nov 18 01:18:56.551 INFO [stdout] set_cpu_affinity 7 7
Nov 18 01:18:56.555 INFO [stdout] debug_thread produced 7172 consumed 7680
Nov 18 01:18:56.555 INFO [stdout] set_cpu_affinity 8 0
Nov 18 01:18:57.552 INFO [stdout] debug_thread produced 537092 consumed 534528
Nov 18 01:18:58.560 INFO [stdout] debug_thread produced 1393668 consumed 1375232
Nov 18 01:18:59.555 INFO [stdout] debug_thread produced 2478596 consumed 2398720
Nov 18 01:19:00.567 INFO [stdout] debug_thread produced 3341316 consumed 3288064
Nov 18 01:19:01.579 INFO [stdout] debug_thread produced 4025348 consumed 3965440
Nov 18 01:19:02.607 INFO [stdout] debug_thread produced 4539908 consumed 4535808
Nov 18 01:19:03.626 INFO [stdout] debug_thread produced 5068804 consumed 5038080
Nov 18 01:19:04.631 INFO [stdout] debug_thread produced 5572100 consumed 5570048
Nov 18 01:19:05.639 INFO [stdout] debug_thread produced 6178820 consumed 6175744
Nov 18 01:19:06.643 INFO [stdout] debug_thread produced 6854148 consumed 6796288
Nov 18 01:19:07.639 INFO [stdout] debug_thread produced 7623172 consumed 7492608
Nov 18 01:19:08.646 INFO [stdout] debug_thread produced 8292868 consumed 8119808
Nov 18 01:19:09.647 INFO [stdout] debug_thread produced 9181188 consumed 8839168
Nov 18 01:19:10.653 INFO [stdout] debug_thread produced 9951236 consumed 9679360
Nov 18 01:19:11.669 INFO [stdout] debug_thread produced 10790916 consumed 10488832
Nov 18 01:19:12.658 INFO [stdout] test test_multi_threads ... ok
Nov 18 01:19:12.658 INFO [stdout] 
Nov 18 01:19:12.658 INFO [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 18 01:19:12.658 INFO [stdout] 
Nov 18 01:19:12.660 INFO [stderr]      Running /target/debug/deps/test_lockfree_stack-80b6e88b9a341bab
Nov 18 01:19:12.667 INFO [stdout] 
Nov 18 01:19:12.667 INFO [stdout] running 1 test
Nov 18 01:19:12.667 INFO [stdout] set_cpu_affinity 1 1
Nov 18 01:19:12.667 INFO [stdout] set_cpu_affinity 5 5
Nov 18 01:19:12.667 INFO [stdout] set_cpu_affinity 4 4
Nov 18 01:19:12.667 INFO [stdout] set_cpu_affinity 2 2
Nov 18 01:19:12.667 INFO [stdout] debug_thread produced 4609 consumed 3072
Nov 18 01:19:12.670 INFO [stdout] set_cpu_affinity 6 6
Nov 18 01:19:12.671 INFO [stdout] set_cpu_affinity 8 0
Nov 18 01:19:12.679 INFO [stdout] set_cpu_affinity 3 3
Nov 18 01:19:12.679 INFO [stdout] set_cpu_affinity 7 7
Nov 18 01:19:13.671 INFO [stdout] debug_thread produced 710148 consumed 709120
Nov 18 01:19:14.675 INFO [stdout] debug_thread produced 1333764 consumed 1333248
Nov 18 01:19:15.671 INFO [stdout] debug_thread produced 1884164 consumed 1883648
Nov 18 01:19:16.675 INFO [stdout] debug_thread produced 2740228 consumed 2672128
Nov 18 01:19:17.671 INFO [stdout] debug_thread produced 4054532 consumed 3964416
Nov 18 01:19:18.691 INFO [stdout] debug_thread produced 5001220 consumed 5001728
Nov 18 01:19:19.691 INFO [stdout] debug_thread produced 5827076 consumed 5827072
Nov 18 01:19:20.698 INFO [stdout] debug_thread produced 6555652 consumed 6435328
Nov 18 01:19:21.699 INFO [stdout] debug_thread produced 7013037 consumed 6995968
Nov 18 01:19:22.699 INFO [stdout] debug_thread produced 7547565 consumed 7485952
Nov 18 01:19:23.710 INFO [stdout] debug_thread produced 8359085 consumed 8283648
Nov 18 01:19:24.719 INFO [stdout] debug_thread produced 9301165 consumed 9277952
Nov 18 01:19:25.719 INFO [stdout] debug_thread produced 10438317 consumed 10438144
Nov 18 01:19:26.720 INFO [stdout] test test_multi_threads ... ok
Nov 18 01:19:26.720 INFO [stdout] 
Nov 18 01:19:26.720 INFO [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 18 01:19:26.720 INFO [stdout] 
Nov 18 01:19:26.723 INFO [stderr]    Doc-tests rs_lockfree
Nov 18 01:19:27.621 INFO [stdout] 
Nov 18 01:19:27.621 INFO [stdout] running 8 tests
Nov 18 01:19:31.158 INFO [stdout] test src/lockfree_queue.rs - lockfree_queue::LockFreeQueue (line 58) ... ok
Nov 18 01:19:31.207 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::add_node (line 193) ... ok
Nov 18 01:19:31.803 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::new_in_heap (line 119) ... ok
Nov 18 01:19:31.860 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::retire (line 157) ... ok
Nov 18 01:19:32.220 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::acquire (line 263) ... ok
Nov 18 01:19:32.288 INFO [stdout] test src/lockfree_stack.rs - lockfree_stack::LockFreeStack (line 58) ... ok
Nov 18 01:19:32.349 INFO [stdout] test src/hazard_pointer.rs - hazard_pointer::HazardNodeT::get_base_hazard_node (line 95) ... ok
Nov 18 01:19:32.387 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::new_in_stack (line 82) ... ok
Nov 18 01:19:32.387 INFO [stdout] 
Nov 18 01:19:32.387 INFO [stdout] test result: ok. 8 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 18 01:19:32.387 INFO [stdout] 
Nov 18 01:19:32.411 INFO [stderr] su: No module specific data is present
Nov 18 01:19:32.993 INFO running `"docker" "inspect" "78f9115f39cab08402d8964bbbfe69c3262247f99a647e81581e424de19d66f1"`
Nov 18 01:19:33.148 INFO running `"docker" "rm" "-f" "78f9115f39cab08402d8964bbbfe69c3262247f99a647e81581e424de19d66f1"`
Nov 18 01:19:33.323 INFO [stdout] 78f9115f39cab08402d8964bbbfe69c3262247f99a647e81581e424de19d66f1