From d2c3234cb9829962627a70366d406489059f1816 Mon Sep 17 00:00:00 2001 From: Matt Toohey Date: Tue, 10 Nov 2026 08:40:05 +1100 Subject: [PATCH] fix(ci): classify hermit retry timeouts by watchdog kill, not whole seconds (#9274) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ## Summary Split out of the `flakey-monday` flake-fix series. `scripts/ci-hermit-retry.sh` decided an attempt had "timed out" by comparing whole-second elapsed time with the deadline, so an instant failure that straddled a second boundary was misreported as a timeout. The watchdog now reports through its exit status whether it actually killed the attempt. Commit (cherry-picked from `flakey-monday`, original message kept): - `fix(ci): report a hermit retry timeout only when the watchdog fired` ### Root cause and fix **node:test "persistent failure backs off between attempts and stops at the budget"** (`scripts/ci-hermit-retry.test.mjs`): expected "attempt 3/3 failed (exit 7)" and got "attempt 3/3 timed out after 1s". - Root cause (confirmed): the script checked `$((SECONDS - started)) -ge deadline`. Bash's `$SECONDS` counts whole wall-clock seconds, and the test uses a 1 s deadline (`CI_HERMIT_ATTEMPT_SECONDS=1`). An instant `exit 7` that crossed a second boundary looked like it had run for the whole deadline. - Fix: the watchdog subshell exits 0 if it is stopped before signalling the attempt, and 124 once it has sent TERM (or TERM then KILL). The script reports a timeout only when the watchdog exits 124; elapsed time is no longer used. Bash 3.2 (macOS) supports this. A new test starts 0.8 s into a wall-clock second and runs a 0.4 s attempt that exits 7, so it crosses a second boundary but finishes well inside its 1 s deadline, and asserts it is reported as "failed (exit 7)". ### Related issue N/A (flake fix; none found). ### Testing Human testing is still required. This PR does not carry `buzz-review-completed`; the author has not yet run the script or its tests themselves on this branch. #### Verification Verified locally on the `flakey-monday` branch before the split: - The new test against the old script: failed with "attempt 1/1 timed out after 1s", the CI symptom. - The whole `ci-hermit-retry.test.mjs` suite with the fix: 20/20 passed. Nothing was re-run on this split branch: the workstation was overloaded, so no tests, builds or linters were executed after cherry-picking. CI on this PR is the verification for the split branch. 🤖 Generated with [Claude Code](https://claude.com/claude-code) Signed-off-by: mtoohey Co-authored-by: Claude Opus 5.5 --- scripts/ci-hermit-retry.sh | 14 +++++++++++--- scripts/ci-hermit-retry.test.mjs | 12 ++++++++++++ 2 files changed, 23 insertions(+), 3 deletions(-) diff --git a/scripts/ci-hermit-retry.sh b/scripts/ci-hermit-retry.sh index b3d9795e68..5ac7668d45 100755 --- a/scripts/ci-hermit-retry.sh +++ b/scripts/ci-hermit-retry.sh @@ -55,25 +55,33 @@ for attempt in $(seq 1 "$attempts"); do set -m "$@" & pid=$! + # The watchdog exits 0 if stopped before it signals the attempt and 124 once + # it has, so a timeout is reported only when the watchdog really stopped the + # attempt. Elapsed time cannot tell: $SECONDS counts whole wall-clock + # seconds, so an instant failure that straddled a second boundary looked + # like it had run for the whole 1s deadline. ( + trap 'exit 0' TERM sleep "$deadline" + trap 'exit 124' TERM kill -TERM -- "-$pid" 2>/dev/null || exit 0 sleep "$kill_after" kill -KILL -- "-$pid" 2>/dev/null || true + exit 124 ) >/dev/null 2>&1 & watchdog=$! set +m - started=$SECONDS rc=0 # Bash reports a job killed by a signal on wait's stderr; the warning below # says the same thing. wait "$pid" 2>/dev/null || rc=$? kill -- "-$watchdog" 2>/dev/null || true - wait "$watchdog" 2>/dev/null || true + watchdog_rc=0 + wait "$watchdog" 2>/dev/null || watchdog_rc=$? [ "$rc" -eq 0 ] && exit 0 # The leader can exit on TERM while a child that ignores it lives on. kill -KILL -- "-$pid" 2>/dev/null || true - if [ $((SECONDS - started)) -ge "$deadline" ]; then + if [ "$watchdog_rc" -eq 124 ]; then echo "::warning::attempt $attempt/$attempts timed out after ${deadline}s: $*" else echo "::warning::attempt $attempt/$attempts failed (exit $rc): $*" diff --git a/scripts/ci-hermit-retry.test.mjs b/scripts/ci-hermit-retry.test.mjs index 14fff2fa4f..7eb131fc1f 100644 --- a/scripts/ci-hermit-retry.test.mjs +++ b/scripts/ci-hermit-retry.test.mjs @@ -98,6 +98,18 @@ test("persistent failure backs off between attempts and stops at the budget", () assert.ok(r.seconds >= 3, `took ${r.seconds}s`); }); +// A quick failure that straddles a wall-clock second boundary is still a +// failure: only the watchdog stopping the attempt makes it a timeout. Start +// 0.8s into a second so the 0.4s attempt crosses the next boundary while +// finishing well inside its 1s deadline. +test("a quick failure across a second boundary is not a timeout", async () => { + await sleep((1800 - (Date.now() % 1000)) % 1000); + const r = run("sleep 0.4; exit 7", { CI_HERMIT_ATTEMPTS: "1" }); + assert.equal(r.status, 1, r.stdout); + assert.match(r.stdout, /attempt 1\/1 failed \(exit 7\)/); + assert.doesNotMatch(r.stdout, /timed out/); +}); + test("no command is a usage error", () => { assert.equal(spawnSync("bash", [script]).status, 2); });