Dec 07 01:37:10.370 INFO testing rs_lockfree-0.1.1 against master#906deae0790bd18681b937fe9a141a3c26cf1855 for pr-56514
Dec 07 01:37:10.370 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56514/worker-3/master#906deae0790bd18681b937fe9a141a3c26cf1855:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-3/pr-56514/master#906deae0790bd18681b937fe9a141a3c26cf1855:/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 +906deae0790bd18681b937fe9a141a3c26cf1855-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 07 01:37:10.832 INFO [stdout] 6aa221b7254de077d528491583e542fec3233a1d79776b7273751c2998620ddd
Dec 07 01:37:10.834 INFO running `"docker" "start" "-a" "6aa221b7254de077d528491583e542fec3233a1d79776b7273751c2998620ddd"`
Dec 07 01:37:12.132 INFO [stderr] usermod: no changes
Dec 07 01:37:12.218 INFO [stderr]    Compiling rs_lockfree v0.1.1 (/source)
Dec 07 01:37:13.608 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 1.45s
Dec 07 01:37:13.612 INFO [stderr] su: No module specific data is present
Dec 07 01:37:14.712 INFO running `"docker" "inspect" "6aa221b7254de077d528491583e542fec3233a1d79776b7273751c2998620ddd"`
Dec 07 01:37:14.983 INFO running `"docker" "rm" "-f" "6aa221b7254de077d528491583e542fec3233a1d79776b7273751c2998620ddd"`
Dec 07 01:37:15.215 INFO [stdout] 6aa221b7254de077d528491583e542fec3233a1d79776b7273751c2998620ddd
Dec 07 01:37:15.218 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56514/worker-3/master#906deae0790bd18681b937fe9a141a3c26cf1855:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-3/pr-56514/master#906deae0790bd18681b937fe9a141a3c26cf1855:/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 +906deae0790bd18681b937fe9a141a3c26cf1855-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 07 01:37:15.640 INFO [stdout] dff7c964627e1d1b16f02b2749c007e469d44ba78ea492852f18a52ef560da9a
Dec 07 01:37:15.645 INFO running `"docker" "start" "-a" "dff7c964627e1d1b16f02b2749c007e469d44ba78ea492852f18a52ef560da9a"`
Dec 07 01:37:16.885 INFO [stderr] usermod: no changes
Dec 07 01:37:16.976 INFO [stderr]    Compiling rs_lockfree v0.1.1 (/source)
Dec 07 01:37:29.155 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 12.25s
Dec 07 01:37:29.162 INFO [stderr] su: No module specific data is present
Dec 07 01:37:30.217 INFO running `"docker" "inspect" "dff7c964627e1d1b16f02b2749c007e469d44ba78ea492852f18a52ef560da9a"`
Dec 07 01:37:30.481 INFO running `"docker" "rm" "-f" "dff7c964627e1d1b16f02b2749c007e469d44ba78ea492852f18a52ef560da9a"`
Dec 07 01:37:30.748 INFO [stdout] dff7c964627e1d1b16f02b2749c007e469d44ba78ea492852f18a52ef560da9a
Dec 07 01:37:30.756 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56514/worker-3/master#906deae0790bd18681b937fe9a141a3c26cf1855:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-3/pr-56514/master#906deae0790bd18681b937fe9a141a3c26cf1855:/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 +906deae0790bd18681b937fe9a141a3c26cf1855-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 07 01:37:31.192 INFO [stdout] 962ee5449b6da36264e8a6d2a6435479f7eb6dcdbf4f9634f58b0b4c5e039c1e
Dec 07 01:37:31.194 INFO running `"docker" "start" "-a" "962ee5449b6da36264e8a6d2a6435479f7eb6dcdbf4f9634f58b0b4c5e039c1e"`
Dec 07 01:37:32.579 INFO [stderr] usermod: no changes
Dec 07 01:37:32.745 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.13s
Dec 07 01:37:32.759 INFO [stderr]      Running /target/debug/deps/rs_lockfree-db296a216112e215
Dec 07 01:37:32.766 INFO [stdout] 
Dec 07 01:37:32.766 INFO [stdout] running 7 tests
Dec 07 01:37:32.769 INFO [stdout] test error::test::test_base ... ok
Dec 07 01:37:32.769 INFO [stdout] test lockfree_queue::test::test_memory_leak ... ok
Dec 07 01:37:32.769 INFO [stdout] test lockfree_queue::test::test_base ... ok
Dec 07 01:37:32.769 INFO [stdout] test spin_lock::test::test_spin_lock ... ok
Dec 07 01:37:32.769 INFO [stdout] test lockfree_stack::test::test_base ... ok
Dec 07 01:37:32.769 INFO [stdout] test spin_rwlock::test::test_rwlock ... ok
Dec 07 01:37:32.772 INFO [stdout] test lockfree_stack::test::test_memory_leak ... ok
Dec 07 01:37:32.772 INFO [stdout] 
Dec 07 01:37:32.772 INFO [stdout] test result: ok. 7 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 07 01:37:32.772 INFO [stdout] 
Dec 07 01:37:32.773 INFO [stderr]      Running /target/debug/deps/test_hazard_epoch-305c1b3c60a54591
Dec 07 01:37:32.778 INFO [stdout] 
Dec 07 01:37:32.778 INFO [stdout] running 2 tests
Dec 07 01:37:32.779 INFO [stdout] hazard_waiting_count=0
Dec 07 01:37:32.779 INFO [stdout] test test_base ... ok
Dec 07 01:37:32.779 INFO [stdout] set_cpu_affinity 3 3
Dec 07 01:37:32.779 INFO [stdout] set_cpu_affinity 5 5
Dec 07 01:37:32.780 INFO [stdout] set_cpu_affinity 6 6
Dec 07 01:37:32.780 INFO [stdout] set_cpu_affinity 2 2
Dec 07 01:37:32.780 INFO [stdout] set_cpu_affinity 7 7
Dec 07 01:37:32.784 INFO [stdout] set_cpu_affinity 1 1
Dec 07 01:37:32.792 INFO [stdout] set_cpu_affinity 8 0
Dec 07 01:37:32.836 INFO [stdout] set_cpu_affinity 9 1
Dec 07 01:37:33.780 INFO [stdout] hazard_waiting_count=43436
Dec 07 01:37:34.789 INFO [stdout] hazard_waiting_count=11206
Dec 07 01:37:35.804 INFO [stdout] hazard_waiting_count=29590
Dec 07 01:37:36.806 INFO [stdout] hazard_waiting_count=6663
Dec 07 01:37:37.808 INFO [stdout] hazard_waiting_count=28542
Dec 07 01:37:38.816 INFO [stdout] hazard_waiting_count=13235
Dec 07 01:37:39.837 INFO [stdout] hazard_waiting_count=15644
Dec 07 01:37:40.856 INFO [stdout] hazard_waiting_count=23990
Dec 07 01:37:41.860 INFO [stdout] hazard_waiting_count=37847
Dec 07 01:37:42.868 INFO [stdout] hazard_waiting_count=3391
Dec 07 01:37:43.888 INFO [stdout] hazard_waiting_count=109271
Dec 07 01:37:44.900 INFO [stdout] hazard_waiting_count=104954
Dec 07 01:37:45.896 INFO [stdout] hazard_waiting_count=243738
Dec 07 01:37:46.909 INFO [stdout] hazard_waiting_count=49182
Dec 07 01:37:47.908 INFO [stdout] hazard_waiting_count=11480
Dec 07 01:37:48.904 INFO [stdout] hazard_waiting_count=29654
Dec 07 01:37:49.908 INFO [stdout] hazard_waiting_count=11660
Dec 07 01:37:50.948 INFO [stdout] hazard_waiting_count=34201
Dec 07 01:37:51.952 INFO [stdout] hazard_waiting_count=303146
Dec 07 01:37:52.948 INFO [stdout] hazard_waiting_count=514
Dec 07 01:37:53.948 INFO [stdout] hazard_waiting_count=6414
Dec 07 01:37:54.948 INFO [stdout] hazard_waiting_count=0
Dec 07 01:37:55.948 INFO [stdout] hazard_waiting_count=0
Dec 07 01:37:56.953 INFO [stdout] hazard_waiting_count=0
Dec 07 01:37:57.952 INFO [stdout] hazard_waiting_count=0
Dec 07 01:37:58.954 INFO [stdout] test test_multi_thread ... ok
Dec 07 01:37:58.954 INFO [stderr]      Running /target/debug/deps/test_lockfree_queue-c59197fc109e846b
Dec 07 01:37:58.954 INFO [stdout] 
Dec 07 01:37:58.954 INFO [stdout] test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 07 01:37:58.954 INFO [stdout] 
Dec 07 01:37:58.955 INFO [stdout] 
Dec 07 01:37:58.955 INFO [stdout] running 1 test
Dec 07 01:37:58.960 INFO [stdout] set_cpu_affinity 1 1
Dec 07 01:37:58.961 INFO [stdout] debug_thread produced 1 consumed 0
Dec 07 01:37:58.964 INFO [stdout] set_cpu_affinity 2 2
Dec 07 01:37:58.980 INFO [stdout] set_cpu_affinity 5 5
Dec 07 01:37:58.980 INFO [stdout] set_cpu_affinity 3 3
Dec 07 01:37:58.980 INFO [stdout] set_cpu_affinity 4 4
Dec 07 01:37:58.980 INFO [stdout] set_cpu_affinity 6 6
Dec 07 01:37:58.980 INFO [stdout] set_cpu_affinity 8 0
Dec 07 01:37:58.980 INFO [stdout] set_cpu_affinity 7 7
Dec 07 01:37:59.996 INFO [stdout] debug_thread produced 428548 consumed 428032
Dec 07 01:38:00.996 INFO [stdout] debug_thread produced 995844 consumed 980480
Dec 07 01:38:01.996 INFO [stdout] debug_thread produced 1555460 consumed 1436160
Dec 07 01:38:03.016 INFO [stdout] debug_thread produced 2060804 consumed 1998336
Dec 07 01:38:04.008 INFO [stdout] debug_thread produced 2553860 consumed 2521088
Dec 07 01:38:05.041 INFO [stdout] debug_thread produced 3115524 consumed 2969600
Dec 07 01:38:06.040 INFO [stdout] debug_thread produced 3665924 consumed 3385344
Dec 07 01:38:07.064 INFO [stdout] debug_thread produced 4077572 consumed 3785216
Dec 07 01:38:08.072 INFO [stdout] debug_thread produced 4495876 consumed 4155392
Dec 07 01:38:09.076 INFO [stdout] debug_thread produced 4916228 consumed 4583424
Dec 07 01:38:10.084 INFO [stdout] debug_thread produced 5278724 consumed 4998144
Dec 07 01:38:11.088 INFO [stdout] debug_thread produced 5689860 consumed 5385216
Dec 07 01:38:12.090 INFO [stdout] debug_thread produced 6082564 consumed 5761536
Dec 07 01:38:13.091 INFO [stdout] debug_thread produced 6494212 consumed 6146048
Dec 07 01:38:14.095 INFO [stdout] debug_thread produced 7044100 consumed 6606336
Dec 07 01:38:15.107 INFO [stdout] debug_thread produced 7674884 consumed 7165440
Dec 07 01:38:16.127 INFO [stdout] debug_thread produced 8374276 consumed 7727616
Dec 07 01:38:17.130 INFO [stdout] debug_thread produced 9000452 consumed 8502784
Dec 07 01:38:18.140 INFO [stdout] debug_thread produced 9668100 consumed 9248768
Dec 07 01:38:19.137 INFO [stdout] debug_thread produced 10521261 consumed 10043392
Dec 07 01:38:20.140 INFO [stdout] debug_thread produced 10958847 consumed 10717184
Dec 07 01:38:21.141 INFO [stdout] test test_multi_threads ... ok
Dec 07 01:38:21.141 INFO [stdout] 
Dec 07 01:38:21.141 INFO [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 07 01:38:21.141 INFO [stdout] 
Dec 07 01:38:21.150 INFO [stderr]      Running /target/debug/deps/test_lockfree_stack-24f66f231deb25c5
Dec 07 01:38:21.156 INFO [stdout] 
Dec 07 01:38:21.156 INFO [stdout] running 1 test
Dec 07 01:38:21.156 INFO [stdout] set_cpu_affinity 2 2
Dec 07 01:38:21.156 INFO [stdout] set_cpu_affinity 3 3
Dec 07 01:38:21.156 INFO [stdout] set_cpu_affinity 1 1
Dec 07 01:38:21.160 INFO [stdout] set_cpu_affinity 6 6
Dec 07 01:38:21.160 INFO [stdout] debug_thread produced 3074 consumed 3072
Dec 07 01:38:21.168 INFO [stdout] set_cpu_affinity 4 4
Dec 07 01:38:21.176 INFO [stdout] set_cpu_affinity 8 0
Dec 07 01:38:21.176 INFO [stdout] set_cpu_affinity 5 5
Dec 07 01:38:21.176 INFO [stdout] set_cpu_affinity 7 7
Dec 07 01:38:22.179 INFO [stdout] debug_thread produced 568836 consumed 555008
Dec 07 01:38:23.179 INFO [stdout] debug_thread produced 1279492 consumed 1189376
Dec 07 01:38:24.232 INFO [stdout] debug_thread produced 2002948 consumed 1826816
Dec 07 01:38:25.232 INFO [stdout] debug_thread produced 2667012 consumed 2594304
Dec 07 01:38:26.248 INFO [stdout] debug_thread produced 3342340 consumed 3211264
Dec 07 01:38:27.260 INFO [stdout] debug_thread produced 4076548 consumed 3963392
Dec 07 01:38:28.264 INFO [stdout] debug_thread produced 4801028 consumed 4651008
Dec 07 01:38:29.260 INFO [stdout] debug_thread produced 5551620 consumed 5351936
Dec 07 01:38:30.256 INFO [stdout] debug_thread produced 6302724 consumed 5988864
Dec 07 01:38:31.297 INFO [stdout] debug_thread produced 6973444 consumed 6573568
Dec 07 01:38:32.296 INFO [stdout] debug_thread produced 7527428 consumed 7357440
Dec 07 01:38:33.303 INFO [stdout] debug_thread produced 8078852 consumed 8073728
Dec 07 01:38:34.312 INFO [stdout] debug_thread produced 8903684 consumed 8635392
Dec 07 01:38:35.334 INFO [stdout] debug_thread produced 9466372 consumed 9094144
Dec 07 01:38:36.364 INFO [stdout] debug_thread produced 9867268 consumed 9840640
Dec 07 01:38:37.356 INFO [stdout] debug_thread produced 10535428 consumed 10485760
Dec 07 01:38:38.364 INFO [stdout] debug_thread produced 11135318 consumed 11134976
Dec 07 01:38:39.368 INFO [stdout] test test_multi_threads ... ok
Dec 07 01:38:39.368 INFO [stdout] 
Dec 07 01:38:39.368 INFO [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 07 01:38:39.368 INFO [stdout] 
Dec 07 01:38:39.368 INFO [stderr]    Doc-tests rs_lockfree
Dec 07 01:38:40.266 INFO [stdout] 
Dec 07 01:38:40.266 INFO [stdout] running 8 tests
Dec 07 01:38:43.604 INFO [stdout] test src/lockfree_stack.rs - lockfree_stack::LockFreeStack (line 58) ... ok
Dec 07 01:38:44.140 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::acquire (line 263) ... ok
Dec 07 01:38:44.140 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::retire (line 157) ... ok
Dec 07 01:38:44.960 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::new_in_stack (line 82) ... ok
Dec 07 01:38:45.037 INFO [stdout] test src/hazard_pointer.rs - hazard_pointer::HazardNodeT::get_base_hazard_node (line 95) ... ok
Dec 07 01:38:45.125 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::new_in_heap (line 119) ... ok
Dec 07 01:38:45.164 INFO [stdout] test src/lockfree_queue.rs - lockfree_queue::LockFreeQueue (line 58) ... ok
Dec 07 01:38:45.174 INFO [stdout] test src/hazard_epoch.rs - hazard_epoch::HazardEpoch::add_node (line 193) ... ok
Dec 07 01:38:45.174 INFO [stdout] 
Dec 07 01:38:45.174 INFO [stdout] test result: ok. 8 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 07 01:38:45.174 INFO [stdout] 
Dec 07 01:38:45.192 INFO [stderr] su: No module specific data is present
Dec 07 01:38:45.485 INFO running `"docker" "inspect" "962ee5449b6da36264e8a6d2a6435479f7eb6dcdbf4f9634f58b0b4c5e039c1e"`
Dec 07 01:38:45.662 INFO running `"docker" "rm" "-f" "962ee5449b6da36264e8a6d2a6435479f7eb6dcdbf4f9634f58b0b4c5e039c1e"`
Dec 07 01:38:45.754 INFO [stdout] 962ee5449b6da36264e8a6d2a6435479f7eb6dcdbf4f9634f58b0b4c5e039c1e