mirror of
https://github.com/block/buzz.git
synced 2026-11-10 19:32:00 +00:00
## 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>
116 lines
3.8 KiB
JavaScript
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);
|
|
});
|