[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 try#b83b707f97d809763b7861afa7638871f3339a33 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-tc2/source", kill_on_drop: false }`
[INFO] [stderr] Cloning into '/workspace/builds/worker-6-tc2/source'...
[INFO] [stderr] done.
[INFO] removed /workspace/builds/worker-6-tc2/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-tc2/source/Cargo.toml
[INFO] validating manifest of git repo https://github.com/wvhulle/forked_stream on toolchain b83b707f97d809763b7861afa7638871f3339a33
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+b83b707f97d809763b7861afa7638871f3339a33" "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" "+b83b707f97d809763b7861afa7638871f3339a33" "generate-lockfile" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] [stderr]     Updating crates.io index
[INFO] [stderr]     Blocking waiting for file lock on package cache
[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" "+b83b707f97d809763b7861afa7638871f3339a33" "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-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-6-tc2/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" "+b83b707f97d809763b7861afa7638871f3339a33" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] 90bb88e63aa528b2dea24ab73583b21a6dcea4be5a45c47a74a5c4fda302fe39
[INFO] running `Command { std: "docker" "start" "-a" "90bb88e63aa528b2dea24ab73583b21a6dcea4be5a45c47a74a5c4fda302fe39", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "90bb88e63aa528b2dea24ab73583b21a6dcea4be5a45c47a74a5c4fda302fe39", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "90bb88e63aa528b2dea24ab73583b21a6dcea4be5a45c47a74a5c4fda302fe39", kill_on_drop: false }`
[INFO] [stdout] 90bb88e63aa528b2dea24ab73583b21a6dcea4be5a45c47a74a5c4fda302fe39
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-6-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-6-tc2/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" "+b83b707f97d809763b7861afa7638871f3339a33" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 55be53cfbef727a5dfb9c735f566e6bf665d3fe71a2a58315f40e09ba40e1260
[INFO] running `Command { std: "docker" "start" "-a" "55be53cfbef727a5dfb9c735f566e6bf665d3fe71a2a58315f40e09ba40e1260", 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.44s
[INFO] running `Command { std: "docker" "inspect" "55be53cfbef727a5dfb9c735f566e6bf665d3fe71a2a58315f40e09ba40e1260", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "55be53cfbef727a5dfb9c735f566e6bf665d3fe71a2a58315f40e09ba40e1260", kill_on_drop: false }`
[INFO] [stdout] 55be53cfbef727a5dfb9c735f566e6bf665d3fe71a2a58315f40e09ba40e1260
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-6-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-6-tc2/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" "+b83b707f97d809763b7861afa7638871f3339a33" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 06d4b53540262fdc9c915a9c68c8ed9ecf2c47afa545263cc979b3e88550771c
[INFO] running `Command { std: "docker" "start" "-a" "06d4b53540262fdc9c915a9c68c8ed9ecf2c47afa545263cc979b3e88550771c", kill_on_drop: false }`
[INFO] [stderr]    Compiling regex-syntax v0.8.6
[INFO] [stderr]    Compiling aho-corasick v1.1.3
[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 jiff v0.2.15
[INFO] [stderr]    Compiling socket2 v0.6.0
[INFO] [stderr]    Compiling signal-hook-registry v1.4.6
[INFO] [stderr]    Compiling mio v1.0.4
[INFO] [stderr]    Compiling tokio-macros v2.5.0
[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 parking_lot v0.12.4
[INFO] [stderr]    Compiling futures-util v0.3.31
[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 tokio-stream v0.1.17
[INFO] [stderr]    Compiling env_logger v0.11.8
[INFO] [stderr]    Compiling test-log v0.2.18
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 25.90s
[INFO] running `Command { std: "docker" "inspect" "06d4b53540262fdc9c915a9c68c8ed9ecf2c47afa545263cc979b3e88550771c", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "06d4b53540262fdc9c915a9c68c8ed9ecf2c47afa545263cc979b3e88550771c", kill_on_drop: false }`
[INFO] [stdout] 06d4b53540262fdc9c915a9c68c8ed9ecf2c47afa545263cc979b3e88550771c
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-6-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-6-tc2/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" "+b83b707f97d809763b7861afa7638871f3339a33" "test" "--frozen", kill_on_drop: false }`
[INFO] [stdout] c6d0e4dfddfea8805dbeab811f684092889a36c1b0a0bfed7ba13e25f18b4267
[INFO] running `Command { std: "docker" "start" "-a" "c6d0e4dfddfea8805dbeab811f684092889a36c1b0a0bfed7ba13e25f18b4267", kill_on_drop: false }`
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 0.11s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/clone_stream-3e9ff6027b3a9363)
[INFO] [stderr]      Running tests/clone_receive.rs (/opt/rustwide/target/debug/deps/clone_receive-994bc61f5c2983c6)
[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] [stdout] 
[INFO] [stderr] [2025-09-01T07:00:51.937328Z /opt/rustwide/workdir/src/fork.rs:74] Registering clone 0.
[INFO] [stdout] running 1 test
[INFO] [stderr] [2025-09-01T07:00:51.937462Z /opt/rustwide/workdir/src/fork.rs:74] Registering clone 1.
[INFO] [stderr] [2025-09-01T07:00:51.968853Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork.
[INFO] [stderr] [2025-09-01T07:00:51.969036Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:30] Currently in state 'NeverPolled'
[INFO] [stderr] [2025-09-01T07:00:51.969125Z /opt/rustwide/workdir/src/fork.rs:66] Found 1 wakers.
[INFO] [stderr] [2025-09-01T07:00:51.969207Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x7bce8400c680, vtable: 0x55e85bc77ed8 } }).
[INFO] [stderr] [2025-09-01T07:00:51.969368Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork.
[INFO] [stderr] [2025-09-01T07:00:51.969457Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:30] Currently in state 'NeverPolled'
[INFO] [stderr] [2025-09-01T07:00:51.969551Z /opt/rustwide/workdir/src/fork.rs:66] Found 2 wakers.
[INFO] [stderr] [2025-09-01T07:00:51.969631Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 1 back into the fork with state: QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x7bce8400c800, vtable: 0x55e85bc77ed8 } }).
[INFO] [stderr] [2025-09-01T07:00:51.978943Z src/fork.rs:122] Waking up all sleeping clones.
[INFO] [stderr] [2025-09-01T07:00:51.979140Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork.
[INFO] [stderr] [2025-09-01T07:00:51.979231Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:29] Currently in state 'QueueEmptyThenBasePending
[INFO] [stderr] [2025-09-01T07:00:51.979314Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:31] Queue is empty
[INFO] [stderr] [2025-09-01T07:00:51.979398Z /opt/rustwide/workdir/src/fork.rs:66] Found 2 wakers.
[INFO] [stderr] [2025-09-01T07:00:51.979454Z /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:51.979563Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 0 back into the fork with state: QueueEmptyThenBaseReady(QueueEmptyThenBaseReady).
[INFO] [stderr] [2025-09-01T07:00:51.979650Z /opt/rustwide/workdir/src/fork.rs:82] Unregistering clone 0.
[INFO] [stderr] [2025-09-01T07:00:51.979738Z src/states/mod.rs:58] Checking if state QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x7bce8400c800, vtable: 0x55e85bc77ed8 } }) should still see queue item with index 0
[INFO] [stderr] [2025-09-01T07:00:51.979864Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork.
[INFO] [stderr] [2025-09-01T07:00:51.979927Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:29] Currently in state 'QueueEmptyThenBasePending
[INFO] [stderr] [2025-09-01T07:00:51.980013Z /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:51.980088Z /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:51.980183Z /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.05s
[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 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/debug/deps/late_clone-45c718b40940ddf5)
[INFO] [stdout] 
[INFO] [stderr] [2025-09-01T07:00:51.995832Z /opt/rustwide/workdir/src/fork.rs:74] Registering clone 0.
[INFO] [stdout] running 1 test
[INFO] [stderr] [2025-09-01T07:00:51.995965Z /opt/rustwide/workdir/src/fork.rs:74] Registering clone 1.
[INFO] [stderr] [2025-09-01T07:00:52.027645Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork.
[INFO] [stderr] [2025-09-01T07:00:52.027755Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:30] Currently in state 'NeverPolled'
[INFO] [stderr] [2025-09-01T07:00:52.027813Z /opt/rustwide/workdir/src/fork.rs:66] Found 1 wakers.
[INFO] [stderr] [2025-09-01T07:00:52.027869Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x7fca9c00c680, vtable: 0x595ea84ca6f8 } }).
[INFO] [stderr] [2025-09-01T07:00:52.027980Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork.
[INFO] [stderr] [2025-09-01T07:00:52.028032Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:30] Currently in state 'NeverPolled'
[INFO] [stderr] [2025-09-01T07:00:52.028086Z /opt/rustwide/workdir/src/fork.rs:66] Found 2 wakers.
[INFO] [stderr] [2025-09-01T07:00:52.028132Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 1 back into the fork with state: QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x7fca9c00c800, vtable: 0x595ea84ca6f8 } }).
[INFO] [stderr] [2025-09-01T07:00:52.037413Z src/fork.rs:122] Waking up all sleeping clones.
[INFO] [stderr] [2025-09-01T07:00:52.037559Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork.
[INFO] [stderr] [2025-09-01T07:00:52.037624Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:29] Currently in state 'QueueEmptyThenBasePending
[INFO] [stderr] [2025-09-01T07:00:52.037681Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:31] Queue is empty
[INFO] [stderr] [2025-09-01T07:00:52.037737Z /opt/rustwide/workdir/src/fork.rs:66] Found 2 wakers.
[INFO] [stderr] [2025-09-01T07:00:52.037781Z /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:52.037831Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 0 back into the fork with state: QueueEmptyThenBaseReady(QueueEmptyThenBaseReady).
[INFO] [stderr] [2025-09-01T07:00:52.037916Z /opt/rustwide/workdir/src/fork.rs:82] Unregistering clone 0.
[INFO] [stderr] [2025-09-01T07:00:52.037966Z src/states/mod.rs:58] Checking if state QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x7fca9c00c800, vtable: 0x595ea84ca6f8 } }) should still see queue item with index 0
[INFO] [stderr] [2025-09-01T07:00:52.038073Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork.
[INFO] [stderr] [2025-09-01T07:00:52.038119Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:29] Currently in state 'QueueEmptyThenBasePending
[INFO] [stderr] [2025-09-01T07:00:52.039744Z /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:52.039897Z /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:52.040015Z /opt/rustwide/workdir/src/fork.rs:74] Registering clone 2.
[INFO] [stderr] [2025-09-01T07:00:52.047334Z /opt/rustwide/workdir/src/fork.rs:44] Clone 2 is being polled through the fork.
[INFO] [stderr] [2025-09-01T07:00:52.047519Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:30] Currently in state 'NeverPolled'
[INFO] [stderr] [2025-09-01T07:00:52.047632Z /opt/rustwide/workdir/src/fork.rs:66] Found 1 wakers.
[INFO] [stderr] [2025-09-01T07:00:52.047703Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 2 back into the fork with state: QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x7fca9c00c800, vtable: 0x595ea84ca6f8 } }).
[INFO] [stderr] [2025-09-01T07:00:52.056999Z src/fork.rs:122] Waking up all sleeping clones.
[INFO] [stderr] [2025-09-01T07:00:52.057219Z /opt/rustwide/workdir/src/fork.rs:44] Clone 2 is being polled through the fork.
[INFO] [stderr] [2025-09-01T07:00:52.057343Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:29] Currently in state 'QueueEmptyThenBasePending
[INFO] [stderr] [2025-09-01T07:00:52.057417Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:31] Queue is empty
[INFO] [stderr] [2025-09-01T07:00:52.057486Z /opt/rustwide/workdir/src/fork.rs:66] Found 1 wakers.
[INFO] [stderr] [2025-09-01T07:00:52.057580Z /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:52.057654Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 2 back into the fork with state: QueueEmptyThenBaseReady(QueueEmptyThenBaseReady).
[INFO] [stderr] [2025-09-01T07:00:52.057744Z /opt/rustwide/workdir/src/fork.rs:82] Unregistering clone 2.
[INFO] [stderr] [2025-09-01T07:00:52.057801Z /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.06s
[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:52.062985Z /opt/rustwide/workdir/src/fork.rs:74] Registering clone 0.
[INFO] [stderr] [2025-09-01T07:00:52.063112Z /opt/rustwide/workdir/src/fork.rs:74] Registering clone 1.
[INFO] [stderr] [2025-09-01T07:00:52.094417Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork.
[INFO] [stderr] [2025-09-01T07:00:52.095196Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:30] Currently in state 'NeverPolled'
[INFO] [stderr] [2025-09-01T07:00:52.095283Z /opt/rustwide/workdir/src/fork.rs:66] Found 1 wakers.
[INFO] [stderr] [2025-09-01T07:00:52.095327Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x71de1000c680, vtable: 0x5be505a77bb8 } }).
[INFO] [stderr] [2025-09-01T07:00:52.095596Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork.
[INFO] [stderr] [2025-09-01T07:00:52.095661Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:30] Currently in state 'NeverPolled'
[INFO] [stderr] [2025-09-01T07:00:52.095704Z /opt/rustwide/workdir/src/fork.rs:66] Found 1 wakers.
[INFO] [stderr] [2025-09-01T07:00:52.095736Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x71de18006500, vtable: 0x5be505a77bb8 } }).
[INFO] [stderr] [2025-09-01T07:00:52.095819Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork.
[INFO] [stderr] [2025-09-01T07:00:52.095854Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:30] Currently in state 'NeverPolled'
[INFO] [stderr] [2025-09-01T07:00:52.095894Z /opt/rustwide/workdir/src/fork.rs:66] Found 2 wakers.
[INFO] [stderr] [2025-09-01T07:00:52.095925Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 1 back into the fork with state: QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x71de18006700, vtable: 0x5be505a77bb8 } }).
[INFO] [stderr] [2025-09-01T07:00:52.105646Z src/fork.rs:122] Waking up all sleeping clones.
[INFO] [stderr] [2025-09-01T07:00:52.105761Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork.
[INFO] [stderr] [2025-09-01T07:00:52.105815Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:29] Currently in state 'QueueEmptyThenBasePending
[INFO] [stderr] [2025-09-01T07:00:52.105866Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:31] Queue is empty
[INFO] [stderr] [2025-09-01T07:00:52.105913Z /opt/rustwide/workdir/src/fork.rs:66] Found 2 wakers.
[INFO] [stderr] [2025-09-01T07:00:52.105950Z /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:52.106011Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 0 back into the fork with state: QueueEmptyThenBaseReady(QueueEmptyThenBaseReady).
[INFO] [stderr] [2025-09-01T07:00:52.106092Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork.
[INFO] [stderr] [2025-09-01T07:00:52.106131Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:29] Currently in state 'QueueEmptyThenBasePending
[INFO] [stderr] [2025-09-01T07:00:52.106178Z src/states/mod.rs:58] Checking if state QueueEmptyThenBaseReady(QueueEmptyThenBaseReady) should still see queue item with index 0
[INFO] [stderr] [2025-09-01T07:00:52.106228Z /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:52.106282Z /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:52.114633Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork.
[INFO] [stderr] [2025-09-01T07:00:52.114734Z /opt/rustwide/workdir/src/fork.rs:66] Found 1 wakers.
[INFO] [stderr] [2025-09-01T07:00:52.114778Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 1 back into the fork with state: NoUnseenQueuedThenBasePending(NoUnseenQueuedThenBasePending { waker: Waker { data: 0x71de18006700, vtable: 0x5be505a77bb8 }, most_recent_queue_item_index: 0 }).
[INFO] [stderr] [2025-09-01T07:00:52.114622Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork.
[INFO] [stderr] [2025-09-01T07:00:52.115195Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:30] Currently in state 'NeverPolled'
[INFO] [stderr] [2025-09-01T07:00:52.115249Z /opt/rustwide/workdir/src/fork.rs:66] Found 2 wakers.
[INFO] [stderr] [2025-09-01T07:00:52.115284Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 1 back into the fork with state: QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x71de1000c880, vtable: 0x5be505a77bb8 } }).
[INFO] [stderr] [2025-09-01T07:00:52.115375Z tests/late_poll.rs:38] Cancelled next() await of adam.
[INFO] [stderr] [2025-09-01T07:00:52.115408Z /opt/rustwide/workdir/src/fork.rs:82] Unregistering clone 0.
[INFO] [stderr] [2025-09-01T07:00:52.126644Z src/fork.rs:122] Waking up all sleeping clones.
[INFO] [stderr] [2025-09-01T07:00:52.126771Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork.
[INFO] [stderr] [2025-09-01T07:00:52.126828Z /opt/rustwide/workdir/src/fork.rs:66] Found 1 wakers.
[INFO] [stderr] [2025-09-01T07:00:52.126864Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 1 back into the fork with state: NoUnseenQueuedThenBaseReady(NoUnseenQueuedThenBaseReady).
[INFO] [stderr] [2025-09-01T07:00:52.126925Z /opt/rustwide/workdir/src/fork.rs:82] Unregistering clone 1.
[INFO] [stdout] test poll_after_send ... ok
[INFO] [stderr] [2025-09-01T07:00:52.141671Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork.
[INFO] [stderr] [2025-09-01T07:00:52.141777Z /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:52.141846Z /opt/rustwide/workdir/src/fork.rs:66] Found 1 wakers.
[INFO] [stderr] [2025-09-01T07:00:52.141887Z /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:52.141939Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 0 back into the fork with state: QueueEmptyThenBaseReady(QueueEmptyThenBaseReady).
[INFO] [stderr] [2025-09-01T07:00:52.142027Z /opt/rustwide/workdir/src/fork.rs:82] Unregistering clone 0.
[INFO] [stdout] test poll_before_send ... ok
[INFO] [stderr] [2025-09-01T07:00:52.177647Z src/fork.rs:122] Waking up all sleeping clones.
[INFO] [stdout] 
[INFO] [stderr] [2025-09-01T07:00:52.177779Z /opt/rustwide/workdir/src/fork.rs:44] Clone 1 is being polled through the fork.
[INFO] [stdout] test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.12s
[INFO] [stderr] [2025-09-01T07:00:52.177829Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:29] Currently in state 'QueueEmptyThenBasePending
[INFO] [stdout] 
[INFO] [stderr] [2025-09-01T07:00:52.177880Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:31] Queue is empty
[INFO] [stderr] [2025-09-01T07:00:52.177927Z /opt/rustwide/workdir/src/fork.rs:66] Found 1 wakers.
[INFO] [stderr] [2025-09-01T07:00:52.177964Z /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:52.178024Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 1 back into the fork with state: QueueEmptyThenBaseReady(QueueEmptyThenBaseReady).
[INFO] [stderr] [2025-09-01T07:00:52.178093Z /opt/rustwide/workdir/src/fork.rs:82] Unregistering clone 1.
[INFO] [stderr]      Running tests/queue_len.rs (/opt/rustwide/target/debug/deps/queue_len-875daa606f45f795)
[INFO] [stdout] 
[INFO] [stderr] [2025-09-01T07:00:52.183007Z /opt/rustwide/workdir/src/fork.rs:74] Registering clone 0.
[INFO] [stdout] running 1 test
[INFO] [stderr] [2025-09-01T07:00:52.214407Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork.
[INFO] [stderr] [2025-09-01T07:00:52.214940Z /opt/rustwide/workdir/src/states/cold_queue/never_polled.rs:30] Currently in state 'NeverPolled'
[INFO] [stderr] [2025-09-01T07:00:52.215146Z /opt/rustwide/workdir/src/fork.rs:66] Found 1 wakers.
[INFO] [stderr] [2025-09-01T07:00:52.215569Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x7c17f800c700, vtable: 0x64a2012941f8 } }).
[INFO] [stderr] [2025-09-01T07:00:52.234367Z /opt/rustwide/workdir/src/fork.rs:44] Clone 0 is being polled through the fork.
[INFO] [stderr] [2025-09-01T07:00:52.234605Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:29] Currently in state 'QueueEmptyThenBasePending
[INFO] [stderr] [2025-09-01T07:00:52.234769Z /opt/rustwide/workdir/src/states/cold_queue/queue_empty_then_base_pending.rs:31] Queue is empty
[INFO] [stderr] [2025-09-01T07:00:52.234900Z /opt/rustwide/workdir/src/fork.rs:66] Found 1 wakers.
[INFO] [stderr] [2025-09-01T07:00:52.235048Z /opt/rustwide/workdir/src/fork.rs:52] Inserting clone 0 back into the fork with state: QueueEmptyThenBasePending(QueueEmptyThenBasePending { waker: Waker { data: 0x7c17f800c700, vtable: 0x64a2012941f8 } }).
[INFO] [stderr] [2025-09-01T07:00:52.244476Z src/fork.rs:122] Waking up all sleeping clones.
[INFO] [stderr] [2025-09-01T07:00:52.254049Z /opt/rustwide/workdir/src/clone.rs:99] Getting the number of queued items for clone 0.
[INFO] [stderr] [2025-09-01T07:00:52.254245Z /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] [stderr]      Running tests/stress_test.rs (/opt/rustwide/target/debug/deps/stress_test-27ac04579624d6cc)
[INFO] [stdout] running 2 tests
[INFO] [stdout] test one_clone_size ... ok
[INFO] [stdout] test two_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] [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.16s
[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" "c6d0e4dfddfea8805dbeab811f684092889a36c1b0a0bfed7ba13e25f18b4267", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "c6d0e4dfddfea8805dbeab811f684092889a36c1b0a0bfed7ba13e25f18b4267", kill_on_drop: false }`
[INFO] [stdout] c6d0e4dfddfea8805dbeab811f684092889a36c1b0a0bfed7ba13e25f18b4267