fix(ci): classify hermit retry timeouts by watchdog kill, not whole seconds (#9274)

## 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 <mtoohey@squareup.com>
Co-authored-by: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
Matt Toohey
2026-11-10 08:40:05 +11:00
committed by GitHub
parent ea548da808
commit d2c3234cb9
2 changed files with 23 additions and 3 deletions

View File

@@ -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): $*"

View File

@@ -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);
});