Files
buzz/scripts/ci-hermit-retry.test.mjs
Matt Toohey d2c3234cb9 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>
2026-11-10 08:40:05 +11:00

116 lines
3.8 KiB
JavaScript

import assert from "node:assert/strict";
import { spawnSync } from "node:child_process";
import {
chmodSync,
existsSync,
mkdtempSync,
readFileSync,
writeFileSync,
} from "node:fs";
import { tmpdir } from "node:os";
import { join } from "node:path";
import { test } from "node:test";
import { setTimeout as sleep } from "node:timers/promises";
import { fileURLToPath } from "node:url";
const script = fileURLToPath(new URL("./ci-hermit-retry.sh", import.meta.url));
// Run the wrapper on a fake tool that counts its calls, then runs `body` with
// $n set to the call number and $dir to a scratch directory.
function run(body, env = {}) {
const dir = mkdtempSync(join(tmpdir(), "ci-hermit-retry-"));
const calls = join(dir, "calls");
writeFileSync(calls, "");
const tool = join(dir, "tool");
writeFileSync(
tool,
`#!/bin/bash
dir="${dir}"
echo call >> "$dir/calls"
n=$(( $(wc -l < "$dir/calls") ))
${body}
`,
);
chmodSync(tool, 0o755);
const started = Date.now();
const result = spawnSync("bash", [script, tool], {
encoding: "utf8",
timeout: 20_000,
env: {
...process.env,
CI_HERMIT_ATTEMPT_SECONDS: "1",
CI_HERMIT_KILL_AFTER_SECONDS: "1",
CI_HERMIT_BACKOFF_SECONDS: "0",
...env,
},
});
return {
dir,
status: result.status,
seconds: (Date.now() - started) / 1000,
calls: readFileSync(calls, "utf8").split("\n").filter(Boolean).length,
stdout: result.stdout,
};
}
test("a first-attempt success runs the tool once and keeps its output", () => {
const r = run("echo v1.2.3");
assert.equal(r.status, 0);
assert.equal(r.calls, 1);
assert.equal(r.stdout, "v1.2.3\n");
});
// A stalled download: the first call hangs on a child that would write a
// marker at 2s if it outlived the attempt's 1s deadline.
test("a stalled attempt is stopped with its children and retried", async () => {
const r = run(`
if [ "$n" -eq 1 ]; then
( sleep 2; touch "$dir/survived" ) &
wait
fi
echo fetched`);
assert.equal(r.status, 0, r.stdout);
assert.equal(r.calls, 2);
assert.match(r.stdout, /::warning::attempt 1\/3 timed out after 1s/);
assert.match(r.stdout, /fetched\n$/);
assert.ok(r.seconds < 10, `took ${r.seconds}s`);
await sleep(Math.max(0, 3000 - r.seconds * 1000));
assert.ok(
!existsSync(join(r.dir, "survived")),
"the stalled attempt's child outlived it",
);
});
test("an attempt that ignores TERM is killed", () => {
const r = run("trap '' TERM; sleep 30", { CI_HERMIT_ATTEMPTS: "1" });
assert.equal(r.status, 1, r.stdout);
assert.match(r.stdout, /attempt 1\/1 timed out after 1s/);
assert.ok(r.seconds < 10, `took ${r.seconds}s`);
});
test("persistent failure backs off between attempts and stops at the budget", () => {
const r = run("exit 7", { CI_HERMIT_BACKOFF_SECONDS: "1" });
assert.equal(r.status, 1);
assert.equal(r.calls, 3);
assert.match(r.stdout, /attempt 3\/3 failed \(exit 7\)/);
assert.match(r.stdout, /::error::all 3 attempts failed/);
// Backoff sleeps 1s after attempt 1 and 2s after attempt 2.
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);
});