[INFO] fetching crate clone-stream 0.2.1... [INFO] testing clone-stream-0.2.1 against try#8de4c7234dd9b97c9d76b58671343fdbbc9a433e+target=x86_64-unknown-linux-musl for musl_upgrade_1_2_5_with_getrandom_patch_0 [INFO] extracting crate clone-stream 0.2.1 into /workspace/builds/worker-3-tc1/source [INFO] removed /workspace/builds/worker-3-tc1/source/rust-toolchain.toml [INFO] started tweaking crates.io crate clone-stream 0.2.1 [INFO] removed 0 missing tests [INFO] finished tweaking crates.io crate clone-stream 0.2.1 [INFO] tweaked toml for crates.io crate clone-stream 0.2.1 written to /workspace/builds/worker-3-tc1/source/Cargo.toml [INFO] validating manifest of crates.io crate clone-stream 0.2.1 on toolchain 8de4c7234dd9b97c9d76b58671343fdbbc9a433e [INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+8de4c7234dd9b97c9d76b58671343fdbbc9a433e" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }` [INFO] crate crates.io crate clone-stream 0.2.1 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" "+8de4c7234dd9b97c9d76b58671343fdbbc9a433e" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }` [INFO] [stderr] Updating crates.io index [INFO] [stderr] Downloading crates ... [INFO] [stderr] Downloaded test-log-macros v0.2.17 [INFO] [stderr] Downloaded test-log v0.2.17 [INFO] [stderr] Downloaded jiff-static v0.2.10 [INFO] [stderr] Downloaded jiff v0.2.10 [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-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:90999bfc7ae267e83380e433d8e61a7c072ca6729e92edbae886d3423b3a6f4c" "/opt/rustwide/cargo-home/bin/cargo" "+8de4c7234dd9b97c9d76b58671343fdbbc9a433e" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }` [INFO] [stdout] 11426fe8a4fa7ea474c2189b2f94b5882c12c386d7e0ea3660b25dd3a3e0a96b [INFO] running `Command { std: "docker" "start" "-a" "11426fe8a4fa7ea474c2189b2f94b5882c12c386d7e0ea3660b25dd3a3e0a96b", kill_on_drop: false }` [INFO] running `Command { std: "docker" "inspect" "11426fe8a4fa7ea474c2189b2f94b5882c12c386d7e0ea3660b25dd3a3e0a96b", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "11426fe8a4fa7ea474c2189b2f94b5882c12c386d7e0ea3660b25dd3a3e0a96b", kill_on_drop: false }` [INFO] [stdout] 11426fe8a4fa7ea474c2189b2f94b5882c12c386d7e0ea3660b25dd3a3e0a96b [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-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:90999bfc7ae267e83380e433d8e61a7c072ca6729e92edbae886d3423b3a6f4c" "/opt/rustwide/cargo-home/bin/cargo" "+8de4c7234dd9b97c9d76b58671343fdbbc9a433e" "build" "--frozen" "--message-format=json" "--target" "x86_64-unknown-linux-musl", kill_on_drop: false }` [INFO] [stdout] d3b13674b71b0a47e13f686422a3297e114cd917488bde132bea815089ecc07d [INFO] running `Command { std: "docker" "start" "-a" "d3b13674b71b0a47e13f686422a3297e114cd917488bde132bea815089ecc07d", kill_on_drop: false }` [INFO] [stderr] Compiling libc v0.2.172 [INFO] [stderr] Compiling memchr v2.7.4 [INFO] [stderr] Compiling log v0.4.27 [INFO] [stderr] Compiling syn v2.0.101 [INFO] [stderr] Compiling num_cpus v1.16.0 [INFO] [stderr] Compiling futures-macro v0.3.31 [INFO] [stderr] Compiling futures-util v0.3.31 [INFO] [stderr] Compiling futures-executor v0.3.31 [INFO] [stderr] Compiling futures v0.3.31 [INFO] [stderr] Compiling clone-stream v0.2.1 (/opt/rustwide/workdir) [INFO] [stderr] Finished `dev` profile [unoptimized + debuginfo] target(s) in 12.41s [INFO] running `Command { std: "docker" "inspect" "d3b13674b71b0a47e13f686422a3297e114cd917488bde132bea815089ecc07d", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "d3b13674b71b0a47e13f686422a3297e114cd917488bde132bea815089ecc07d", kill_on_drop: false }` [INFO] [stdout] d3b13674b71b0a47e13f686422a3297e114cd917488bde132bea815089ecc07d [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-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:90999bfc7ae267e83380e433d8e61a7c072ca6729e92edbae886d3423b3a6f4c" "/opt/rustwide/cargo-home/bin/cargo" "+8de4c7234dd9b97c9d76b58671343fdbbc9a433e" "test" "--frozen" "--no-run" "--message-format=json" "--target" "x86_64-unknown-linux-musl", kill_on_drop: false }` [INFO] [stdout] 67481c1fdbce74ecaf0811214ee974d49d678e9cb01c51dd4ee7deb184fa3eb7 [INFO] running `Command { std: "docker" "start" "-a" "67481c1fdbce74ecaf0811214ee974d49d678e9cb01c51dd4ee7deb184fa3eb7", kill_on_drop: false }` [INFO] [stderr] Compiling regex-syntax v0.8.5 [INFO] [stderr] Compiling aho-corasick v1.1.3 [INFO] [stderr] Compiling futures-channel v0.3.31 [INFO] [stderr] Compiling smallvec v1.15.0 [INFO] [stderr] Compiling anstyle-parse v0.2.6 [INFO] [stderr] Compiling colorchoice v1.0.3 [INFO] [stderr] Compiling anstyle-query v1.1.2 [INFO] [stderr] Compiling anstyle v1.0.10 [INFO] [stderr] Compiling tokio-macros v2.5.0 [INFO] [stderr] Compiling socket2 v0.5.9 [INFO] [stderr] Compiling futures-util v0.3.31 [INFO] [stderr] Compiling parking_lot_core v0.9.10 [INFO] [stderr] Compiling anstream v0.6.18 [INFO] [stderr] Compiling signal-hook-registry v1.4.5 [INFO] [stderr] Compiling parking_lot v0.12.3 [INFO] [stderr] Compiling mio v1.0.3 [INFO] [stderr] Compiling jiff v0.2.10 [INFO] [stderr] Compiling test-log-macros v0.2.17 [INFO] [stderr] Compiling tokio v1.44.2 [INFO] [stderr] Compiling regex-automata v0.4.9 [INFO] [stderr] Compiling futures-executor v0.3.31 [INFO] [stderr] Compiling futures v0.3.31 [INFO] [stderr] Compiling clone-stream v0.2.1 (/opt/rustwide/workdir) [INFO] [stderr] Compiling regex v1.11.1 [INFO] [stderr] Compiling env_filter v0.1.3 [INFO] [stderr] Compiling env_logger v0.11.8 [INFO] [stderr] Compiling test-log v0.2.17 [INFO] [stderr] Compiling tokio-stream v0.1.17 [INFO] [stderr] Finished `test` profile [unoptimized + debuginfo] target(s) in 55.26s [INFO] running `Command { std: "docker" "inspect" "67481c1fdbce74ecaf0811214ee974d49d678e9cb01c51dd4ee7deb184fa3eb7", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "67481c1fdbce74ecaf0811214ee974d49d678e9cb01c51dd4ee7deb184fa3eb7", kill_on_drop: false }` [INFO] [stdout] 67481c1fdbce74ecaf0811214ee974d49d678e9cb01c51dd4ee7deb184fa3eb7 [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-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:90999bfc7ae267e83380e433d8e61a7c072ca6729e92edbae886d3423b3a6f4c" "/opt/rustwide/cargo-home/bin/cargo" "+8de4c7234dd9b97c9d76b58671343fdbbc9a433e" "test" "--frozen" "--target" "x86_64-unknown-linux-musl", kill_on_drop: false }` [INFO] [stdout] 746295188a1fafa4c4b04b3b561eda3a8b05e3b13ad0eb5a58b21e151bec8551 [INFO] running `Command { std: "docker" "start" "-a" "746295188a1fafa4c4b04b3b561eda3a8b05e3b13ad0eb5a58b21e151bec8551", kill_on_drop: false }` [INFO] [stderr] Finished `test` profile [unoptimized + debuginfo] target(s) in 0.20s [INFO] [stderr] Running unittests src/lib.rs (/opt/rustwide/target/x86_64-unknown-linux-musl/debug/deps/clone_stream-c271350f1431fdc3) [INFO] [stdout] [INFO] [stdout] running 0 tests [INFO] [stdout] [INFO] [stderr] Running tests/clone_receive.rs (/opt/rustwide/target/x86_64-unknown-linux-musl/debug/deps/clone_receive-68942960d3302f24) [INFO] [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s [INFO] [stdout] [INFO] [stdout] [INFO] [stdout] running 1 test [INFO] [stderr] [2025-06-30T08:24:52.200750Z /opt/rustwide/workdir/src/fork.rs:91] Registering clone 0. [INFO] [stderr] [2025-06-30T08:24:52.203974Z /opt/rustwide/workdir/src/fork.rs:91] Registering clone 1. [INFO] [stderr] [2025-06-30T08:24:52.235627Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-06-30T08:24:52.235724Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:39] Currently in state 'NeverPolled' [INFO] [stderr] [2025-06-30T08:24:52.235784Z /opt/rustwide/workdir/src/fork.rs:83] Found 1 wakers. [INFO] [stderr] [2025-06-30T08:24:52.235828Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending. [INFO] [stderr] [2025-06-30T08:24:52.235897Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-06-30T08:24:52.235945Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:39] Currently in state 'NeverPolled' [INFO] [stderr] [2025-06-30T08:24:52.235995Z /opt/rustwide/workdir/src/fork.rs:83] Found 2 wakers. [INFO] [stderr] [2025-06-30T08:24:52.236031Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 1 back into the fork with state: QueueEmptyThenBasePending. [INFO] [stderr] [2025-06-30T08:24:52.247639Z src/fork.rs:139] Waking up all sleeping clones. [INFO] [stdout] test clone_pair_receives ... ok [INFO] [stderr] [2025-06-30T08:24:52.247895Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stdout] [INFO] [stderr] [2025-06-30T08:24:52.247980Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:38] Currently in state 'QueueEmptyThenBasePending' [INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.06s [INFO] [stderr] [2025-06-30T08:24:52.248056Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:40] Queue is empty [INFO] [stdout] [INFO] [stderr] [2025-06-30T08:24:52.248138Z /opt/rustwide/workdir/src/fork.rs:83] Found 2 wakers. [INFO] [stderr] [2025-06-30T08:24:52.248202Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:51] At least one clone is interested in the new item. [INFO] [stderr] [2025-06-30T08:24:52.248289Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 0 back into the fork with state: QueueEmptyThenBaseReady. [INFO] [stderr] [2025-06-30T08:24:52.248365Z /opt/rustwide/workdir/src/fork.rs:99] Unregistering clone 0. [INFO] [stderr] [2025-06-30T08:24:52.248441Z src/states/mod.rs:90] Checking if state QueueEmptyThenBasePending should still see queue item with index 0 [INFO] [stderr] [2025-06-30T08:24:52.248527Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-06-30T08:24:52.248608Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:38] Currently in state 'QueueEmptyThenBasePending' [INFO] [stderr] [2025-06-30T08:24:52.248667Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:85] No other clone is waiting for the first item in the queue. [INFO] [stderr] [2025-06-30T08:24:52.248739Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 1 back into the fork with state: UnseenQueuedItemReady. [INFO] [stderr] [2025-06-30T08:24:52.248797Z /opt/rustwide/workdir/src/fork.rs:99] Unregistering clone 1. [INFO] [stderr] Running tests/is_terminated.rs (/opt/rustwide/target/x86_64-unknown-linux-musl/debug/deps/is_terminated-ae52a6fec625ee6d) [INFO] [stdout] [INFO] [stdout] running 2 tests [INFO] [stdout] test two_clones_terminated ... ok [INFO] [stdout] test ready_into_stream ... ok [INFO] [stdout] [INFO] [stdout] test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.01s [INFO] [stdout] [INFO] [stdout] [INFO] [stderr] Running tests/late_clone.rs (/opt/rustwide/target/x86_64-unknown-linux-musl/debug/deps/late_clone-cd2490cd2dd68166) [INFO] [stdout] running 1 test [INFO] [stderr] [2025-06-30T08:24:52.275609Z /opt/rustwide/workdir/src/fork.rs:91] Registering clone 0. [INFO] [stderr] [2025-06-30T08:24:52.275775Z /opt/rustwide/workdir/src/fork.rs:91] Registering clone 1. [INFO] [stderr] [2025-06-30T08:24:52.307130Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-06-30T08:24:52.307288Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:39] Currently in state 'NeverPolled' [INFO] [stderr] [2025-06-30T08:24:52.307358Z /opt/rustwide/workdir/src/fork.rs:83] Found 1 wakers. [INFO] [stderr] [2025-06-30T08:24:52.307425Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending. [INFO] [stderr] [2025-06-30T08:24:52.307514Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-06-30T08:24:52.307596Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:39] Currently in state 'NeverPolled' [INFO] [stderr] [2025-06-30T08:24:52.307658Z /opt/rustwide/workdir/src/fork.rs:83] Found 2 wakers. [INFO] [stderr] [2025-06-30T08:24:52.307713Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 1 back into the fork with state: QueueEmptyThenBasePending. [INFO] [stderr] [2025-06-30T08:24:52.316953Z src/fork.rs:139] Waking up all sleeping clones. [INFO] [stderr] [2025-06-30T08:24:52.317118Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-06-30T08:24:52.317197Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:38] Currently in state 'QueueEmptyThenBasePending' [INFO] [stderr] [2025-06-30T08:24:52.317270Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:40] Queue is empty [INFO] [stderr] [2025-06-30T08:24:52.317332Z /opt/rustwide/workdir/src/fork.rs:83] Found 2 wakers. [INFO] [stderr] [2025-06-30T08:24:52.317382Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:51] At least one clone is interested in the new item. [INFO] [stderr] [2025-06-30T08:24:52.317457Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 0 back into the fork with state: QueueEmptyThenBaseReady. [INFO] [stderr] [2025-06-30T08:24:52.317523Z /opt/rustwide/workdir/src/fork.rs:99] Unregistering clone 0. [INFO] [stderr] [2025-06-30T08:24:52.317590Z src/states/mod.rs:90] Checking if state QueueEmptyThenBasePending should still see queue item with index 0 [INFO] [stderr] [2025-06-30T08:24:52.317671Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-06-30T08:24:52.317726Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:38] Currently in state 'QueueEmptyThenBasePending' [INFO] [stderr] [2025-06-30T08:24:52.317789Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:85] No other clone is waiting for the first item in the queue. [INFO] [stderr] [2025-06-30T08:24:52.317860Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 1 back into the fork with state: UnseenQueuedItemReady. [INFO] [stderr] [2025-06-30T08:24:52.317979Z /opt/rustwide/workdir/src/fork.rs:91] Registering clone 2. [INFO] [stderr] [2025-06-30T08:24:52.330634Z /opt/rustwide/workdir/src/fork.rs:44] Clone 2 is being polled through the fork. [INFO] [stderr] [2025-06-30T08:24:52.330726Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:39] Currently in state 'NeverPolled' [INFO] [stderr] [2025-06-30T08:24:52.330777Z /opt/rustwide/workdir/src/fork.rs:83] Found 1 wakers. [INFO] [stderr] [2025-06-30T08:24:52.330815Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 2 back into the fork with state: QueueEmptyThenBasePending. [INFO] [stderr] [2025-06-30T08:24:52.337033Z src/fork.rs:139] Waking up all sleeping clones. [INFO] [stderr] [2025-06-30T08:24:52.337200Z /opt/rustwide/workdir/src/fork.rs:44] Clone 2 is being polled through the fork. [INFO] [stderr] [2025-06-30T08:24:52.337284Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:38] Currently in state 'QueueEmptyThenBasePending' [INFO] [stderr] [2025-06-30T08:24:52.337357Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:40] Queue is empty [INFO] [stderr] [2025-06-30T08:24:52.337431Z /opt/rustwide/workdir/src/fork.rs:83] Found 1 wakers. [INFO] [stderr] [2025-06-30T08:24:52.337487Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:55] No other clone is interested in the new item. [INFO] [stderr] [2025-06-30T08:24:52.337576Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 2 back into the fork with state: QueueEmptyThenBaseReady. [INFO] [stderr] [2025-06-30T08:24:52.337644Z /opt/rustwide/workdir/src/fork.rs:99] Unregistering clone 2. [INFO] [stderr] [2025-06-30T08:24:52.337699Z /opt/rustwide/workdir/src/fork.rs:99] Unregistering clone 1. [INFO] [stderr] Running tests/late_poll.rs (/opt/rustwide/target/x86_64-unknown-linux-musl/debug/deps/late_poll-57b85f8f28f158c0) [INFO] [stdout] test clone_after_send ... ok [INFO] [stdout] [INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.07s [INFO] [stdout] [INFO] [stdout] [INFO] [stdout] running 2 tests [INFO] [stderr] [2025-06-30T08:24:52.345175Z /opt/rustwide/workdir/src/fork.rs:91] Registering clone 0. [INFO] [stderr] [2025-06-30T08:24:52.345285Z /opt/rustwide/workdir/src/fork.rs:91] Registering clone 1. [INFO] [stderr] [2025-06-30T08:24:52.376443Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-06-30T08:24:52.376503Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-06-30T08:24:52.376684Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:39] Currently in state 'NeverPolled' [INFO] [stderr] [2025-06-30T08:24:52.376768Z /opt/rustwide/workdir/src/fork.rs:83] Found 1 wakers. [INFO] [stderr] [2025-06-30T08:24:52.376994Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending. [INFO] [stderr] [2025-06-30T08:24:52.376618Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:39] Currently in state 'NeverPolled' [INFO] [stderr] [2025-06-30T08:24:52.380610Z /opt/rustwide/workdir/src/fork.rs:83] Found 1 wakers. [INFO] [stderr] [2025-06-30T08:24:52.380667Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending. [INFO] [stderr] [2025-06-30T08:24:52.380740Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-06-30T08:24:52.380780Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:39] Currently in state 'NeverPolled' [INFO] [stderr] [2025-06-30T08:24:52.380821Z /opt/rustwide/workdir/src/fork.rs:83] Found 2 wakers. [INFO] [stderr] [2025-06-30T08:24:52.380854Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 1 back into the fork with state: QueueEmptyThenBasePending. [INFO] [stderr] [2025-06-30T08:24:52.386059Z src/fork.rs:139] Waking up all sleeping clones. [INFO] [stderr] [2025-06-30T08:24:52.386165Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-06-30T08:24:52.386215Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:38] Currently in state 'QueueEmptyThenBasePending' [INFO] [stderr] [2025-06-30T08:24:52.386264Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:40] Queue is empty [INFO] [stderr] [2025-06-30T08:24:52.386313Z /opt/rustwide/workdir/src/fork.rs:83] Found 2 wakers. [INFO] [stderr] [2025-06-30T08:24:52.386351Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:51] At least one clone is interested in the new item. [INFO] [stderr] [2025-06-30T08:24:52.386402Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 0 back into the fork with state: QueueEmptyThenBaseReady. [INFO] [stderr] [2025-06-30T08:24:52.386476Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-06-30T08:24:52.386516Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:38] Currently in state 'QueueEmptyThenBasePending' [INFO] [stderr] [2025-06-30T08:24:52.386582Z src/states/mod.rs:90] Checking if state QueueEmptyThenBaseReady should still see queue item with index 0 [INFO] [stderr] [2025-06-30T08:24:52.386626Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:85] No other clone is waiting for the first item in the queue. [INFO] [stderr] [2025-06-30T08:24:52.386678Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 1 back into the fork with state: UnseenQueuedItemReady. [INFO] [stderr] [2025-06-30T08:24:52.396231Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-06-30T08:24:52.396574Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:39] Currently in state 'NeverPolled' [INFO] [stderr] [2025-06-30T08:24:52.396904Z /opt/rustwide/workdir/src/fork.rs:83] Found 2 wakers. [INFO] [stderr] [2025-06-30T08:24:52.397060Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 1 back into the fork with state: QueueEmptyThenBasePending. [INFO] [stderr] [2025-06-30T08:24:52.397349Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-06-30T08:24:52.397976Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:38] Currently in state 'QueueEmptyThenBasePending' [INFO] [stderr] [2025-06-30T08:24:52.398177Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:40] Queue is empty [INFO] [stderr] [2025-06-30T08:24:52.398497Z /opt/rustwide/workdir/src/fork.rs:83] Found 2 wakers. [INFO] [stderr] [2025-06-30T08:24:52.398933Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending. [INFO] [stderr] [2025-06-30T08:24:52.399592Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-06-30T08:24:52.402798Z /opt/rustwide/workdir/src/fork.rs:83] Found 1 wakers. [INFO] [stderr] [2025-06-30T08:24:52.402850Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 1 back into the fork with state: NoUnseenQueuedThenBasePending. [INFO] [stderr] [2025-06-30T08:24:52.403030Z tests/late_poll.rs:38] Cancelled next() await of adam. [INFO] [stderr] [2025-06-30T08:24:52.403465Z /opt/rustwide/workdir/src/fork.rs:99] Unregistering clone 0. [INFO] [stderr] [2025-06-30T08:24:52.406032Z src/fork.rs:139] Waking up all sleeping clones. [INFO] [stderr] [2025-06-30T08:24:52.406113Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-06-30T08:24:52.406174Z /opt/rustwide/workdir/src/fork.rs:83] Found 1 wakers. [INFO] [stderr] [2025-06-30T08:24:52.406220Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 1 back into the fork with state: NoUnseenQueuedThenBaseReady. [INFO] [stderr] [2025-06-30T08:24:52.406280Z /opt/rustwide/workdir/src/fork.rs:99] Unregistering clone 1. [INFO] [stdout] test poll_after_send ... ok [INFO] [stderr] [2025-06-30T08:24:52.418910Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-06-30T08:24:52.419002Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_ready.rs:33] The queue was empty on last poll of this clone, but the base was ready. [INFO] [stderr] [2025-06-30T08:24:52.419069Z /opt/rustwide/workdir/src/fork.rs:83] Found 1 wakers. [INFO] [stderr] [2025-06-30T08:24:52.419109Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_ready.rs:48] No other clone is interested in the new item. [INFO] [stderr] [2025-06-30T08:24:52.419167Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 0 back into the fork with state: QueueEmptyThenBaseReady. [INFO] [stderr] [2025-06-30T08:24:52.419229Z /opt/rustwide/workdir/src/fork.rs:99] Unregistering clone 0. [INFO] [stderr] [2025-06-30T08:24:52.456193Z src/fork.rs:139] Waking up all sleeping clones. [INFO] [stderr] [2025-06-30T08:24:52.456311Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-06-30T08:24:52.456358Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:38] Currently in state 'QueueEmptyThenBasePending' [INFO] [stderr] [2025-06-30T08:24:52.456406Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:40] Queue is empty [INFO] [stderr] [2025-06-30T08:24:52.456461Z /opt/rustwide/workdir/src/fork.rs:83] Found 1 wakers. [INFO] [stderr] [2025-06-30T08:24:52.456496Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:55] No other clone is interested in the new item. [INFO] [stderr] [2025-06-30T08:24:52.456562Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 1 back into the fork with state: QueueEmptyThenBaseReady. [INFO] [stderr] [2025-06-30T08:24:52.456618Z /opt/rustwide/workdir/src/fork.rs:99] Unregistering clone 1. [INFO] [stdout] test poll_before_send ... ok [INFO] [stdout] [INFO] [stdout] test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.11s [INFO] [stdout] [INFO] [stderr] Running tests/queue_len.rs (/opt/rustwide/target/x86_64-unknown-linux-musl/debug/deps/queue_len-c8fcb296defda177) [INFO] [stdout] [INFO] [stdout] running 1 test [INFO] [stderr] [2025-06-30T08:24:52.459158Z /opt/rustwide/workdir/src/fork.rs:91] Registering clone 0. [INFO] [stderr] [2025-06-30T08:24:52.490643Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-06-30T08:24:52.490812Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:39] Currently in state 'NeverPolled' [INFO] [stderr] [2025-06-30T08:24:52.490923Z /opt/rustwide/workdir/src/fork.rs:83] Found 1 wakers. [INFO] [stderr] [2025-06-30T08:24:52.491008Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending. [INFO] [stderr] [2025-06-30T08:24:52.513630Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-06-30T08:24:52.513794Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:38] Currently in state 'QueueEmptyThenBasePending' [INFO] [stderr] [2025-06-30T08:24:52.513907Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:40] Queue is empty [INFO] [stderr] [2025-06-30T08:24:52.514002Z /opt/rustwide/workdir/src/fork.rs:83] Found 1 wakers. [INFO] [stderr] [2025-06-30T08:24:52.514082Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending. [INFO] [stderr] [2025-06-30T08:24:52.520432Z src/fork.rs:139] Waking up all sleeping clones. [INFO] [stderr] [2025-06-30T08:24:52.530931Z /opt/rustwide/workdir/src/clone.rs:99] Getting the number of queued items for clone 0. [INFO] [stderr] [2025-06-30T08:24:52.531093Z /opt/rustwide/workdir/src/fork.rs:99] Unregistering clone 0. [INFO] [stdout] test cancelled_next_queue_empty ... ok [INFO] [stdout] [INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.07s [INFO] [stdout] [INFO] [stderr] Running tests/size_hint.rs (/opt/rustwide/target/x86_64-unknown-linux-musl/debug/deps/size_hint-f8036b9f8452ae6b) [INFO] [stdout] [INFO] [stdout] running 2 tests [INFO] [stdout] test two_clone_size ... ok [INFO] [stdout] test one_clone_size ... ok [INFO] [stdout] [INFO] [stdout] test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.01s [INFO] [stdout] [INFO] [stderr] Running tests/stress_test.rs (/opt/rustwide/target/x86_64-unknown-linux-musl/debug/deps/stress_test-aca725d46d1039b6) [INFO] [stdout] [INFO] [stdout] running 2 tests [INFO] [stdout] test mass_send ... ok [INFO] [stdout] test mass_send_interval ... ok [INFO] [stdout] [INFO] [stdout] test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 1.17s [INFO] [stdout] [INFO] [stderr] Running tests/util.rs (/opt/rustwide/target/x86_64-unknown-linux-musl/debug/deps/util-229366c8871959da) [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] running `Command { std: "docker" "inspect" "746295188a1fafa4c4b04b3b561eda3a8b05e3b13ad0eb5a58b21e151bec8551", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "746295188a1fafa4c4b04b3b561eda3a8b05e3b13ad0eb5a58b21e151bec8551", kill_on_drop: false }` [INFO] [stdout] 746295188a1fafa4c4b04b3b561eda3a8b05e3b13ad0eb5a58b21e151bec8551