[INFO] cloning repository https://github.com/hds/future-timer [INFO] running `Command { std: "git" "-c" "credential.helper=" "-c" "credential.helper=/workspace/cargo-home/bin/git-credential-null" "clone" "--bare" "https://github.com/hds/future-timer" "/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fhds%2Ffuture-timer", kill_on_drop: false }` [INFO] [stderr] Cloning into bare repository '/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fhds%2Ffuture-timer'... [INFO] running `Command { std: "git" "rev-parse" "HEAD", kill_on_drop: false }` [INFO] [stdout] 772d66e7da76ea8f5aa0024c7b4f51a3f621461b [INFO] testing hds/future-timer against master#e9385f9eea0221ef295a188d49d16f8f5189abf1 for pr-146098 [INFO] running `Command { std: "git" "clone" "/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fhds%2Ffuture-timer" "/workspace/builds/worker-2-tc1/source", kill_on_drop: false }` [INFO] [stderr] Cloning into '/workspace/builds/worker-2-tc1/source'... [INFO] [stderr] done. [INFO] started tweaking git repo https://github.com/hds/future-timer [INFO] finished tweaking git repo https://github.com/hds/future-timer [INFO] tweaked toml for git repo https://github.com/hds/future-timer written to /workspace/builds/worker-2-tc1/source/Cargo.toml [INFO] validating manifest of git repo https://github.com/hds/future-timer on toolchain e9385f9eea0221ef295a188d49d16f8f5189abf1 [INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+e9385f9eea0221ef295a188d49d16f8f5189abf1" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }` [INFO] crate git repo https://github.com/hds/future-timer already has a lockfile, it will not be regenerated [INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+e9385f9eea0221ef295a188d49d16f8f5189abf1" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }` [INFO] [stderr] Downloading crates ... [INFO] [stderr] Downloaded tokio v1.44.0 [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-2-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-2-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:e90291280db7d1fac5b66fc6dad9f9662629e7365a55743daf9bdf73ebc4ea79" "/opt/rustwide/cargo-home/bin/cargo" "+e9385f9eea0221ef295a188d49d16f8f5189abf1" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }` [INFO] [stdout] c9ddab9ae0563fdd58bb5adc9a8214e950dbb1b047a1e12591a8cf664ab592d6 [INFO] running `Command { std: "docker" "start" "-a" "c9ddab9ae0563fdd58bb5adc9a8214e950dbb1b047a1e12591a8cf664ab592d6", kill_on_drop: false }` [INFO] running `Command { std: "docker" "inspect" "c9ddab9ae0563fdd58bb5adc9a8214e950dbb1b047a1e12591a8cf664ab592d6", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "c9ddab9ae0563fdd58bb5adc9a8214e950dbb1b047a1e12591a8cf664ab592d6", kill_on_drop: false }` [INFO] [stdout] c9ddab9ae0563fdd58bb5adc9a8214e950dbb1b047a1e12591a8cf664ab592d6 [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-2-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-2-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:e90291280db7d1fac5b66fc6dad9f9662629e7365a55743daf9bdf73ebc4ea79" "/opt/rustwide/cargo-home/bin/cargo" "+e9385f9eea0221ef295a188d49d16f8f5189abf1" "build" "--frozen" "--message-format=json", kill_on_drop: false }` [INFO] [stdout] 0afc3ba99204efbf9119134fffef69f1999010809629100531d8e05c8b5444df [INFO] running `Command { std: "docker" "start" "-a" "0afc3ba99204efbf9119134fffef69f1999010809629100531d8e05c8b5444df", kill_on_drop: false }` [INFO] [stderr] Compiling future-timing v0.1.0 (/opt/rustwide/workdir) [INFO] [stderr] Finished `dev` profile [unoptimized + debuginfo] target(s) in 0.34s [INFO] running `Command { std: "docker" "inspect" "0afc3ba99204efbf9119134fffef69f1999010809629100531d8e05c8b5444df", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "0afc3ba99204efbf9119134fffef69f1999010809629100531d8e05c8b5444df", kill_on_drop: false }` [INFO] [stdout] 0afc3ba99204efbf9119134fffef69f1999010809629100531d8e05c8b5444df [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-2-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-2-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:e90291280db7d1fac5b66fc6dad9f9662629e7365a55743daf9bdf73ebc4ea79" "/opt/rustwide/cargo-home/bin/cargo" "+e9385f9eea0221ef295a188d49d16f8f5189abf1" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }` [INFO] [stdout] b51e961f595756e0b52e5d0e6ec2ab4882eb0e63447089e96ad1135472a19070 [INFO] running `Command { std: "docker" "start" "-a" "b51e961f595756e0b52e5d0e6ec2ab4882eb0e63447089e96ad1135472a19070", kill_on_drop: false }` [INFO] [stderr] Compiling smallvec v1.14.0 [INFO] [stderr] Compiling socket2 v0.5.8 [INFO] [stderr] Compiling signal-hook-registry v1.4.2 [INFO] [stderr] Compiling syn v2.0.100 [INFO] [stderr] Compiling parking_lot_core v0.9.10 [INFO] [stderr] Compiling parking_lot v0.12.3 [INFO] [stderr] Compiling tokio-macros v2.5.0 [INFO] [stderr] Compiling tokio v1.44.0 [INFO] [stderr] Compiling future-timing v0.1.0 (/opt/rustwide/workdir) [INFO] [stderr] Finished `test` profile [unoptimized + debuginfo] target(s) in 16.79s [INFO] running `Command { std: "docker" "inspect" "b51e961f595756e0b52e5d0e6ec2ab4882eb0e63447089e96ad1135472a19070", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "b51e961f595756e0b52e5d0e6ec2ab4882eb0e63447089e96ad1135472a19070", kill_on_drop: false }` [INFO] [stdout] b51e961f595756e0b52e5d0e6ec2ab4882eb0e63447089e96ad1135472a19070 [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-2-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-2-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:e90291280db7d1fac5b66fc6dad9f9662629e7365a55743daf9bdf73ebc4ea79" "/opt/rustwide/cargo-home/bin/cargo" "+e9385f9eea0221ef295a188d49d16f8f5189abf1" "test" "--frozen", kill_on_drop: false }` [INFO] [stdout] 02398935d476df142df3ed13d209570de483d5a874eb2d619682a7f86e5690a6 [INFO] running `Command { std: "docker" "start" "-a" "02398935d476df142df3ed13d209570de483d5a874eb2d619682a7f86e5690a6", kill_on_drop: false }` [INFO] [stderr] Finished `test` profile [unoptimized + debuginfo] target(s) in 0.06s [INFO] [stderr] Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/future_timing-34062ab4e711e1e4) [INFO] [stdout] [INFO] [stdout] running 0 tests [INFO] [stdout] [INFO] [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s [INFO] [stdout] [INFO] [stderr] Running tests/tokio.rs (/opt/rustwide/target/debug/deps/tokio-9a86b2f678c442b8) [INFO] [stdout] [INFO] [stdout] running 3 tests [INFO] [stdout] test never_yield ... ok [INFO] [stdout] test short_async_sleep ... ok [INFO] [stdout] test more_busy_time ... ok [INFO] [stdout] [INFO] [stdout] test result: ok. 3 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.01s [INFO] [stdout] [INFO] [stderr] Doc-tests future_timing [INFO] [stdout] [INFO] [stdout] running 6 tests [INFO] [stdout] test src/lib.rs - (line 26) ... ok [INFO] [stdout] test src/lib.rs - timed (line 94) ... ok [INFO] [stdout] test src/lib.rs - Timed (line 126) ... FAILED [INFO] [stdout] test src/lib.rs - TimingOutput::into_parts (line 236) ... ok [INFO] [stdout] test src/lib.rs - TimingOutput::into_inner (line 255) ... ok [INFO] [stdout] test src/lib.rs - TimingOutput::timing (line 218) ... ok [INFO] [stdout] [INFO] [stdout] failures: [INFO] [stdout] [INFO] [stdout] ---- src/lib.rs - Timed (line 126) stdout ---- [INFO] [stdout] Test executable failed (exit status: 101). [INFO] [stdout] [INFO] [stdout] stderr: [INFO] [stdout] [INFO] [stdout] thread 'main' (156) panicked at src/lib.rs:17:5: [INFO] [stdout] assertion failed: !timing.idle().is_zero() [INFO] [stdout] stack backtrace: [INFO] [stdout] 0: 0x5be371804f82 - std::backtrace_rs::backtrace::libunwind::trace::h66a2a7c2ae287f78 [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/std/src/../../backtrace/src/backtrace/libunwind.rs:117:9 [INFO] [stdout] 1: 0x5be371804f82 - std::backtrace_rs::backtrace::trace_unsynchronized::hfc2e0cbc9b584495 [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/std/src/../../backtrace/src/backtrace/mod.rs:66:14 [INFO] [stdout] 2: 0x5be371804f82 - std::sys::backtrace::_print_fmt::h118f0de0547bd6e5 [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/std/src/sys/backtrace.rs:66:9 [INFO] [stdout] 3: 0x5be371804f82 - ::fmt::h4a7ebf3c97b63e54 [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/std/src/sys/backtrace.rs:39:26 [INFO] [stdout] 4: 0x5be3718148cf - core::fmt::rt::Argument::fmt::h614abe7b62e687bb [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/core/src/fmt/rt.rs:173:76 [INFO] [stdout] 5: 0x5be3718148cf - core::fmt::write::h5e5759cada453e98 [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/core/src/fmt/mod.rs:1468:25 [INFO] [stdout] 6: 0x5be3717dcab1 - std::io::default_write_fmt::h6f5532915a01b00a [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/std/src/io/mod.rs:639:11 [INFO] [stdout] 7: 0x5be3717dcab1 - std::io::Write::write_fmt::h503716d2664a2999 [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/std/src/io/mod.rs:1954:13 [INFO] [stdout] 8: 0x5be3717e4242 - std::sys::backtrace::BacktraceLock::print::haede8464af6f6593 [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/std/src/sys/backtrace.rs:42:9 [INFO] [stdout] 9: 0x5be3717e860f - std::panicking::default_hook::{{closure}}::hd1d459f3747276de [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/std/src/panicking.rs:301:27 [INFO] [stdout] 10: 0x5be3717e8469 - std::panicking::default_hook::h4615f5c23d4bd826 [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/std/src/panicking.rs:328:9 [INFO] [stdout] 11: 0x5be3717e8d45 - std::panicking::panic_with_hook::h290022751dfbc99c [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/std/src/panicking.rs:834:13 [INFO] [stdout] 12: 0x5be3717e8af6 - std::panicking::panic_handler::{{closure}}::h8a82486ef1115454 [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/std/src/panicking.rs:700:13 [INFO] [stdout] 13: 0x5be3717e4379 - std::sys::backtrace::__rust_end_short_backtrace::h24c7668dbf64a695 [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/std/src/sys/backtrace.rs:174:18 [INFO] [stdout] 14: 0x5be3717d144d - __rustc[c97015d5850a580e]::rust_begin_unwind [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/std/src/panicking.rs:698:5 [INFO] [stdout] 15: 0x5be371818380 - core::panicking::panic_fmt::h28e12f8802cd0928 [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/core/src/panicking.rs:78:14 [INFO] [stdout] 16: 0x5be37181835c - core::panicking::panic::hed5eaea7fae41482 [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/core/src/panicking.rs:148:5 [INFO] [stdout] 17: 0x5be371737295 - rust_out::main::{{closure}}::he5195e0d2f37beb5 [INFO] [stdout] 18: 0x5be3717312a6 - tokio::runtime::park::CachedParkThread::block_on::{{closure}}::hb8420831bd508c9c [INFO] [stdout] 19: 0x5be3717309c0 - tokio::runtime::park::CachedParkThread::block_on::h6557c2bc5951b279 [INFO] [stdout] 20: 0x5be3717324dd - tokio::runtime::context::blocking::BlockingRegionGuard::block_on::h0b20db2b62902220 [INFO] [stdout] 21: 0x5be371732c40 - tokio::runtime::scheduler::multi_thread::MultiThread::block_on::{{closure}}::hbc5616996360b1c4 [INFO] [stdout] 22: 0x5be371731d7d - tokio::runtime::context::runtime::enter_runtime::hd1819f09c4d7bb77 [INFO] [stdout] 23: 0x5be371732bc1 - tokio::runtime::scheduler::multi_thread::MultiThread::block_on::he2928c9ae12b11f7 [INFO] [stdout] 24: 0x5be371732839 - tokio::runtime::runtime::Runtime::block_on_inner::h51c72bc44d8bb71c [INFO] [stdout] 25: 0x5be371732a8d - tokio::runtime::runtime::Runtime::block_on::hca062c11ef3842d1 [INFO] [stdout] 26: 0x5be371736f6d - rust_out::main::hb22b1395de73f456 [INFO] [stdout] 27: 0x5be37172f613 - core::ops::function::FnOnce::call_once::h5ed97ba2579b91d6 [INFO] [stdout] 28: 0x5be37172e6d6 - std::sys::backtrace::__rust_begin_short_backtrace::h846c7e453f901015 [INFO] [stdout] 29: 0x5be37172e6b9 - std::rt::lang_start::{{closure}}::hfc3e6038d6e2d99f [INFO] [stdout] 30: 0x5be3717de2a0 - core::ops::function::impls:: for &F>::call_once::h968e9241fe7c2037 [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/core/src/ops/function.rs:287:21 [INFO] [stdout] 31: 0x5be3717de2a0 - std::panicking::catch_unwind::do_call::h45ef651a412481b5 [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/std/src/panicking.rs:590:40 [INFO] [stdout] 32: 0x5be3717de2a0 - std::panicking::catch_unwind::hcaa3034585148361 [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/std/src/panicking.rs:553:19 [INFO] [stdout] 33: 0x5be3717de2a0 - std::panic::catch_unwind::ha29e7dd569426822 [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/std/src/panic.rs:359:14 [INFO] [stdout] 34: 0x5be3717de2a0 - std::rt::lang_start_internal::{{closure}}::h1174a1e1c9fac06b [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/std/src/rt.rs:175:24 [INFO] [stdout] 35: 0x5be3717de2a0 - std::panicking::catch_unwind::do_call::h2405b56a0869833e [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/std/src/panicking.rs:590:40 [INFO] [stdout] 36: 0x5be3717de2a0 - std::panicking::catch_unwind::hb69d6a3eb24e9b7e [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/std/src/panicking.rs:553:19 [INFO] [stdout] 37: 0x5be3717de2a0 - std::panic::catch_unwind::ha4cc96915d08b99e [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/std/src/panic.rs:359:14 [INFO] [stdout] 38: 0x5be3717de2a0 - std::rt::lang_start_internal::h743e0642e9937917 [INFO] [stdout] at /rustc/e9385f9eea0221ef295a188d49d16f8f5189abf1/library/std/src/rt.rs:171:5 [INFO] [stdout] 39: 0x5be37172e6a1 - std::rt::lang_start::h03d20ae2166acee7 [INFO] [stdout] 40: 0x5be371737335 - main [INFO] [stdout] 41: 0x77762a45a1ca - [INFO] [stdout] 42: 0x77762a45a28b - __libc_start_main [INFO] [stdout] 43: 0x5be37172e475 - _start [INFO] [stdout] 44: 0x0 - [INFO] [stdout] [INFO] [stdout] [INFO] [stdout] [INFO] [stdout] failures: [INFO] [stdout] src/lib.rs - Timed (line 126) [INFO] [stdout] [INFO] [stdout] test result: FAILED. 5 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 1.55s [INFO] [stdout] [INFO] [stderr] error: doctest failed, to rerun pass `--doc` [INFO] running `Command { std: "docker" "inspect" "02398935d476df142df3ed13d209570de483d5a874eb2d619682a7f86e5690a6", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "02398935d476df142df3ed13d209570de483d5a874eb2d619682a7f86e5690a6", kill_on_drop: false }` [INFO] [stdout] 02398935d476df142df3ed13d209570de483d5a874eb2d619682a7f86e5690a6