[INFO] cloning repository https://github.com/wvhulle/forked_stream [INFO] running `Command { std: "git" "-c" "credential.helper=" "-c" "credential.helper=/workspace/cargo-home/bin/git-credential-null" "clone" "--bare" "https://github.com/wvhulle/forked_stream" "/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fwvhulle%2Fforked_stream", kill_on_drop: false }` [INFO] [stderr] Cloning into bare repository '/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fwvhulle%2Fforked_stream'... [INFO] running `Command { std: "git" "rev-parse" "HEAD", kill_on_drop: false }` [INFO] [stdout] 8b3fbaba9d38b078ea024c538ad0cbb1634065bc [INFO] testing wvhulle/forked_stream against master#cdb45c87e2cd43495379f7e867e3cc15dcee9f93 for pr-145838-1 [INFO] running `Command { std: "git" "clone" "/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fwvhulle%2Fforked_stream" "/workspace/builds/worker-6-tc1/source", kill_on_drop: false }` [INFO] [stderr] Cloning into '/workspace/builds/worker-6-tc1/source'... [INFO] [stderr] done. [INFO] removed /workspace/builds/worker-6-tc1/source/rust-toolchain.toml [INFO] started tweaking git repo https://github.com/wvhulle/forked_stream [INFO] finished tweaking git repo https://github.com/wvhulle/forked_stream [INFO] tweaked toml for git repo https://github.com/wvhulle/forked_stream written to /workspace/builds/worker-6-tc1/source/Cargo.toml [INFO] validating manifest of git repo https://github.com/wvhulle/forked_stream on toolchain cdb45c87e2cd43495379f7e867e3cc15dcee9f93 [INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+cdb45c87e2cd43495379f7e867e3cc15dcee9f93" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }` [INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+cdb45c87e2cd43495379f7e867e3cc15dcee9f93" "generate-lockfile" "--manifest-path" "Cargo.toml", kill_on_drop: false }` [INFO] [stderr] Updating crates.io index [INFO] [stderr] Locking 102 packages to latest Rust 1.91.0-nightly compatible versions [INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+cdb45c87e2cd43495379f7e867e3cc15dcee9f93" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }` [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:7ad1b28ee6f5f7f699f6cf7015098d6ccdd96d6f2d78dd06228f5b4c9faf309c" "/opt/rustwide/cargo-home/bin/cargo" "+cdb45c87e2cd43495379f7e867e3cc15dcee9f93" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }` [INFO] [stdout] e0ef3e77b233c11c67bdd0633310fc3c4c70135f16ea75baf6986a61228d95e1 [INFO] running `Command { std: "docker" "start" "-a" "e0ef3e77b233c11c67bdd0633310fc3c4c70135f16ea75baf6986a61228d95e1", kill_on_drop: false }` [INFO] running `Command { std: "docker" "inspect" "e0ef3e77b233c11c67bdd0633310fc3c4c70135f16ea75baf6986a61228d95e1", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "e0ef3e77b233c11c67bdd0633310fc3c4c70135f16ea75baf6986a61228d95e1", kill_on_drop: false }` [INFO] [stdout] e0ef3e77b233c11c67bdd0633310fc3c4c70135f16ea75baf6986a61228d95e1 [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:7ad1b28ee6f5f7f699f6cf7015098d6ccdd96d6f2d78dd06228f5b4c9faf309c" "/opt/rustwide/cargo-home/bin/cargo" "+cdb45c87e2cd43495379f7e867e3cc15dcee9f93" "build" "--frozen" "--message-format=json", kill_on_drop: false }` [INFO] [stdout] 34e67111e51be891214e0baec76e6fb4a54cb68012ae8dec35273c7170bad98a [INFO] running `Command { std: "docker" "start" "-a" "34e67111e51be891214e0baec76e6fb4a54cb68012ae8dec35273c7170bad98a", kill_on_drop: false }` [INFO] [stderr] Compiling libc v0.2.175 [INFO] [stderr] Compiling futures-core v0.3.31 [INFO] [stderr] Compiling futures-sink v0.3.31 [INFO] [stderr] Compiling slab v0.4.11 [INFO] [stderr] Compiling syn v2.0.106 [INFO] [stderr] Compiling futures-channel v0.3.31 [INFO] [stderr] Compiling num_cpus v1.17.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 10.59s [INFO] running `Command { std: "docker" "inspect" "34e67111e51be891214e0baec76e6fb4a54cb68012ae8dec35273c7170bad98a", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "34e67111e51be891214e0baec76e6fb4a54cb68012ae8dec35273c7170bad98a", kill_on_drop: false }` [INFO] [stdout] 34e67111e51be891214e0baec76e6fb4a54cb68012ae8dec35273c7170bad98a [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:7ad1b28ee6f5f7f699f6cf7015098d6ccdd96d6f2d78dd06228f5b4c9faf309c" "/opt/rustwide/cargo-home/bin/cargo" "+cdb45c87e2cd43495379f7e867e3cc15dcee9f93" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }` [INFO] [stdout] 7df03e0ea7d059853b5458fe6f61268a77fe1b85df33ea378f798a24492d0420 [INFO] running `Command { std: "docker" "start" "-a" "7df03e0ea7d059853b5458fe6f61268a77fe1b85df33ea378f798a24492d0420", kill_on_drop: false }` [INFO] [stderr] Compiling aho-corasick v1.1.3 [INFO] [stderr] Compiling regex-syntax v0.8.6 [INFO] [stderr] Compiling cfg-if v1.0.3 [INFO] [stderr] Compiling futures-channel v0.3.31 [INFO] [stderr] Compiling anstyle-query v1.1.4 [INFO] [stderr] Compiling tokio-macros v2.5.0 [INFO] [stderr] Compiling signal-hook-registry v1.4.6 [INFO] [stderr] Compiling socket2 v0.6.0 [INFO] [stderr] Compiling mio v1.0.4 [INFO] [stderr] Compiling jiff v0.2.15 [INFO] [stderr] Compiling test-log-macros v0.2.18 [INFO] [stderr] Compiling anstream v0.6.20 [INFO] [stderr] Compiling parking_lot_core v0.9.11 [INFO] [stderr] Compiling futures-util v0.3.31 [INFO] [stderr] Compiling parking_lot v0.12.4 [INFO] [stderr] Compiling tokio v1.47.1 [INFO] [stderr] Compiling regex-automata v0.4.10 [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.2 [INFO] [stderr] Compiling env_filter v0.1.3 [INFO] [stderr] Compiling env_logger v0.11.8 [INFO] [stderr] Compiling test-log v0.2.18 [INFO] [stderr] Compiling tokio-stream v0.1.17 [INFO] [stderr] Finished `test` profile [unoptimized + debuginfo] target(s) in 27.35s [INFO] running `Command { std: "docker" "inspect" "7df03e0ea7d059853b5458fe6f61268a77fe1b85df33ea378f798a24492d0420", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "7df03e0ea7d059853b5458fe6f61268a77fe1b85df33ea378f798a24492d0420", kill_on_drop: false }` [INFO] [stdout] 7df03e0ea7d059853b5458fe6f61268a77fe1b85df33ea378f798a24492d0420 [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:7ad1b28ee6f5f7f699f6cf7015098d6ccdd96d6f2d78dd06228f5b4c9faf309c" "/opt/rustwide/cargo-home/bin/cargo" "+cdb45c87e2cd43495379f7e867e3cc15dcee9f93" "test" "--frozen", kill_on_drop: false }` [INFO] [stdout] 242002bc67dc9fc9b510a6108766b18ae14c4d0a0cf5e5836c4de3d81f451645 [INFO] running `Command { std: "docker" "start" "-a" "242002bc67dc9fc9b510a6108766b18ae14c4d0a0cf5e5836c4de3d81f451645", kill_on_drop: false }` [INFO] [stderr] Finished `test` profile [unoptimized + debuginfo] target(s) in 0.12s [INFO] [stderr] Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/clone_stream-3e9ff6027b3a9363) [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/debug/deps/clone_receive-994bc61f5c2983c6) [INFO] [stdout] [INFO] [stdout] running 1 test [INFO] [stderr] [2025-09-01T07:00:06.448311Z /opt/rustwide/workdir/src/fork.rs:74] Registering clone 0. [INFO] [stderr] [2025-09-01T07:00:06.448430Z /opt/rustwide/workdir/src/fork.rs:74] Registering clone 1. [INFO] [stderr] [2025-09-01T07:00:06.479784Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-09-01T07:00:06.479957Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:30] Currently in state 'NeverPolled' [INFO] [stderr] [2025-09-01T07:00:06.480047Z /opt/rustwide/workdir/src/fork.rs:66] Found 1 wakers. [INFO] [stderr] [2025-09-01T07:00:06.480106Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x7b569c00c680, vtable: 0x59d841cd4bc0 } }). [INFO] [stderr] [2025-09-01T07:00:06.480229Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-09-01T07:00:06.480293Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:30] Currently in state 'NeverPolled' [INFO] [stderr] [2025-09-01T07:00:06.480378Z /opt/rustwide/workdir/src/fork.rs:66] Found 2 wakers. [INFO] [stderr] [2025-09-01T07:00:06.480434Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 1 back into the fork with state: QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x7b569c00c800, vtable: 0x59d841cd4bc0 } }). [INFO] [stderr] [2025-09-01T07:00:06.489673Z src/fork.rs:122] Waking up all sleeping clones. [INFO] [stderr] [2025-09-01T07:00:06.489798Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-09-01T07:00:06.489871Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:29] Currently in state 'QueueEmptyThenBasePending [INFO] [stderr] [2025-09-01T07:00:06.489969Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:31] Queue is empty [INFO] [stderr] [2025-09-01T07:00:06.490083Z /opt/rustwide/workdir/src/fork.rs:66] Found 2 wakers. [INFO] [stderr] [2025-09-01T07:00:06.490167Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:42] At least one clone is interested in the new item. [INFO] [stderr] [2025-09-01T07:00:06.490261Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 0 back into the fork with state: QueueEmptyThenBaseReady(QueueEmptyThenBaseReady). [INFO] [stderr] [2025-09-01T07:00:06.490377Z /opt/rustwide/workdir/src/fork.rs:82] Unregistering clone 0. [INFO] [stderr] [2025-09-01T07:00:06.490761Z src/states/mod.rs:58] Checking if state QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x7b569c00c800, vtable: 0x59d841cd4bc0 } }) should still see queue item with index 0 [INFO] [stderr] [2025-09-01T07:00:06.490903Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-09-01T07:00:06.491017Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:29] Currently in state 'QueueEmptyThenBasePending [INFO] [stderr] [2025-09-01T07:00:06.491146Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:76] No other clone is waiting for the first item in the queue. [INFO] [stderr] [2025-09-01T07:00:06.491305Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 1 back into the fork with state: UnseenQueuedItemReady(UnseenQueuedItemReady { unseen_ready_queue_item_index: 0 }). [INFO] [stderr] [2025-09-01T07:00:06.491453Z /opt/rustwide/workdir/src/fork.rs:82] 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/debug/deps/is_terminated-246de3e8f2d83d8c) [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.00s [INFO] [stdout] [INFO] [stdout] [INFO] [stdout] running 1 test [INFO] [stderr] Running tests/late_clone.rs (/opt/rustwide/target/debug/deps/late_clone-45c718b40940ddf5) [INFO] [stderr] [2025-09-01T07:00:06.505003Z /opt/rustwide/workdir/src/fork.rs:74] Registering clone 0. [INFO] [stderr] [2025-09-01T07:00:06.505201Z /opt/rustwide/workdir/src/fork.rs:74] Registering clone 1. [INFO] [stderr] [2025-09-01T07:00:06.536621Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-09-01T07:00:06.536807Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:30] Currently in state 'NeverPolled' [INFO] [stderr] [2025-09-01T07:00:06.536942Z /opt/rustwide/workdir/src/fork.rs:66] Found 1 wakers. [INFO] [stderr] [2025-09-01T07:00:06.537070Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x7c8d9400c680, vtable: 0x59ecbee713e0 } }). [INFO] [stderr] [2025-09-01T07:00:06.537263Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-09-01T07:00:06.537373Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:30] Currently in state 'NeverPolled' [INFO] [stderr] [2025-09-01T07:00:06.537471Z /opt/rustwide/workdir/src/fork.rs:66] Found 2 wakers. [INFO] [stderr] [2025-09-01T07:00:06.537557Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 1 back into the fork with state: QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x7c8d9400c800, vtable: 0x59ecbee713e0 } }). [INFO] [stderr] [2025-09-01T07:00:06.546855Z src/fork.rs:122] Waking up all sleeping clones. [INFO] [stderr] [2025-09-01T07:00:06.547054Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-09-01T07:00:06.547172Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:29] Currently in state 'QueueEmptyThenBasePending [INFO] [stderr] [2025-09-01T07:00:06.547295Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:31] Queue is empty [INFO] [stderr] [2025-09-01T07:00:06.548564Z /opt/rustwide/workdir/src/fork.rs:66] Found 2 wakers. [INFO] [stderr] [2025-09-01T07:00:06.548682Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:42] At least one clone is interested in the new item. [INFO] [stderr] [2025-09-01T07:00:06.548812Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 0 back into the fork with state: QueueEmptyThenBaseReady(QueueEmptyThenBaseReady). [INFO] [stderr] [2025-09-01T07:00:06.548945Z /opt/rustwide/workdir/src/fork.rs:82] Unregistering clone 0. [INFO] [stderr] [2025-09-01T07:00:06.549061Z src/states/mod.rs:58] Checking if state QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x7c8d9400c800, vtable: 0x59ecbee713e0 } }) should still see queue item with index 0 [INFO] [stderr] [2025-09-01T07:00:06.549237Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-09-01T07:00:06.549341Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:29] Currently in state 'QueueEmptyThenBasePending [INFO] [stderr] [2025-09-01T07:00:06.549452Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:76] No other clone is waiting for the first item in the queue. [INFO] [stderr] [2025-09-01T07:00:06.549561Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 1 back into the fork with state: UnseenQueuedItemReady(UnseenQueuedItemReady { unseen_ready_queue_item_index: 0 }). [INFO] [stderr] [2025-09-01T07:00:06.549688Z /opt/rustwide/workdir/src/fork.rs:74] Registering clone 2. [INFO] [stderr] [2025-09-01T07:00:06.555950Z /opt/rustwide/workdir/src/fork.rs:44] Clone 2 is being polled through the fork. [INFO] [stderr] [2025-09-01T07:00:06.556149Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:30] Currently in state 'NeverPolled' [INFO] [stderr] [2025-09-01T07:00:06.556279Z /opt/rustwide/workdir/src/fork.rs:66] Found 1 wakers. [INFO] [stderr] [2025-09-01T07:00:06.556361Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 2 back into the fork with state: QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x7c8d9400c800, vtable: 0x59ecbee713e0 } }). [INFO] [stderr] [2025-09-01T07:00:06.566648Z src/fork.rs:122] Waking up all sleeping clones. [INFO] [stderr] [2025-09-01T07:00:06.566831Z /opt/rustwide/workdir/src/fork.rs:44] Clone 2 is being polled through the fork. [INFO] [stderr] [2025-09-01T07:00:06.566958Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:29] Currently in state 'QueueEmptyThenBasePending [INFO] [stderr] [2025-09-01T07:00:06.567086Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:31] Queue is empty [INFO] [stderr] [2025-09-01T07:00:06.567199Z /opt/rustwide/workdir/src/fork.rs:66] Found 1 wakers. [INFO] [stderr] [2025-09-01T07:00:06.567286Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:46] No other clone is interested in the new item. [INFO] [stderr] [2025-09-01T07:00:06.567393Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 2 back into the fork with state: QueueEmptyThenBaseReady(QueueEmptyThenBaseReady). [INFO] [stderr] [2025-09-01T07:00:06.567502Z /opt/rustwide/workdir/src/fork.rs:82] Unregistering clone 2. [INFO] [stderr] [2025-09-01T07:00:06.567594Z /opt/rustwide/workdir/src/fork.rs:82] 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.07s [INFO] [stdout] [INFO] [stderr] Running tests/late_poll.rs (/opt/rustwide/target/debug/deps/late_poll-75a960eb727c11bf) [INFO] [stdout] [INFO] [stdout] running 2 tests [INFO] [stderr] [2025-09-01T07:00:06.573463Z /opt/rustwide/workdir/src/fork.rs:74] Registering clone 0. [INFO] [stderr] [2025-09-01T07:00:06.573585Z /opt/rustwide/workdir/src/fork.rs:74] Registering clone 1. [INFO] [stderr] [2025-09-01T07:00:06.573602Z /opt/rustwide/workdir/src/fork.rs:74] Registering clone 0. [INFO] [stderr] [2025-09-01T07:00:06.573653Z /opt/rustwide/workdir/src/fork.rs:74] Registering clone 1. [INFO] [stderr] [2025-09-01T07:00:06.604921Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-09-01T07:00:06.604920Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-09-01T07:00:06.605078Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:30] Currently in state 'NeverPolled' [INFO] [stderr] [2025-09-01T07:00:06.605036Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:30] Currently in state 'NeverPolled' [INFO] [stderr] [2025-09-01T07:00:06.605168Z /opt/rustwide/workdir/src/fork.rs:66] Found 1 wakers. [INFO] [stderr] [2025-09-01T07:00:06.605220Z /opt/rustwide/workdir/src/fork.rs:66] Found 1 wakers. [INFO] [stderr] [2025-09-01T07:00:06.605268Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x7c7b24006600, vtable: 0x5e296d26a8a0 } }). [INFO] [stderr] [2025-09-01T07:00:06.605315Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x7c7b2c00c680, vtable: 0x5e296d26a8a0 } }). [INFO] [stderr] [2025-09-01T07:00:06.605436Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-09-01T07:00:06.605596Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:30] Currently in state 'NeverPolled' [INFO] [stderr] [2025-09-01T07:00:06.605666Z /opt/rustwide/workdir/src/fork.rs:66] Found 2 wakers. [INFO] [stderr] [2025-09-01T07:00:06.605728Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 1 back into the fork with state: QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x7c7b24006800, vtable: 0x5e296d26a8a0 } }). [INFO] [stderr] [2025-09-01T07:00:06.614997Z src/fork.rs:122] Waking up all sleeping clones. [INFO] [stderr] [2025-09-01T07:00:06.615192Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-09-01T07:00:06.615295Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:29] Currently in state 'QueueEmptyThenBasePending [INFO] [stderr] [2025-09-01T07:00:06.615377Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:31] Queue is empty [INFO] [stderr] [2025-09-01T07:00:06.615450Z /opt/rustwide/workdir/src/fork.rs:66] Found 2 wakers. [INFO] [stderr] [2025-09-01T07:00:06.615540Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:42] At least one clone is interested in the new item. [INFO] [stderr] [2025-09-01T07:00:06.615619Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 0 back into the fork with state: QueueEmptyThenBaseReady(QueueEmptyThenBaseReady). [INFO] [stderr] [2025-09-01T07:00:06.615746Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-09-01T07:00:06.615812Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:29] Currently in state 'QueueEmptyThenBasePending [INFO] [stderr] [2025-09-01T07:00:06.615888Z src/states/mod.rs:58] Checking if state QueueEmptyThenBaseReady(QueueEmptyThenBaseReady) should still see queue item with index 0 [INFO] [stderr] [2025-09-01T07:00:06.615966Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:76] No other clone is waiting for the first item in the queue. [INFO] [stderr] [2025-09-01T07:00:06.616060Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 1 back into the fork with state: UnseenQueuedItemReady(UnseenQueuedItemReady { unseen_ready_queue_item_index: 0 }). [INFO] [stderr] [2025-09-01T07:00:06.624716Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-09-01T07:00:06.624823Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:30] Currently in state 'NeverPolled' [INFO] [stderr] [2025-09-01T07:00:06.624876Z /opt/rustwide/workdir/src/fork.rs:66] Found 2 wakers. [INFO] [stderr] [2025-09-01T07:00:06.624925Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 1 back into the fork with state: QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x7c7b2c00c880, vtable: 0x5e296d26a8a0 } }). [INFO] [stderr] [2025-09-01T07:00:06.625035Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-09-01T07:00:06.625080Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:29] Currently in state 'QueueEmptyThenBasePending [INFO] [stderr] [2025-09-01T07:00:06.625134Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:31] Queue is empty [INFO] [stderr] [2025-09-01T07:00:06.625182Z /opt/rustwide/workdir/src/fork.rs:66] Found 2 wakers. [INFO] [stderr] [2025-09-01T07:00:06.625221Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x7c7b2c00c680, vtable: 0x5e296d26a8a0 } }). [INFO] [stderr] [2025-09-01T07:00:06.625312Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-09-01T07:00:06.625660Z tests/late_poll.rs:38] Cancelled next() await of adam. [INFO] [stderr] [2025-09-01T07:00:06.625750Z /opt/rustwide/workdir/src/fork.rs:82] Unregistering clone 0. [INFO] [stderr] [2025-09-01T07:00:06.625720Z /opt/rustwide/workdir/src/fork.rs:66] Found 1 wakers. [INFO] [stderr] [2025-09-01T07:00:06.625830Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 1 back into the fork with state: NoUnseenQueuedThenBasePending(NoUnseenQueuedThenBasePending { waker: Waker { data: 0x7c7b24006800, vtable: 0x5e296d26a8a0 }, most_recent_queue_item_index: 0 }). [INFO] [stderr] [2025-09-01T07:00:06.635116Z src/fork.rs:122] Waking up all sleeping clones. [INFO] [stderr] [2025-09-01T07:00:06.635258Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-09-01T07:00:06.635317Z /opt/rustwide/workdir/src/fork.rs:66] Found 1 wakers. [INFO] [stderr] [2025-09-01T07:00:06.635352Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 1 back into the fork with state: NoUnseenQueuedThenBaseReady(NoUnseenQueuedThenBaseReady). [INFO] [stderr] [2025-09-01T07:00:06.635417Z /opt/rustwide/workdir/src/fork.rs:82] Unregistering clone 1. [INFO] [stderr] [2025-09-01T07:00:06.644754Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-09-01T07:00:06.644922Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_ready.rs:24] The queue was empty on last poll of this clone, but the base was ready. [INFO] [stderr] [2025-09-01T07:00:06.645031Z /opt/rustwide/workdir/src/fork.rs:66] Found 1 wakers. [INFO] [stderr] [2025-09-01T07:00:06.645103Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_ready.rs:39] No other clone is interested in the new item. [INFO] [stderr] [2025-09-01T07:00:06.645188Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 0 back into the fork with state: QueueEmptyThenBaseReady(QueueEmptyThenBaseReady). [INFO] [stderr] [2025-09-01T07:00:06.645292Z /opt/rustwide/workdir/src/fork.rs:82] Unregistering clone 0. [INFO] [stdout] test poll_after_send ... ok [INFO] [stderr] [2025-09-01T07:00:06.685126Z src/fork.rs:122] Waking up all sleeping clones. [INFO] [stderr] [2025-09-01T07:00:06.685324Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork. [INFO] [stderr] [2025-09-01T07:00:06.685400Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:29] Currently in state 'QueueEmptyThenBasePending [INFO] [stderr] [2025-09-01T07:00:06.685473Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:31] Queue is empty [INFO] [stderr] [2025-09-01T07:00:06.685569Z /opt/rustwide/workdir/src/fork.rs:66] Found 1 wakers. [INFO] [stderr] [2025-09-01T07:00:06.685630Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:46] No other clone is interested in the new item. [INFO] [stderr] [2025-09-01T07:00:06.685702Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 1 back into the fork with state: QueueEmptyThenBaseReady(QueueEmptyThenBaseReady). [INFO] [stderr] [2025-09-01T07:00:06.685789Z /opt/rustwide/workdir/src/fork.rs:82] 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/debug/deps/queue_len-875daa606f45f795) [INFO] [stdout] [INFO] [stdout] running 1 test [INFO] [stderr] [2025-09-01T07:00:06.694035Z /opt/rustwide/workdir/src/fork.rs:74] Registering clone 0. [INFO] [stderr] [2025-09-01T07:00:06.725510Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-09-01T07:00:06.726564Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:30] Currently in state 'NeverPolled' [INFO] [stderr] [2025-09-01T07:00:06.726686Z /opt/rustwide/workdir/src/fork.rs:66] Found 1 wakers. [INFO] [stderr] [2025-09-01T07:00:06.726763Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x72670400c700, vtable: 0x581a332e00b0 } }). [INFO] [stderr] [2025-09-01T07:00:06.745099Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork. [INFO] [stderr] [2025-09-01T07:00:06.745290Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:29] Currently in state 'QueueEmptyThenBasePending [INFO] [stderr] [2025-09-01T07:00:06.745409Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:31] Queue is empty [INFO] [stderr] [2025-09-01T07:00:06.745507Z /opt/rustwide/workdir/src/fork.rs:66] Found 1 wakers. [INFO] [stderr] [2025-09-01T07:00:06.745619Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x72670400c700, vtable: 0x581a332e00b0 } }). [INFO] [stderr] [2025-09-01T07:00:06.755977Z src/fork.rs:122] Waking up all sleeping clones. [INFO] [stderr] [2025-09-01T07:00:06.765613Z /opt/rustwide/workdir/src/clone.rs:99] Getting the number of queued items for clone 0. [INFO] [stderr] [2025-09-01T07:00:06.765794Z /opt/rustwide/workdir/src/fork.rs:82] 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/debug/deps/size_hint-2d6a2f3bc8f36cdb) [INFO] [stdout] [INFO] [stdout] running 2 tests [INFO] [stdout] test one_clone_size ... ok [INFO] [stdout] test two_clone_size ... ok [INFO] [stdout] [INFO] [stderr] Running tests/stress_test.rs (/opt/rustwide/target/debug/deps/stress_test-27ac04579624d6cc) [INFO] [stdout] test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s [INFO] [stdout] [INFO] [stdout] [INFO] [stdout] running 2 tests [INFO] [stdout] test mass_send_interval ... ok [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.13s [INFO] [stdout] [INFO] [stderr] Running tests/util.rs (/opt/rustwide/target/debug/deps/util-3f001fde7eae1ca8) [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] Doc-tests clone_stream [INFO] [stdout] [INFO] [stdout] running 1 test [INFO] [stdout] test src/lib.rs - ForkStream::fork (line 32) ... ok [INFO] [stdout] [INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s [INFO] [stdout] [INFO] running `Command { std: "docker" "inspect" "242002bc67dc9fc9b510a6108766b18ae14c4d0a0cf5e5836c4de3d81f451645", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "242002bc67dc9fc9b510a6108766b18ae14c4d0a0cf5e5836c4de3d81f451645", kill_on_drop: false }` [INFO] [stdout] 242002bc67dc9fc9b510a6108766b18ae14c4d0a0cf5e5836c4de3d81f451645