[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_libc_patch_0 [INFO] extracting crate clone-stream 0.2.1 into /workspace/builds/worker-6-tc1/source [INFO] removed /workspace/builds/worker-6-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-6-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] Blocking waiting for file lock on package cache [INFO] [stderr] Blocking waiting for file lock on package cache [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-6-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-6-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] 18f4216a4ab8bcf03d500a0c7039110532874f2eef0aa0d15daeacd14906e400 [INFO] running `Command { std: "docker" "start" "-a" "18f4216a4ab8bcf03d500a0c7039110532874f2eef0aa0d15daeacd14906e400", kill_on_drop: false }` [INFO] running `Command { std: "docker" "inspect" "18f4216a4ab8bcf03d500a0c7039110532874f2eef0aa0d15daeacd14906e400", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "18f4216a4ab8bcf03d500a0c7039110532874f2eef0aa0d15daeacd14906e400", kill_on_drop: false }` [INFO] [stdout] 18f4216a4ab8bcf03d500a0c7039110532874f2eef0aa0d15daeacd14906e400 [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-6-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-6-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] 5052587fdc499c7011d9627d7eebd788bb733f1e2730c8fd662c2d531076eefb [INFO] running `Command { std: "docker" "start" "-a" "5052587fdc499c7011d9627d7eebd788bb733f1e2730c8fd662c2d531076eefb", kill_on_drop: false }` [INFO] [stderr] Compiling autocfg v1.4.0 [INFO] [stderr] Compiling futures-core v0.3.31 [INFO] [stderr] Compiling futures-sink v0.3.31 [INFO] [stderr] Compiling pin-project-lite v0.2.16 [INFO] [stderr] Compiling futures-task v0.3.31 [INFO] [stderr] Compiling memchr v2.7.4 [INFO] [stderr] Compiling futures-io v0.3.31 [INFO] [stderr] Compiling pin-utils v0.1.0 [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-channel v0.3.31 [INFO] [stderr] Compiling slab v0.4.9 [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 11.26s [INFO] running `Command { std: "docker" "inspect" "5052587fdc499c7011d9627d7eebd788bb733f1e2730c8fd662c2d531076eefb", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "5052587fdc499c7011d9627d7eebd788bb733f1e2730c8fd662c2d531076eefb", kill_on_drop: false }` [INFO] [stdout] 5052587fdc499c7011d9627d7eebd788bb733f1e2730c8fd662c2d531076eefb [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-6-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-6-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] df84254fa72beb30e56e81a72218a58aee7be7fd6a7ea68be4a43f391257f916 [INFO] running `Command { std: "docker" "start" "-a" "df84254fa72beb30e56e81a72218a58aee7be7fd6a7ea68be4a43f391257f916", kill_on_drop: false }` [INFO] [stderr] Compiling futures-core v0.3.31 [INFO] [stderr] Compiling parking_lot_core v0.9.10 [INFO] [stderr] Compiling cfg-if v1.0.0 [INFO] [stderr] Compiling scopeguard v1.2.0 [INFO] [stderr] Compiling log v0.4.27 [INFO] [stderr] Compiling smallvec v1.15.0 [INFO] [stderr] Compiling aho-corasick v1.1.3 [INFO] [stderr] Compiling lock_api v0.4.12 [INFO] [stderr] Compiling colorchoice v1.0.3 [INFO] [stderr] Compiling anstyle-query v1.1.2 [INFO] [stderr] Compiling anstyle-parse v0.2.6 [INFO] [stderr] Compiling anstyle v1.0.10 [INFO] [stderr] Compiling bytes v1.10.1 [INFO] [stderr] Compiling tokio-macros v2.5.0 [INFO] [stderr] Compiling socket2 v0.5.9 [INFO] [stderr] Compiling mio v1.0.3 [INFO] [stderr] Compiling futures-channel v0.3.31 [INFO] [stderr] Compiling signal-hook-registry v1.4.5 [INFO] [stderr] Compiling jiff v0.2.10 [INFO] [stderr] Compiling test-log-macros v0.2.17 [INFO] [stderr] Compiling anstream v0.6.18 [INFO] [stderr] Compiling futures-util v0.3.31 [INFO] [stderr] Compiling parking_lot v0.12.3 [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 regex v1.11.1 [INFO] [stderr] Compiling futures v0.3.31 [INFO] [stderr] Compiling clone-stream v0.2.1 (/opt/rustwide/workdir) [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 26.26s [INFO] running `Command { std: "docker" "inspect" "df84254fa72beb30e56e81a72218a58aee7be7fd6a7ea68be4a43f391257f916", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "df84254fa72beb30e56e81a72218a58aee7be7fd6a7ea68be4a43f391257f916", kill_on_drop: false }` [INFO] [stdout] df84254fa72beb30e56e81a72218a58aee7be7fd6a7ea68be4a43f391257f916 [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-6-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-6-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] 5467c551e4192a305f61817bb7c218dfdf28e74118ecd13635db0566c1f905e7 [INFO] running `Command { std: "docker" "start" "-a" "5467c551e4192a305f61817bb7c218dfdf28e74118ecd13635db0566c1f905e7", kill_on_drop: false }` [INFO] [stderr] Finished `test` profile [unoptimized + debuginfo] target(s) in 0.14s [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] [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/clone_receive.rs (/opt/rustwide/target/x86_64-unknown-linux-musl/debug/deps/clone_receive-68942960d3302f24) [INFO] [stdout] [INFO] [stdout] running 1 test [INFO] [stderr] [2025-06-29T13:47:35.961107Z /opt/rustwide/workdir/src/fork.rs:91] Registering clone 0. [INFO] [stderr] [2025-06-29T13:47:35.961304Z /opt/rustwide/workdir/src/fork.rs:91] Registering clone 1. [INFO] [stderr] [2025-06-29T13:47:35.992716Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-06-29T13:47:35.996630Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:39] Currently in state 'NeverPolled' [INFO] [stderr] [2025-06-29T13:47:35.996713Z /opt/rustwide/workdir/src/fork.rs:83] Found 1 wakers. [INFO] [stderr] [2025-06-29T13:47:35.996757Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending. [INFO] [stderr] [2025-06-29T13:47:35.996831Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-06-29T13:47:35.996873Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:39] Currently in state 'NeverPolled' [INFO] [stderr] [2025-06-29T13:47:35.996918Z /opt/rustwide/workdir/src/fork.rs:83] Found 2 wakers. [INFO] [stderr] [2025-06-29T13:47:35.996953Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 1 back into the fork with state: QueueEmptyThenBasePending. [INFO] [stderr] [2025-06-29T13:47:36.002162Z src/fork.rs:139] Waking up all sleeping clones. [INFO] [stderr] [2025-06-29T13:47:36.002321Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-06-29T13:47:36.002412Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:38] Currently in state 'QueueEmptyThenBasePending' [INFO] [stderr] [2025-06-29T13:47:36.002496Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:40] Queue is empty [INFO] [stderr] [2025-06-29T13:47:36.002570Z /opt/rustwide/workdir/src/fork.rs:83] Found 2 wakers. [INFO] [stderr] [2025-06-29T13:47:36.002669Z /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-29T13:47:36.002789Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 0 back into the fork with state: QueueEmptyThenBaseReady. [INFO] [stderr] [2025-06-29T13:47:36.002889Z /opt/rustwide/workdir/src/fork.rs:99] Unregistering clone 0. [INFO] [stderr] [2025-06-29T13:47:36.002960Z src/states/mod.rs:90] Checking if state QueueEmptyThenBasePending should still see queue item with index 0 [INFO] [stderr] [2025-06-29T13:47:36.003068Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-06-29T13:47:36.003164Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:38] Currently in state 'QueueEmptyThenBasePending' [INFO] [stderr] [2025-06-29T13:47:36.003252Z /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-29T13:47:36.003340Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 1 back into the fork with state: UnseenQueuedItemReady. [INFO] [stderr] [2025-06-29T13:47:36.003438Z /opt/rustwide/workdir/src/fork.rs:99] Unregistering clone 1. [INFO] [stdout] test clone_pair_receives ... ok [INFO] [stdout] [INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.04s [INFO] [stdout] [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 ready_into_stream ... ok [INFO] [stdout] test two_clones_terminated ... ok [INFO] [stdout] [INFO] [stdout] test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s [INFO] [stdout] [INFO] [stderr] Running tests/late_clone.rs (/opt/rustwide/target/x86_64-unknown-linux-musl/debug/deps/late_clone-cd2490cd2dd68166) [INFO] [stdout] [INFO] [stdout] running 1 test [INFO] [stderr] [2025-06-29T13:47:36.021264Z /opt/rustwide/workdir/src/fork.rs:91] Registering clone 0. [INFO] [stderr] [2025-06-29T13:47:36.021433Z /opt/rustwide/workdir/src/fork.rs:91] Registering clone 1. [INFO] [stderr] [2025-06-29T13:47:36.054901Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-06-29T13:47:36.055011Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:39] Currently in state 'NeverPolled' [INFO] [stderr] [2025-06-29T13:47:36.055069Z /opt/rustwide/workdir/src/fork.rs:83] Found 1 wakers. [INFO] [stderr] [2025-06-29T13:47:36.055117Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending. [INFO] [stderr] [2025-06-29T13:47:36.055196Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-06-29T13:47:36.055326Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:39] Currently in state 'NeverPolled' [INFO] [stderr] [2025-06-29T13:47:36.055417Z /opt/rustwide/workdir/src/fork.rs:83] Found 2 wakers. [INFO] [stderr] [2025-06-29T13:47:36.055484Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 1 back into the fork with state: QueueEmptyThenBasePending. [INFO] [stderr] [2025-06-29T13:47:36.062742Z src/fork.rs:139] Waking up all sleeping clones. [INFO] [stderr] [2025-06-29T13:47:36.062898Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-06-29T13:47:36.063023Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:38] Currently in state 'QueueEmptyThenBasePending' [INFO] [stderr] [2025-06-29T13:47:36.063302Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:40] Queue is empty [INFO] [stderr] [2025-06-29T13:47:36.063633Z /opt/rustwide/workdir/src/fork.rs:83] Found 2 wakers. [INFO] [stderr] [2025-06-29T13:47:36.063955Z /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-29T13:47:36.064030Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 0 back into the fork with state: QueueEmptyThenBaseReady. [INFO] [stderr] [2025-06-29T13:47:36.064091Z /opt/rustwide/workdir/src/fork.rs:99] Unregistering clone 0. [INFO] [stderr] [2025-06-29T13:47:36.064135Z src/states/mod.rs:90] Checking if state QueueEmptyThenBasePending should still see queue item with index 0 [INFO] [stderr] [2025-06-29T13:47:36.064215Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-06-29T13:47:36.064260Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:38] Currently in state 'QueueEmptyThenBasePending' [INFO] [stderr] [2025-06-29T13:47:36.064314Z /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-29T13:47:36.064383Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 1 back into the fork with state: UnseenQueuedItemReady. [INFO] [stderr] [2025-06-29T13:47:36.064435Z /opt/rustwide/workdir/src/fork.rs:91] Registering clone 2. [INFO] [stderr] [2025-06-29T13:47:36.073901Z /opt/rustwide/workdir/src/fork.rs:44] Clone 2 is being polled through the fork. [INFO] [stderr] [2025-06-29T13:47:36.074006Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:39] Currently in state 'NeverPolled' [INFO] [stderr] [2025-06-29T13:47:36.074075Z /opt/rustwide/workdir/src/fork.rs:83] Found 1 wakers. [INFO] [stderr] [2025-06-29T13:47:36.074128Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 2 back into the fork with state: QueueEmptyThenBasePending. [INFO] [stderr] [2025-06-29T13:47:36.083689Z src/fork.rs:139] Waking up all sleeping clones. [INFO] [stderr] [2025-06-29T13:47:36.083810Z /opt/rustwide/workdir/src/fork.rs:44] Clone 2 is being polled through the fork. [INFO] [stderr] [2025-06-29T13:47:36.083863Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:38] Currently in state 'QueueEmptyThenBasePending' [INFO] [stderr] [2025-06-29T13:47:36.083920Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:40] Queue is empty [INFO] [stderr] [2025-06-29T13:47:36.083973Z /opt/rustwide/workdir/src/fork.rs:83] Found 1 wakers. [INFO] [stderr] [2025-06-29T13:47:36.084022Z /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-29T13:47:36.084085Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 2 back into the fork with state: QueueEmptyThenBaseReady. [INFO] [stderr] [2025-06-29T13:47:36.084153Z /opt/rustwide/workdir/src/fork.rs:99] Unregistering clone 2. [INFO] [stderr] [2025-06-29T13:47:36.084196Z /opt/rustwide/workdir/src/fork.rs:99] Unregistering clone 1. [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.06s [INFO] [stdout] [INFO] [stderr] Running tests/late_poll.rs (/opt/rustwide/target/x86_64-unknown-linux-musl/debug/deps/late_poll-57b85f8f28f158c0) [INFO] [stdout] [INFO] [stdout] running 2 tests [INFO] [stderr] [2025-06-29T13:47:36.116310Z /opt/rustwide/workdir/src/fork.rs:91] Registering clone 0. [INFO] [stderr] [2025-06-29T13:47:36.133667Z /opt/rustwide/workdir/src/fork.rs:91] Registering clone 1. [INFO] [stderr] [2025-06-29T13:47:36.145319Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-06-29T13:47:36.145452Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:39] Currently in state 'NeverPolled' [INFO] [stderr] [2025-06-29T13:47:36.145529Z /opt/rustwide/workdir/src/fork.rs:83] Found 1 wakers. [INFO] [stderr] [2025-06-29T13:47:36.145579Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending. [INFO] [stderr] [2025-06-29T13:47:36.145683Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-06-29T13:47:36.145731Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:39] Currently in state 'NeverPolled' [INFO] [stderr] [2025-06-29T13:47:36.145782Z /opt/rustwide/workdir/src/fork.rs:83] Found 2 wakers. [INFO] [stderr] [2025-06-29T13:47:36.145826Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 1 back into the fork with state: QueueEmptyThenBasePending. [INFO] [stderr] [2025-06-29T13:47:36.156080Z src/fork.rs:139] Waking up all sleeping clones. [INFO] [stderr] [2025-06-29T13:47:36.156384Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-06-29T13:47:36.156721Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:38] Currently in state 'QueueEmptyThenBasePending' [INFO] [stderr] [2025-06-29T13:47:36.156822Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:40] Queue is empty [INFO] [stderr] [2025-06-29T13:47:36.156937Z /opt/rustwide/workdir/src/fork.rs:83] Found 2 wakers. [INFO] [stderr] [2025-06-29T13:47:36.157134Z /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-29T13:47:36.157219Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 0 back into the fork with state: QueueEmptyThenBaseReady. [INFO] [stderr] [2025-06-29T13:47:36.157303Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-06-29T13:47:36.157362Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:38] Currently in state 'QueueEmptyThenBasePending' [INFO] [stderr] [2025-06-29T13:47:36.157417Z src/states/mod.rs:90] Checking if state QueueEmptyThenBaseReady should still see queue item with index 0 [INFO] [stderr] [2025-06-29T13:47:36.157469Z /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-29T13:47:36.157531Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 1 back into the fork with state: UnseenQueuedItemReady. [INFO] [stderr] [2025-06-29T13:47:36.164301Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-06-29T13:47:36.164454Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:39] Currently in state 'NeverPolled' [INFO] [stderr] [2025-06-29T13:47:36.164528Z /opt/rustwide/workdir/src/fork.rs:83] Found 1 wakers. [INFO] [stderr] [2025-06-29T13:47:36.164654Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending. [INFO] [stderr] [2025-06-29T13:47:36.166721Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-06-29T13:47:36.166845Z /opt/rustwide/workdir/src/fork.rs:83] Found 1 wakers. [INFO] [stderr] [2025-06-29T13:47:36.166891Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 1 back into the fork with state: NoUnseenQueuedThenBasePending. [INFO] [stderr] [2025-06-29T13:47:36.175113Z src/fork.rs:139] Waking up all sleeping clones. [INFO] [stderr] [2025-06-29T13:47:36.175213Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-06-29T13:47:36.175270Z /opt/rustwide/workdir/src/fork.rs:83] Found 1 wakers. [INFO] [stderr] [2025-06-29T13:47:36.175313Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 1 back into the fork with state: NoUnseenQueuedThenBaseReady. [INFO] [stderr] [2025-06-29T13:47:36.175377Z /opt/rustwide/workdir/src/fork.rs:99] Unregistering clone 1. [INFO] [stderr] [2025-06-29T13:47:36.185112Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-06-29T13:47:36.185217Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:39] Currently in state 'NeverPolled' [INFO] [stderr] [2025-06-29T13:47:36.185277Z /opt/rustwide/workdir/src/fork.rs:83] Found 2 wakers. [INFO] [stderr] [2025-06-29T13:47:36.185328Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 1 back into the fork with state: QueueEmptyThenBasePending. [INFO] [stderr] [2025-06-29T13:47:36.185398Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-06-29T13:47:36.185440Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:38] Currently in state 'QueueEmptyThenBasePending' [INFO] [stderr] [2025-06-29T13:47:36.185492Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:40] Queue is empty [INFO] [stderr] [2025-06-29T13:47:36.185537Z /opt/rustwide/workdir/src/fork.rs:83] Found 2 wakers. [INFO] [stderr] [2025-06-29T13:47:36.185574Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending. [INFO] [stderr] [2025-06-29T13:47:36.185649Z tests/late_poll.rs:38] Cancelled next() await of adam. [INFO] [stderr] [2025-06-29T13:47:36.185684Z /opt/rustwide/workdir/src/fork.rs:99] Unregistering clone 0. [INFO] [stderr] [2025-06-29T13:47:36.185675Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-06-29T13:47:36.185963Z /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-29T13:47:36.186101Z /opt/rustwide/workdir/src/fork.rs:83] Found 1 wakers. [INFO] [stderr] [2025-06-29T13:47:36.186149Z /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-29T13:47:36.186209Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 0 back into the fork with state: QueueEmptyThenBaseReady. [INFO] [stderr] [2025-06-29T13:47:36.186295Z /opt/rustwide/workdir/src/fork.rs:99] Unregistering clone 0. [INFO] [stdout] test poll_after_send ... ok [INFO] [stderr] [2025-06-29T13:47:36.244830Z src/fork.rs:139] Waking up all sleeping clones. [INFO] [stderr] [2025-06-29T13:47:36.245064Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-06-29T13:47:36.245274Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:38] Currently in state 'QueueEmptyThenBasePending' [INFO] [stderr] [2025-06-29T13:47:36.245439Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:40] Queue is empty [INFO] [stderr] [2025-06-29T13:47:36.245532Z /opt/rustwide/workdir/src/fork.rs:83] Found 1 wakers. [INFO] [stderr] [2025-06-29T13:47:36.245631Z /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-29T13:47:36.245748Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 1 back into the fork with state: QueueEmptyThenBaseReady. [INFO] [stderr] [2025-06-29T13:47:36.245845Z /opt/rustwide/workdir/src/fork.rs:99] Unregistering clone 1. [INFO] [stderr] Running tests/queue_len.rs (/opt/rustwide/target/x86_64-unknown-linux-musl/debug/deps/queue_len-c8fcb296defda177) [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.14s [INFO] [stdout] [INFO] [stdout] [INFO] [stdout] running 1 test [INFO] [stderr] [2025-06-29T13:47:36.267112Z /opt/rustwide/workdir/src/fork.rs:91] Registering clone 0. [INFO] [stderr] [2025-06-29T13:47:36.306332Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-06-29T13:47:36.306449Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:39] Currently in state 'NeverPolled' [INFO] [stderr] [2025-06-29T13:47:36.306519Z /opt/rustwide/workdir/src/fork.rs:83] Found 1 wakers. [INFO] [stderr] [2025-06-29T13:47:36.306571Z /opt/rustwide/workdir/src/fork.rs:69] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending. [INFO] [stderr] [2025-06-29T13:47:36.336704Z src/fork.rs:139] Waking up all sleeping clones. [INFO] [stderr] [2025-06-29T13:47:36.346006Z /opt/rustwide/workdir/src/clone.rs:99] Getting the number of queued items for clone 0. [INFO] [stderr] [2025-06-29T13:47:36.346124Z /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.09s [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.00s [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_interval ... ok [INFO] [stderr] Running tests/util.rs (/opt/rustwide/target/x86_64-unknown-linux-musl/debug/deps/util-229366c8871959da) [INFO] [stdout] test mass_send ... 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] [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" "5467c551e4192a305f61817bb7c218dfdf28e74118ecd13635db0566c1f905e7", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "5467c551e4192a305f61817bb7c218dfdf28e74118ecd13635db0566c1f905e7", kill_on_drop: false }` [INFO] [stdout] 5467c551e4192a305f61817bb7c218dfdf28e74118ecd13635db0566c1f905e7