[INFO] fetching crate timer-lib 0.4.0...
[INFO] testing timer-lib-0.4.0 against master#ec6f9a5b4413f74386267ef8efc93712c2ce6db6 for pr-155739-1
[INFO] extracting crate timer-lib 0.4.0 into /workspace/builds/worker-5-tc1/source
[INFO] started tweaking crates.io crate timer-lib 0.4.0
[INFO] removed 0 missing examples
[INFO] removed 0 missing tests
[INFO] finished tweaking crates.io crate timer-lib 0.4.0
[INFO] tweaked toml for crates.io crate timer-lib 0.4.0 written to /workspace/builds/worker-5-tc1/source/Cargo.toml
[INFO] validating manifest of crates.io crate timer-lib 0.4.0 on toolchain ec6f9a5b4413f74386267ef8efc93712c2ce6db6
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+ec6f9a5b4413f74386267ef8efc93712c2ce6db6" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] crate crates.io crate timer-lib 0.4.0 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" "+ec6f9a5b4413f74386267ef8efc93712c2ce6db6" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] [stderr]  Downloading crates ...
[INFO] [stderr]   Downloaded syn v2.0.89
[INFO] [stderr]   Downloaded tokio v1.43.1
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-5-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-5-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:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+ec6f9a5b4413f74386267ef8efc93712c2ce6db6" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] ae3ee11cac452986a75a8f74f865e0d8a835a359d3b25e203e32f02feddf03df
[INFO] running `Command { std: "docker" "start" "-a" "ae3ee11cac452986a75a8f74f865e0d8a835a359d3b25e203e32f02feddf03df", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "ae3ee11cac452986a75a8f74f865e0d8a835a359d3b25e203e32f02feddf03df", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "ae3ee11cac452986a75a8f74f865e0d8a835a359d3b25e203e32f02feddf03df", kill_on_drop: false }`
[INFO] [stdout] ae3ee11cac452986a75a8f74f865e0d8a835a359d3b25e203e32f02feddf03df
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-5-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-5-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:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+ec6f9a5b4413f74386267ef8efc93712c2ce6db6" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 394a13827c89f0ad725eb837c08a4e14b29832dacf93c894e8b682109708bd52
[INFO] running `Command { std: "docker" "start" "-a" "394a13827c89f0ad725eb837c08a4e14b29832dacf93c894e8b682109708bd52", kill_on_drop: false }`
[INFO] [stderr]    Compiling proc-macro2 v1.0.92
[INFO] [stderr]    Compiling fastrand v2.3.0
[INFO] [stderr]    Compiling quote v1.0.37
[INFO] [stderr]    Compiling syn v2.0.89
[INFO] [stderr]    Compiling tokio-macros v2.5.0
[INFO] [stderr]    Compiling async-trait v0.1.83
[INFO] [stderr]    Compiling tokio v1.43.1
[INFO] [stderr]    Compiling timer-lib v0.4.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `dev` profile [unoptimized + debuginfo] target(s) in 8.77s
[INFO] running `Command { std: "docker" "inspect" "394a13827c89f0ad725eb837c08a4e14b29832dacf93c894e8b682109708bd52", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "394a13827c89f0ad725eb837c08a4e14b29832dacf93c894e8b682109708bd52", kill_on_drop: false }`
[INFO] [stdout] 394a13827c89f0ad725eb837c08a4e14b29832dacf93c894e8b682109708bd52
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-5-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-5-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:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+ec6f9a5b4413f74386267ef8efc93712c2ce6db6" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] ccd82634979724d7b1bedd939996688246986c59b86e58e32fb0a8572d33dd63
[INFO] running `Command { std: "docker" "start" "-a" "ccd82634979724d7b1bedd939996688246986c59b86e58e32fb0a8572d33dd63", kill_on_drop: false }`
[INFO] [stderr]    Compiling zerocopy v0.8.27
[INFO] [stderr]    Compiling zerocopy-derive v0.8.27
[INFO] [stderr]    Compiling serde_derive v1.0.228
[INFO] [stderr]    Compiling futures-sink v0.3.31
[INFO] [stderr]    Compiling futures-core v0.3.31
[INFO] [stderr]    Compiling libc v0.2.171
[INFO] [stderr]    Compiling anstyle v1.0.13
[INFO] [stderr]    Compiling clap_lex v1.0.0
[INFO] [stderr]    Compiling futures-task v0.3.31
[INFO] [stderr]    Compiling serde_json v1.0.149
[INFO] [stderr]    Compiling tokio v1.43.1
[INFO] [stderr]    Compiling futures-io v0.3.31
[INFO] [stderr]    Compiling rayon v1.11.0
[INFO] [stderr]    Compiling plotters v0.3.7
[INFO] [stderr]    Compiling futures-channel v0.3.31
[INFO] [stderr]    Compiling futures-util v0.3.31
[INFO] [stderr]    Compiling clap_builder v4.5.60
[INFO] [stderr]    Compiling is-terminal v0.4.17
[INFO] [stderr]    Compiling futures v0.3.31
[INFO] [stderr]    Compiling clap v4.5.60
[INFO] [stderr]    Compiling serde v1.0.228
[INFO] [stderr]    Compiling timer-lib v0.4.0 (/opt/rustwide/workdir)
[INFO] [stderr]    Compiling tinytemplate v1.2.1
[INFO] [stderr]    Compiling half v2.7.1
[INFO] [stderr]    Compiling ciborium-ll v0.2.2
[INFO] [stderr]    Compiling ciborium v0.2.2
[INFO] [stderr]    Compiling criterion v0.5.1
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 26.99s
[INFO] running `Command { std: "docker" "inspect" "ccd82634979724d7b1bedd939996688246986c59b86e58e32fb0a8572d33dd63", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "ccd82634979724d7b1bedd939996688246986c59b86e58e32fb0a8572d33dd63", kill_on_drop: false }`
[INFO] [stdout] ccd82634979724d7b1bedd939996688246986c59b86e58e32fb0a8572d33dd63
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-5-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-5-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:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+ec6f9a5b4413f74386267ef8efc93712c2ce6db6" "test" "--frozen", kill_on_drop: false }`
[INFO] [stdout] eb66dc5b457fc62eb5937d1ef46b2e124934c1a7230c102a38ae972ee68553e1
[INFO] running `Command { std: "docker" "start" "-a" "eb66dc5b457fc62eb5937d1ef46b2e124934c1a7230c102a38ae972ee68553e1", kill_on_drop: false }`
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 0.15s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/timer_lib-fd58be1677bcaa3f)
[INFO] [stdout] 
[INFO] [stdout] running 23 tests
[INFO] [stdout] test errors::tests::error_messages_are_stable_and_descriptive ... ok
[INFO] [stdout] test registry::tests::registry_supports_direct_timer_controls ... ok
[INFO] [stdout] test timer::tests::builder_starts_recurring_timers_with_less_boilerplate ... ok
[INFO] [stdout] test timer::tests::builder_initial_delay_controls_the_first_recurring_tick ... ok
[INFO] [stdout] test timer::tests::completion_subscription_is_lossless ... ok
[INFO] [stdout] test timer::tests::callback_timeout_counts_as_a_failed_execution ... ok
[INFO] [stdout] test registry::tests::registry_can_pause_and_resume_tracked_timers ... ok
[INFO] [stdout] test timer::tests::event_helpers_wait_for_cancelled_outcomes ... ok
[INFO] [stdout] test timer::tests::event_helpers_wait_for_pause_resume_and_stop ... ok
[INFO] [stdout] test timer::tests::event_suppression_can_be_enabled_from_the_builder ... ok
[INFO] [stdout] test timer::tests::events_are_emitted_for_key_lifecycle_changes ... ok
[INFO] [stdout] test timer::tests::fixed_rate_and_fixed_delay_schedules_diverge_under_slow_callbacks ... ok
[INFO] [stdout] test timer::tests::interval_adjustments_apply_to_future_ticks ... ok
[INFO] [stdout] test registry::tests::registry_start_helpers_are_easy_to_use ... ok
[INFO] [stdout] test timer::tests::paused_builder_start_waits_for_resume ... ok
[INFO] [stdout] test timer::tests::recurring_timers_can_delay_the_first_tick ... ok
[INFO] [stdout] test timer::tests::timer_starts_stopped ... ok
[INFO] [stdout] test timer::tests::stop_is_graceful_and_cancel_is_immediate ... ok
[INFO] [stdout] test timer::tests::retry_policy_retries_failed_callbacks_before_succeeding ... ok
[INFO] [stdout] test timer::tests::replacing_a_run_records_replaced_outcome ... ok
[INFO] [stdout] test timer::tests::completion_wait_advances_to_the_next_unseen_outcome ... ok
[INFO] [stdout] test timer::tests::one_shot_timer_returns_completed_outcome ... ok
[INFO] [stderr]      Running tests/public_api.rs (/opt/rustwide/target/debug/deps/public_api-1c1faca2cae7fb3d)
[INFO] [stdout] test errors::tests::error_helpers_expose_stable_queries ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 23 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.03s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 15 tests
[INFO] [stderr]      Running tests/stress.rs (/opt/rustwide/target/debug/deps/stress-6f293c2940455071)
[INFO] [stdout] test builder_api_is_simple_to_use ... ok
[INFO] [stdout] test labels_and_registry_snapshots_are_available_from_the_public_api ... ok
[INFO] [stdout] test lifecycle_wait_helpers_are_consumable_from_the_public_api ... ok
[INFO] [stdout] test callback_timeout_is_available_from_the_public_api ... ok
[INFO] [stdout] test recurring_schedule_is_the_public_configuration_entry_point ... ok
[INFO] [stdout] test registry_pause_and_resume_helpers_are_available_from_the_public_api ... ok
[INFO] [stdout] test registry_spawn_helpers_reduce_boilerplate ... ok
[INFO] [stdout] test registry_ergonomics_cover_common_bulk_operations ... ok
[INFO] [stdout] test completion_api_is_simple_to_consume ... ok
[INFO] [stdout] test timer_events_are_consumable_from_the_public_api ... ok
[INFO] [stdout] test jitter_and_retry_backoff_are_available_from_the_public_api ... ok
[INFO] [stdout] test timer_closure_api_is_simple_to_use ... ok
[INFO] [stdout] test start_at_is_available_from_the_public_api ... ok
[INFO] [stdout] test retry_policy_is_available_from_the_public_api ... ok
[INFO] [stdout] test recurring_initial_delay_is_available_from_the_public_api ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 15 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.01s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 3 tests
[INFO] [stdout] test concurrent_joiners_see_the_same_completed_outcome ... ok
[INFO] [stdout] test many_timers_complete_under_registry_load ... ok
[INFO] [stderr]      Running tests/weird.rs (/opt/rustwide/target/debug/deps/weird-5a8f95e1e6116fa0)
[INFO] [stdout] test registry_cancel_all_stops_many_recurring_timers_concurrently ... ok
[INFO] [stderr]    Doc-tests timer_lib
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 3 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.16s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 6 tests
[INFO] [stdout] test join_is_idempotent_after_cancel ... ok
[INFO] [stdout] test removed_timer_keeps_running_after_leaving_registry ... ok
[INFO] [stdout] test callback_can_request_stop_on_itself_without_deadlocking ... ok
[INFO] [stdout] test callback_cannot_restart_its_own_timer_inline ... ok
[INFO] [stdout] test lagged_event_subscriber_can_still_observe_finished ... ok
[INFO] [stdout] test concurrent_stop_cancel_and_join_do_not_deadlock ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 6 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.01s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 4 tests
[INFO] [stdout] test src/lib.rs - (line 19) ... ok
[INFO] [stdout] test src/lib.rs - (line 63) ... ok
[INFO] [stdout] test src/lib.rs - (line 86) ... ok
[INFO] [stdout] test src/lib.rs - (line 41) ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 4 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 2.05s
[INFO] [stdout] 
[INFO] running `Command { std: "docker" "inspect" "eb66dc5b457fc62eb5937d1ef46b2e124934c1a7230c102a38ae972ee68553e1", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "eb66dc5b457fc62eb5937d1ef46b2e124934c1a7230c102a38ae972ee68553e1", kill_on_drop: false }`
[INFO] [stdout] eb66dc5b457fc62eb5937d1ef46b2e124934c1a7230c102a38ae972ee68553e1
