From 024d9b4d755600a4664c247f35991a869092a34c Mon Sep 17 00:00:00 2001 From: Maximilian Roos Date: Sun, 23 Aug 2026 08:41:24 -0700 Subject: [PATCH 1/4] fix(shell_exec): stream rather than fail when delayed_stream's timed wait fails Phase 1's `Err` arm returned to the caller after joining the reader threads, and those sit in `read_to_end` until the child closes its pipes -- so the caller waited out the child's full runtime and then got `Failed to wait for command` for a command that had already finished. The arm became reachable in #3857: `shared_child` allocates a pipe and registers a SIGCHLD handler on every timed wait, where `wait-timeout` set its self-pipe up once per process, so a sandbox or an fd limit now surfaces as `Err` where it used to surface as the abort of #3856. It now falls through to streaming, like an exceeded threshold. Phase 2's `wait()` is a bare `waitid(WNOWAIT)` loop with neither a pipe nor a signal registration, so whatever broke the timed wait can't reach it and the real exit status still comes back. The wall-clock sites tear the child down instead, because a wait they can't observe bounds nothing; the module docstring records that split. `test_cmd_delayed_stream_crosses_the_threshold` covers the fall-through, which no test reached before: the suite's thresholds are `0`, which streams without calling `wait_timeout`, and `-1`, which skips phase 1. --- src/shell_exec.rs | 51 ++++++++++++++++++++++++++++++++++++++++------- 1 file changed, 44 insertions(+), 7 deletions(-) diff --git a/src/shell_exec.rs b/src/shell_exec.rs index 53fcfc17d..2116bb57f 100644 --- a/src/shell_exec.rs +++ b/src/shell_exec.rs @@ -65,6 +65,16 @@ //! wakeup costs at worst a wait that runs to its deadline, which is what a //! deadline is for. It also probes the wake fd and falls back to `write()` on a //! pipe, so the syscall that sandbox denies is not even on the path. +//! +//! **When the timed wait itself fails.** Setting a deadline is fallible — each +//! call allocates a pipe and registers a handler — so each site decides what a +//! failed `wait_timeout` means instead of propagating it. Where the deadline +//! bounds wall-clock (`run_with_timeout_impl`, the pager) the site tears the +//! child down, because a wait it cannot observe bounds nothing. Where it only +//! decides when output starts streaming ([`Cmd::delayed_stream`]) the site +//! streams. No site fails the command: a denied syscall in wt's own machinery +//! is not the child's fault, and erroring over one repeats #3856 in a quieter +//! form. use std::collections::BTreeSet; use std::ffi::{OsStr, OsString}; @@ -2215,13 +2225,17 @@ impl Cmd { trace.complete(status.success()); return stream_exit_result(status, &buffer, &cmd_str); } - // Threshold exceeded — fall through to streaming. - Ok(None) => {} - Err(e) => { - let _ = stdout_handle.join(); - let _ = stderr_handle.join(); - trace.fail(&e); - return Err(e).context("Failed to wait for command"); + // No status yet: the threshold passed, or the timed wait + // itself failed. Both fall through to streaming. A failed + // wait means the deadline machinery broke — `sigchld` + // allocates a pipe and registers a handler per call, which + // a sandbox or an fd limit can deny — not that the child + // misbehaved, and Phase 2's `wait()` is a bare `waitid` + // with neither, so it still returns the real status. + // Failing here would turn a denied syscall into a failed + // command, which is the shape of #3856. + outcome => { + tracing::debug!(?outcome, "No exit status yet; switching to streaming"); } } } @@ -2912,6 +2926,29 @@ mod tests { Cmd::new("true").delayed_stream(5_000, None).unwrap(); } + #[test] + #[cfg(unix)] + fn test_cmd_delayed_stream_crosses_the_threshold() { + // A command that outlives the threshold leaves phase 1 with no status + // (`wait_timeout` returns `Ok(None)`) and switches to streaming. Phase 2 + // must then wait out the real exit rather than reporting at the + // threshold — the elapsed time is what distinguishes the two, since both + // return `Ok`. + // + // The other two thresholds skip this path entirely: `0` streams without + // waiting, `-1` disables phase 1. + let start = Instant::now(); + Cmd::new("sleep") + .arg("0.3") + .delayed_stream(50, None) + .unwrap(); + let elapsed = start.elapsed(); + assert!( + elapsed >= Duration::from_millis(300), + "phase 2 must wait for the child, not return at the threshold: {elapsed:?}" + ); + } + #[test] #[cfg(unix)] fn test_cmd_delayed_stream_streams_then_reports_failure() { From 760042a2be5a523e3b1c00a4d58768d3f475f297 Mon Sep 17 00:00:00 2001 From: Maximilian Roos Date: Sun, 23 Aug 2026 08:46:04 -0700 Subject: [PATCH 2/4] test(shell_exec): pin the threshold switch by where the late output goes The first version asserted elapsed time, which a phase-1 `Ok(Some)` satisfies just as well: the child runs the same wall-clock either way, so the assertion held whether or not the arm under test was taken. A line the child writes after the switch is the discriminator. Streaming sends it to stderr, so the error's buffer is empty; had phase 1 returned a status, `late` would still be buffered. Raising the threshold above the child's runtime fails the assertion with `left: "late"`. --- src/shell_exec.rs | 31 +++++++++++++++++-------------- 1 file changed, 17 insertions(+), 14 deletions(-) diff --git a/src/shell_exec.rs b/src/shell_exec.rs index 2116bb57f..b0eac7e6d 100644 --- a/src/shell_exec.rs +++ b/src/shell_exec.rs @@ -2930,22 +2930,25 @@ mod tests { #[cfg(unix)] fn test_cmd_delayed_stream_crosses_the_threshold() { // A command that outlives the threshold leaves phase 1 with no status - // (`wait_timeout` returns `Ok(None)`) and switches to streaming. Phase 2 - // must then wait out the real exit rather than reporting at the - // threshold — the elapsed time is what distinguishes the two, since both - // return `Ok`. + // (`wait_timeout` returns `Ok(None)`), which switches the readers to + // streaming, and phase 2 then reports the real exit. // - // The other two thresholds skip this path entirely: `0` streams without - // waiting, `-1` disables phase 1. - let start = Instant::now(); - Cmd::new("sleep") - .arg("0.3") + // What pins the switch is where the late output goes: a streamed line + // is written to stderr instead of the buffer, so the error carries + // none of it. Had phase 1 returned a status instead, `late` would + // still be buffered and would show up here. The other thresholds never + // reach this arm — `0` streams without waiting, `-1` skips phase 1. + let err = Cmd::new("sh") + .args(["-c", "sleep 0.2; echo late 1>&2; exit 3"]) .delayed_stream(50, None) - .unwrap(); - let elapsed = start.elapsed(); - assert!( - elapsed >= Duration::from_millis(300), - "phase 2 must wait for the child, not return at the threshold: {elapsed:?}" + .unwrap_err(); + let stream_err = err + .downcast_ref::() + .expect("non-zero delayed_stream exit should be a StreamCommandError"); + assert_eq!(stream_err.exit_info, "exit code 3"); + assert_eq!( + stream_err.output, "", + "output written after the switch must stream, not buffer" ); } From 1f47bfd8172dba643b55c9c018b0c77786d6994f Mon Sep 17 00:00:00 2001 From: Maximilian Roos Date: Sun, 23 Aug 2026 08:59:00 -0700 Subject: [PATCH 3/4] docs(shell_exec): drop the one-trigger gloss on the progress message A failed timed wait now starts streaming too, so naming the threshold as the moment it prints describes one of two triggers. The module docstring above already records when each happens. --- src/shell_exec.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/shell_exec.rs b/src/shell_exec.rs index b0eac7e6d..925d51efa 100644 --- a/src/shell_exec.rs +++ b/src/shell_exec.rs @@ -2141,7 +2141,7 @@ impl Cmd { /// to never switch to streaming (always buffer); `0` streams immediately. /// /// `progress_message`, when set, prints to stderr at the moment streaming - /// starts (the delay threshold is crossed). + /// starts. /// /// Like [`Cmd::stream`], this does **not** acquire the concurrency /// semaphore: a delayed-stream command runs in the foreground and would From 10e4fd34b9692c0d8b3a31598750632e750033bb Mon Sep 17 00:00:00 2001 From: Maximilian Roos Date: Sun, 23 Aug 2026 09:03:47 -0700 Subject: [PATCH 4/4] test(shell_exec): widen the margin between the switch and the late write 150 ms between the threshold and the child's echo races the scheduler, which tests/CLAUDE.md warns against; 450 ms covers a deschedule longer than the suite produces. The threshold stays at 50 ms rather than shrinking: a spent `remaining` skips the wait, and the test would then pass without reaching the arm it covers. --- src/shell_exec.rs | 10 +++++++++- 1 file changed, 9 insertions(+), 1 deletion(-) diff --git a/src/shell_exec.rs b/src/shell_exec.rs index 925d51efa..2715ba290 100644 --- a/src/shell_exec.rs +++ b/src/shell_exec.rs @@ -2938,8 +2938,16 @@ mod tests { // none of it. Had phase 1 returned a status instead, `late` would // still be buffered and would show up here. The other thresholds never // reach this arm — `0` streams without waiting, `-1` skips phase 1. + // + // The child writes 450 ms after the threshold passes. Only the switch + // has to land in that window, and it follows the wait immediately, so + // the margin covers a deschedule far longer than anything the suite + // produces. The threshold stays well above zero for the opposite + // reason: were `remaining` to reach it already spent, phase 1 would + // skip the wait entirely and the test would pass without reaching the + // arm it exists to cover. let err = Cmd::new("sh") - .args(["-c", "sleep 0.2; echo late 1>&2; exit 3"]) + .args(["-c", "sleep 0.5; echo late 1>&2; exit 3"]) .delayed_stream(50, None) .unwrap_err(); let stream_err = err