Nov 17 20:15:10.346 INFO testing tokio-timer-0.2.7 against master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c for pr-55982
Nov 17 20:15:10.346 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 17 20:15:10.569 INFO [stdout] f15c78cb0b405b8563e760a00304f191ed6ee7a44c19c101963db63038047f94
Nov 17 20:15:10.575 INFO running `"docker" "start" "-a" "f15c78cb0b405b8563e760a00304f191ed6ee7a44c19c101963db63038047f94"`
Nov 17 20:15:11.086 INFO [stderr] usermod: no changes
Nov 17 20:15:11.157 INFO [stderr]    Compiling tokio-timer v0.2.7 (/source)
Nov 17 20:15:12.367 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 1.26s
Nov 17 20:15:12.373 INFO [stderr] su: No module specific data is present
Nov 17 20:15:13.061 INFO running `"docker" "inspect" "f15c78cb0b405b8563e760a00304f191ed6ee7a44c19c101963db63038047f94"`
Nov 17 20:15:13.301 INFO running `"docker" "rm" "-f" "f15c78cb0b405b8563e760a00304f191ed6ee7a44c19c101963db63038047f94"`
Nov 17 20:15:13.535 INFO [stdout] f15c78cb0b405b8563e760a00304f191ed6ee7a44c19c101963db63038047f94
Nov 17 20:15:13.541 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 17 20:15:14.040 INFO [stdout] 6baf162fb4bfff9bef8a22fdb383620775d4b6b4e940c108394d5c662e67d774
Nov 17 20:15:14.043 INFO running `"docker" "start" "-a" "6baf162fb4bfff9bef8a22fdb383620775d4b6b4e940c108394d5c662e67d774"`
Nov 17 20:15:15.124 INFO [stderr] usermod: no changes
Nov 17 20:15:15.271 INFO [stderr]    Compiling tokio-mock-task v0.1.0
Nov 17 20:15:15.701 INFO [stderr]    Compiling tokio-timer v0.2.7 (/source)
Nov 17 20:15:21.189 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 6.03s
Nov 17 20:15:21.200 INFO [stderr] su: No module specific data is present
Nov 17 20:15:22.256 INFO running `"docker" "inspect" "6baf162fb4bfff9bef8a22fdb383620775d4b6b4e940c108394d5c662e67d774"`
Nov 17 20:15:22.527 INFO running `"docker" "rm" "-f" "6baf162fb4bfff9bef8a22fdb383620775d4b6b4e940c108394d5c662e67d774"`
Nov 17 20:15:22.927 INFO [stdout] 6baf162fb4bfff9bef8a22fdb383620775d4b6b4e940c108394d5c662e67d774
Nov 17 20:15:22.933 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 17 20:15:23.327 INFO [stdout] 01f611f05e69e2fa4d4337abac0cd3cd73c6e5f84321df644e6d93b39f1f8ac5
Nov 17 20:15:23.331 INFO running `"docker" "start" "-a" "01f611f05e69e2fa4d4337abac0cd3cd73c6e5f84321df644e6d93b39f1f8ac5"`
Nov 17 20:15:24.407 INFO [stderr] usermod: no changes
Nov 17 20:15:24.498 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.07s
Nov 17 20:15:24.502 INFO [stderr]      Running /target/debug/deps/tokio_timer-946ba26f1815dd66
Nov 17 20:15:24.509 INFO [stdout] 
Nov 17 20:15:24.509 INFO [stdout] running 1 test
Nov 17 20:15:24.511 INFO [stdout] test wheel::test::test_level_for ... ok
Nov 17 20:15:24.511 INFO [stdout] 
Nov 17 20:15:24.511 INFO [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 17 20:15:24.511 INFO [stdout] 
Nov 17 20:15:24.511 INFO [stderr]      Running /target/debug/deps/clock-3d2e8328c5da50f3
Nov 17 20:15:24.516 INFO [stdout] 
Nov 17 20:15:24.516 INFO [stdout] running 3 tests
Nov 17 20:15:24.516 INFO [stdout] test default_clock ... ok
Nov 17 20:15:24.516 INFO [stdout] test execution_context ... ok
Nov 17 20:15:24.519 INFO [stdout] test custom_clock ... ok
Nov 17 20:15:24.519 INFO [stdout] 
Nov 17 20:15:24.519 INFO [stdout] test result: ok. 3 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 17 20:15:24.519 INFO [stdout] 
Nov 17 20:15:24.520 INFO [stderr]      Running /target/debug/deps/deadline-903b76d2492cecf8
Nov 17 20:15:24.523 INFO [stdout] 
Nov 17 20:15:24.523 INFO [stdout] running 6 tests
Nov 17 20:15:24.524 INFO [stdout] test deadline_now_elapses ... ok
Nov 17 20:15:24.524 INFO [stdout] test deadline_future_elapses ... ok
Nov 17 20:15:24.524 INFO [stdout] test completed_future_past_deadline ... ok
Nov 17 20:15:24.524 INFO [stdout] test future_and_deadline_in_future ... ok
Nov 17 20:15:24.524 INFO [stdout] test simultaneous_deadline_future_completion ... ok
Nov 17 20:15:24.525 INFO [stdout] test future_errors_first ... ok
Nov 17 20:15:24.525 INFO [stdout] 
Nov 17 20:15:24.525 INFO [stdout] test result: ok. 6 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 17 20:15:24.525 INFO [stdout] 
Nov 17 20:15:24.526 INFO [stderr]      Running /target/debug/deps/delay-27cc2869b437f8e5
Nov 17 20:15:24.527 INFO [stdout] 
Nov 17 20:15:24.527 INFO [stdout] running 20 tests
Nov 17 20:15:24.528 INFO [stdout] test greater_than_max ... ok
Nov 17 20:15:24.528 INFO [stdout] test delayed_delay_wrapping_level_0 ... ok
Nov 17 20:15:24.528 INFO [stdout] test delayed_delay_level_0 ... ok
Nov 17 20:15:24.528 INFO [stdout] test delay_with_deadline_in_past ... ok
Nov 17 20:15:24.528 INFO [stdout] test reset_future_delay_before_fire ... ok
Nov 17 20:15:24.528 INFO [stdout] test immediate_delay ... ok
Nov 17 20:15:24.529 INFO [stdout] test concurrently_set_two_timers_second_one_shorter ... ok
Nov 17 20:15:24.529 INFO [stdout] test delay_with_default_handle ... ok
Nov 17 20:15:24.529 INFO [stdout] test reset_past_delay_before_fire ... ok
Nov 17 20:15:24.529 INFO [stdout] test creating_delay_outside_of_context ... ok
Nov 17 20:15:24.529 INFO [stdout] test delayed_delay_level_1 ... ok
Nov 17 20:15:24.529 INFO [stdout] test reset_past_delay_before_turn ... ok
Nov 17 20:15:24.529 INFO [stdout] test very_long_delay ... ok
Nov 17 20:15:24.529 INFO [stdout] test set_timeout_at_deadline_greater_than_max_timer ... ok
Nov 17 20:15:24.530 INFO [stdout] test sorta_long_delay ... ok
Nov 17 20:15:24.530 INFO [stdout] test short_delay ... ok
Nov 17 20:15:24.530 INFO [stdout] test sub_ms_delayed_delay ... ok
Nov 17 20:15:24.530 INFO [stdout] test unpark_is_delayed ... ok
Nov 17 20:15:24.530 INFO [stdout] test timer_wrapping_with_higher_levels ... ok
Nov 17 20:15:24.534 INFO [stdout] test reset_future_delay_after_fire ... ok
Nov 17 20:15:24.534 INFO [stderr]      Running /target/debug/deps/hammer-951230007a52ebff
Nov 17 20:15:24.534 INFO [stdout] 
Nov 17 20:15:24.534 INFO [stdout] test result: ok. 20 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 17 20:15:24.534 INFO [stdout] 
Nov 17 20:15:24.537 INFO [stdout] 
Nov 17 20:15:24.537 INFO [stdout] running 3 tests
Nov 17 20:15:27.972 INFO [stdout] test hammer_reset ... ok
Nov 17 20:15:48.187 INFO [stdout] test hammer_cancel ... ok
Nov 17 20:15:49.555 INFO [stdout] test hammer_complete ... ok
Nov 17 20:15:49.555 INFO [stderr]      Running /target/debug/deps/interval-a2173ac9ec580285
Nov 17 20:15:49.556 INFO [stdout] 
Nov 17 20:15:49.556 INFO [stdout] test result: ok. 3 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 17 20:15:49.556 INFO [stdout] 
Nov 17 20:15:49.557 INFO [stdout] 
Nov 17 20:15:49.557 INFO [stdout] running 2 tests
Nov 17 20:15:49.558 INFO [stdout] test usage ... ok
Nov 17 20:15:49.613 INFO [stdout] test interval_zero_duration ... ok
Nov 17 20:15:49.614 INFO [stderr]      Running /target/debug/deps/queue-0585188d34a1b55a
Nov 17 20:15:49.614 INFO [stdout] 
Nov 17 20:15:49.614 INFO [stdout] test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 17 20:15:49.615 INFO [stdout] 
Nov 17 20:15:49.615 INFO [stdout] 
Nov 17 20:15:49.615 INFO [stdout] running 8 tests
Nov 17 20:15:49.616 INFO [stdout] test single_short_delay ... ok
Nov 17 20:15:49.616 INFO [stdout] test single_immediate_delay ... ok
Nov 17 20:15:49.616 INFO [stdout] test reset_entry ... ok
Nov 17 20:15:49.618 INFO [stdout] test remove_expired_item ... ok
Nov 17 20:15:49.618 INFO [stdout] test multi_delay_at_start ... ok
Nov 17 20:15:49.618 INFO [stdout] test insert_in_past_fires_immediately ... ok
Nov 17 20:15:49.623 INFO [stdout] test multi_immediate_delays ... ok
Nov 17 20:15:49.623 INFO [stdout] test remove_entry ... ok
Nov 17 20:15:49.623 INFO [stdout] 
Nov 17 20:15:49.623 INFO [stdout] test result: ok. 8 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 17 20:15:49.623 INFO [stdout] 
Nov 17 20:15:49.631 INFO [stdout] 
Nov 17 20:15:49.631 INFO [stderr]      Running /target/debug/deps/timeout-03115b1c703d2e11
Nov 17 20:15:49.631 INFO [stdout] running 9 tests
Nov 17 20:15:49.631 INFO [stdout] test idle_stream_timesout_periodically ... ok
Nov 17 20:15:49.631 INFO [stdout] test deadline_future_elapses ... ok
Nov 17 20:15:49.631 INFO [stdout] test simultaneous_deadline_future_completion ... ok
Nov 17 20:15:49.631 INFO [stdout] test future_errors_first ... ok
Nov 17 20:15:49.631 INFO [stdout] test future_and_deadline_in_future ... ok
Nov 17 20:15:49.631 INFO [stdout] test future_and_timeout_in_future ... ok
Nov 17 20:15:49.631 INFO [stdout] test completed_future_past_deadline ... ok
Nov 17 20:15:49.633 INFO [stdout] test stream_and_timeout_in_future ... ok
Nov 17 20:15:49.639 INFO [stdout] test deadline_now_elapses ... ok
Nov 17 20:15:49.640 INFO [stdout] 
Nov 17 20:15:49.640 INFO [stdout] test result: ok. 9 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 17 20:15:49.640 INFO [stdout] 
Nov 17 20:15:49.645 INFO [stderr]    Doc-tests tokio-timer
Nov 17 20:15:50.427 INFO [stdout] 
Nov 17 20:15:50.427 INFO [stdout] running 16 tests
Nov 17 20:15:53.999 INFO [stdout] test src/delay_queue.rs - delay_queue::DelayQueue<T>::new (line 215) ... ok
Nov 17 20:15:54.215 INFO [stdout] test src/clock/clock.rs - clock::clock::now (line 36) ... ok
Nov 17 20:15:54.331 INFO [stdout] test src/delay_queue.rs - delay_queue::DelayQueue<T>::capacity (line 589) ... ok
Nov 17 20:15:55.043 INFO [stdout] test src/delay_queue.rs - delay_queue::DelayQueue<T>::is_empty (line 636) ... ok
Nov 17 20:15:58.487 INFO [stdout] test src/delay_queue.rs - delay_queue::DelayQueue<T>::reserve (line 617) ... ok
Nov 17 20:16:05.803 INFO [stdout] test src/delay_queue.rs - delay_queue::DelayQueue<T>::with_capacity (line 256) ... ok
Nov 17 20:16:09.367 INFO [stdout] test src/delay_queue.rs - delay_queue::DelayQueue (line 70) ... ok
Nov 17 20:16:09.478 INFO [stdout] test src/delay_queue.rs - delay_queue::DelayQueue<T>::with_capacity_and_handle (line 229) ... ok
Nov 17 20:16:12.995 INFO [stdout] test src/delay_queue.rs - delay_queue::DelayQueue<T>::insert_at (line 300) ... ok
Nov 17 20:16:13.329 INFO [stdout] test src/delay_queue.rs - delay_queue::DelayQueue<T>::reset_at (line 475) ... ok
Nov 17 20:16:13.624 INFO [stdout] test src/delay_queue.rs - delay_queue::DelayQueue<T>::insert (line 369) ... ok
Nov 17 20:16:14.315 INFO [stdout] test src/delay_queue.rs - delay_queue::DelayQueue<T>::clear (line 561) ... ok
Nov 17 20:16:15.993 INFO [stdout] test src/delay_queue.rs - delay_queue::DelayQueue<T>::reset (line 531) ... ok
Nov 17 20:16:16.451 INFO [stdout] test src/delay_queue.rs - delay_queue::DelayQueue<T>::remove (line 424) ... ok
Nov 17 20:16:20.915 INFO [stdout] test src/timeout.rs - timeout::Timeout (line 33) ... ok
Nov 17 20:16:21.029 INFO [stdout] test src/timeout.rs - timeout::Timeout<T>::new (line 108) ... ok
Nov 17 20:16:21.029 INFO [stdout] 
Nov 17 20:16:21.029 INFO [stdout] test result: ok. 16 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 17 20:16:21.029 INFO [stdout] 
Nov 17 20:16:21.081 INFO [stderr] su: No module specific data is present
Nov 17 20:16:22.120 INFO running `"docker" "inspect" "01f611f05e69e2fa4d4337abac0cd3cd73c6e5f84321df644e6d93b39f1f8ac5"`
Nov 17 20:16:22.373 INFO running `"docker" "rm" "-f" "01f611f05e69e2fa4d4337abac0cd3cd73c6e5f84321df644e6d93b39f1f8ac5"`
Nov 17 20:16:22.613 INFO [stdout] 01f611f05e69e2fa4d4337abac0cd3cd73c6e5f84321df644e6d93b39f1f8ac5