From caf29632128191e6994fe210eed1b5813c06611e Mon Sep 17 00:00:00 2001 From: Jakob Heuser Date: Mon, 21 Sep 2026 17:29:46 -0700 Subject: [PATCH 1/3] chore(ci): move the Vale upgrade wait loops into a tested script --- .github/scripts/vale-upgrade-wait.cjs | 409 +++++++++++++++++ .github/scripts/vale-upgrade-wait.test.cjs | 486 +++++++++++++++++++++ .github/workflows/vale-upgrade.yml | 137 ++---- 3 files changed, 931 insertions(+), 101 deletions(-) create mode 100644 .github/scripts/vale-upgrade-wait.cjs create mode 100644 .github/scripts/vale-upgrade-wait.test.cjs diff --git a/.github/scripts/vale-upgrade-wait.cjs b/.github/scripts/vale-upgrade-wait.cjs new file mode 100644 index 00000000..0e282453 --- /dev/null +++ b/.github/scripts/vale-upgrade-wait.cjs @@ -0,0 +1,409 @@ +#!/usr/bin/env node +// SPDX-License-Identifier: MIT +"use strict"; + +/** + * Vale — wait out the publish race before the upgrade detects anything. + * + * THE PUBLISH RACE. vale-upgrade.yml fires on the same push to main that fires + * release-vale.yml: the merge of a manifest change. Starting together is also + * the problem. release-vale.yml has to fetch, verify, pack, and publish six + * packages before the registry can answer "what is published" with the new + * set, and vale-upgrade-detect.cjs asks the registry. Measured on 3.22.0: the + * manifest merged at 18:09:13Z, the publish run started three seconds later, + * the packages were stamped 18:09:30 — and an upgrade run started at 18:09 + * would have compared the pins against the OLD latest, found nothing to do, + * and exited clean. Before the push trigger existed, the daily cron noticed + * that publish thirteen hours after the packages were on npm. + * + * This script is the two waits that close that gap, in order: + * + * 1. waitForReleaseRun — hold until the `Release Vale` run for THIS commit + * has concluded. `gh run list --commit` is exact, so a publish run for a + * different manifest commit (an earlier release still draining) is never + * mistaken for this one. Polls every 30 s for up to 25 minutes; on 3.22.0 + * the run had stamped the packages 14 s after it started, so the bound is + * for a queued runner, not for the work. + * + * 2. waitForRegistry — `npm publish` returning is not the same as the + * registry's packument serving the new dist-tag; that propagates, usually + * in seconds, occasionally longer. Ask the registry the exact question + * the detect step is about to ask, with the same script and no side + * effects (`--json` alone, which the script refuses to combine with + * `--write`), up to five times a minute apart. + * + * EVERY EXIT IS 0. A publish that concludes anything but success, one that + * never appears inside the bound, a registry that still says "current" at the + * end: each is a `::warning::` and a clean exit, never a failed check. This + * workflow must not go red over a race it did not cause, and a red here would + * say "the upgrade is broken" when the truth is "the publish is". The daily + * schedule in vale-upgrade.yml retries once the packages are actually there, + * which is what a backstop is for. + * + * What the workflow learns is the `ready` output: whether the detect step + * should run at all. It is "true" when the registry serves a newer set, and + * "false" when waiting established there is nothing to upgrade to yet. + * + * TWO CASES ARE "true" WITHOUT A NEWER SET, on purpose: + * + * - A run that is not a `push` has no publish to wait for: its commit is + * whatever main is, and the run list for that commit is empty by + * construction, so waiting would only burn the bound. Both waits are + * skipped and detect runs against whatever the registry serves. + * + * - A probe that ERRORS on every attempt is kept apart from one that + * answers "current". The detect script prints its error to stderr and + * nothing to stdout, so reading its stdout alone would take a registry + * outage for "still the old version" and the closing warning would blame + * propagation for something else. An error that persists is not this + * script's to report: the detect step runs the same code next and fails + * loudly on it, which is right — a broken registry read is a real + * failure, not the race. + * + * Usage: + * node .github/scripts/vale-upgrade-wait.cjs + * [--workflow ] [--timeout-minutes ] [--poll-seconds ] + * [--attempts ] [--interval-seconds ] + * + * Reads GITHUB_EVENT_NAME and GITHUB_SHA. `gh` needs GH_TOKEN with + * `actions: read`. + * + * Outputs (appended to $GITHUB_OUTPUT when set): + * ready "true" when the detect step should run + * outcome one word saying why: ahead | skipped | publish-failed | + * publish-unfinished | registry-stale | probe-errored + */ + +const { execFileSync } = require("node:child_process"); +const { appendFileSync } = require("node:fs"); +const { join } = require("node:path"); + +const RELEASE_WORKFLOW = "release-vale.yml"; +const DETECT_SCRIPT = join(__dirname, "vale-upgrade-detect.cjs"); + +const MINUTE = 60 * 1000; +const SECOND = 1000; + +const DEFAULTS = { + timeoutMs: 25 * MINUTE, + pollMs: 30 * SECOND, + attempts: 5, + intervalMs: 60 * SECOND, +}; + +function setOutput(key, value, env = process.env) { + const file = env.GITHUB_OUTPUT; + if (file) { + appendFileSync(file, `${key}=${value}\n`); + } +} + +function parseArgs(argv) { + const read = (name, fallback, scale = 1) => { + const at = argv.indexOf(name); + if (at === -1) { + return typeof fallback === "number" ? fallback * scale : fallback; + } + const value = argv[at + 1]; + if (value === undefined || value.startsWith("--")) { + throw new Error(`${name} needs a value`); + } + if (typeof fallback === "number") { + const number = Number(value); + if (!Number.isFinite(number) || number <= 0) { + throw new Error(`${name} needs a positive number, got ${value}`); + } + return number * scale; + } + return value; + }; + return { + workflow: read("--workflow", RELEASE_WORKFLOW), + timeoutMs: read("--timeout-minutes", DEFAULTS.timeoutMs / MINUTE, MINUTE), + pollMs: read("--poll-seconds", DEFAULTS.pollMs / SECOND, SECOND), + attempts: read("--attempts", DEFAULTS.attempts), + intervalMs: read( + "--interval-seconds", + DEFAULTS.intervalMs / SECOND, + SECOND + ), + }; +} + +/** + * `gh` as an argv array, never through a shell. A non-zero exit becomes a + * thrown Error carrying stderr, which the poll loop treats as "not yet + * registered": one rate-limited or 5xx'd call in fifty polls must not end the + * wait, let alone the run. + */ +function runGh(args) { + try { + return execFileSync("gh", args, { + encoding: "utf8", + stdio: ["ignore", "pipe", "pipe"], + }); + } catch (error) { + const detail = error.stderr?.toString().trim() || error.message; + throw new Error(`gh ${args.join(" ")} failed: ${detail}`); + } +} + +/** + * The detect script in a child process rather than in-process, for two + * reasons: its stderr passes straight through, so "see the error above" in the + * log is literally true; and its own $GITHUB_OUTPUT writes stay out of THIS + * step's outputs, which would otherwise pick up a stray `update=false`. + */ +function probeRegistry() { + const env = { ...process.env }; + delete env.GITHUB_OUTPUT; + const stdout = execFileSync(process.execPath, [DETECT_SCRIPT, "--json"], { + encoding: "utf8", + env, + stdio: ["ignore", "pipe", "inherit"], + }); + return JSON.parse(stdout.trim()); +} + +const sleepFor = (ms) => new Promise((resolve) => setTimeout(resolve, ms)); + +/** `gh run list --json status,conclusion` as a list of {status, conclusion}. */ +function parseRuns(stdout) { + const runs = JSON.parse(stdout.trim() || "[]"); + if (!Array.isArray(runs)) { + throw new TypeError(`gh run list returned ${typeof runs}, not an array`); + } + return runs.map(({ status, conclusion }) => ({ + status: status ?? "", + conclusion: conclusion ?? "", + })); +} + +const describeRuns = (runs) => + runs.map((run) => `${run.status}/${run.conclusion || "-"}`).join("; "); + +/** + * Hold until every `Release Vale` run for `sha` has concluded. + * + * Resolves to `{ outcome: "succeeded" | "failed" | "timeout", runs }`, never + * rejects on a `gh` failure: a failed call is logged and polled again exactly + * like "not yet registered", and a call that fails until the deadline is a + * timeout. The run list can lag the push by a few seconds, so an empty answer + * is also "not yet". + */ +async function waitForReleaseRun({ + sha, + workflow = RELEASE_WORKFLOW, + timeoutMs = DEFAULTS.timeoutMs, + intervalMs = DEFAULTS.pollMs, + runGh: gh = runGh, + sleep = sleepFor, + log = (line) => console.log(line), + now = Date.now, +}) { + if (!sha) { + throw new Error("waitForReleaseRun needs the commit sha to look for"); + } + const deadline = now() + timeoutMs; + let runs = []; + let lastError; + + for (;;) { + let state; + try { + runs = parseRuns( + gh([ + "run", + "list", + "--workflow", + workflow, + "--event", + "push", + "--commit", + sha, + "--json", + "status,conclusion", + ]) + ); + lastError = undefined; + state = runs.length === 0 ? "not yet registered" : describeRuns(runs); + } catch (error) { + runs = []; + lastError = error; + state = `${error.message}; treating as not yet registered`; + } + + if ( + !lastError && + runs.length > 0 && + runs.every((run) => run.status === "completed") + ) { + const outcome = runs.every((run) => run.conclusion === "success") + ? "succeeded" + : "failed"; + return { outcome, runs }; + } + + if (now() >= deadline) { + return { + outcome: "timeout", + runs, + detail: lastError + ? `the last gh call failed: ${lastError.message}` + : runs.length === 0 + ? "no run found" + : describeRuns(runs), + }; + } + + log( + `Release Vale for ${sha}: ${state}; retrying in ${intervalMs / SECOND} s.` + ); + await sleep(intervalMs); + } +} + +/** + * Hold until the registry serves a newer set than the pins. + * + * Resolves to `{ outcome: "ahead" | "stale" | "probe-errored", ... }`. "stale" + * means at least one probe answered and the answer was "current" every time it + * did; "probe-errored" means no probe answered at all, which is a different + * fact and is reported as one. + */ +async function waitForRegistry({ + attempts = DEFAULTS.attempts, + intervalMs = DEFAULTS.intervalMs, + probe = probeRegistry, + sleep = sleepFor, + log = (line) => console.log(line), +}) { + let answered = 0; + for (let attempt = 1; attempt <= attempts; attempt += 1) { + try { + const comparison = await probe(); + answered += 1; + if (comparison.ahead === true) { + log( + `The registry serves a newer set than the pins: ${JSON.stringify(comparison)}` + ); + return { outcome: "ahead", comparison, attempt }; + } + log( + `The registry still serves the pinned version (attempt ${attempt} of ${attempts}): ${JSON.stringify(comparison)}` + ); + } catch (error) { + log( + `The registry probe failed (attempt ${attempt} of ${attempts}): ${error.message}` + ); + } + if (attempt < attempts) { + log(`Retrying in ${intervalMs / SECOND} s.`); + await sleep(intervalMs); + } + } + return { + outcome: answered === 0 ? "probe-errored" : "stale", + attempts, + answered, + }; +} + +async function main({ + argv = process.argv.slice(2), + env = process.env, + runGh: gh = runGh, + probe = probeRegistry, + sleep = sleepFor, + log = (line) => console.log(line), + now = Date.now, +} = {}) { + const options = parseArgs(argv); + const finish = (ready, outcome) => { + setOutput("ready", String(ready), env); + setOutput("outcome", outcome, env); + return { ready, outcome }; + }; + + const event = env.GITHUB_EVENT_NAME; + if (event !== "push") { + log( + `A ${event ?? "local"} run has no Release Vale run to wait for; detect runs against whatever the registry serves.` + ); + return finish(true, "skipped"); + } + + const sha = env.GITHUB_SHA; + if (!sha) { + throw new Error("GITHUB_SHA must be set on a push"); + } + + const release = await waitForReleaseRun({ + sha, + workflow: options.workflow, + timeoutMs: options.timeoutMs, + intervalMs: options.pollMs, + runGh: gh, + sleep, + log, + now, + }); + if (release.outcome === "failed") { + log( + `::warning::the Release Vale run for ${sha} did not succeed (${describeRuns(release.runs)}); nothing to upgrade to yet. The daily schedule will retry once a publish lands.` + ); + return finish(false, "publish-failed"); + } + if (release.outcome === "timeout") { + log( + `::warning::gave up waiting for the Release Vale run for ${sha} after ${options.timeoutMs / MINUTE} minutes (${release.detail}). The daily schedule will retry.` + ); + return finish(false, "publish-unfinished"); + } + log(`Release Vale succeeded for ${sha}.`); + + const registry = await waitForRegistry({ + attempts: options.attempts, + intervalMs: options.intervalMs, + probe, + sleep, + log, + }); + if (registry.outcome === "ahead") { + return finish(true, "ahead"); + } + if (registry.outcome === "stale") { + log( + `::warning::no probe in ${registry.attempts} attempts after the publish succeeded reported a newer set than the pins; each attempt is logged above with its result. The daily schedule will retry.` + ); + return finish(false, "registry-stale"); + } + log( + `::warning::every one of ${registry.attempts} registry probes failed after the publish succeeded; the detect step runs the same read next and fails the run if it persists.` + ); + return finish(true, "probe-errored"); +} + +// Exported so vale-upgrade-wait.test.cjs can drive each wait with `gh`, the +// probe, and the clock replaced, and main() end to end the same way. +module.exports = { + DEFAULTS, + main, + parseArgs, + parseRuns, + waitForRegistry, + waitForReleaseRun, +}; + +if (require.main === module) { + main().catch((error) => { + // Still exit 0. A wait that cannot run must not also suppress the + // upgrade, so the detect step is told to go ahead — the behaviour before + // the wait existed — and the failure is a warning in the log. + console.log( + `::warning::vale-upgrade-wait failed: ${error.message}; running detect without waiting.` + ); + setOutput("ready", "true"); + setOutput("outcome", "wait-errored"); + }); +} diff --git a/.github/scripts/vale-upgrade-wait.test.cjs b/.github/scripts/vale-upgrade-wait.test.cjs new file mode 100644 index 00000000..275fad44 --- /dev/null +++ b/.github/scripts/vale-upgrade-wait.test.cjs @@ -0,0 +1,486 @@ +// SPDX-License-Identifier: MIT +"use strict"; + +/** + * Tests for vale-upgrade-wait.cjs — the two waits between the manifest push + * and the upgrade's registry read. + * + * The property under test is the one the workflow promises in its comments: + * no outcome here fails the run. So every case asserts on the warning and on + * the `ready` output, and the cases that matter most are the ones a stubbed + * `gh` that only varied its ANSWER would never reach — a `gh` that errors, and + * a probe that throws. Time is a fake clock advanced by the injected `sleep`, + * so the 25-minute bound costs nothing to hit. + */ + +const test = require("node:test"); +const assert = require("node:assert/strict"); +const { mkdtempSync, readFileSync, rmSync } = require("node:fs"); +const { tmpdir } = require("node:os"); +const { join } = require("node:path"); + +const { + DEFAULTS, + main, + parseArgs, + parseRuns, + waitForRegistry, + waitForReleaseRun, +} = require("./vale-upgrade-wait.cjs"); + +const SHA = "0123456789abcdef0123456789abcdef01234567"; + +/** A fake clock: `sleep` advances it instead of waiting. */ +function clock() { + let at = 1_000_000; + const slept = []; + return { + now: () => at, + sleep: async (ms) => { + slept.push(ms); + at += ms; + }, + slept, + }; +} + +/** + * A `gh` that answers from a script of results in order and repeats the last + * one. An Error entry is thrown, which is how the real runner reports a + * non-zero exit. + */ +function ghScript(results) { + const calls = []; + const gh = (args) => { + calls.push(args); + const result = results[Math.min(calls.length - 1, results.length - 1)]; + if (result instanceof Error) { + throw result; + } + return JSON.stringify(result); + }; + return { gh, calls }; +} + +/** A probe answering from a script the same way. */ +function probeScript(results) { + let calls = 0; + const probe = async () => { + const result = results[Math.min(calls, results.length - 1)]; + calls += 1; + if (result instanceof Error) { + throw result; + } + return result; + }; + return { probe, count: () => calls }; +} + +const queued = { status: "queued", conclusion: null }; +const inProgress = { status: "in_progress", conclusion: null }; +const succeeded = { status: "completed", conclusion: "success" }; +const failed = { status: "completed", conclusion: "failure" }; + +const stale = { pinned: "3.21.0-1", upstream: "3.21.0-1", ahead: false }; +const ahead = { pinned: "3.21.0-1", upstream: "3.22.0-2", ahead: true }; + +test("parseRuns reads gh's JSON and tolerates a null conclusion", () => { + assert.deepEqual(parseRuns("[]"), []); + assert.deepEqual(parseRuns("\n"), []); + assert.deepEqual(parseRuns(JSON.stringify([inProgress, succeeded])), [ + { status: "in_progress", conclusion: "" }, + { status: "completed", conclusion: "success" }, + ]); + assert.throws(() => parseRuns("{}"), /not an array/); +}); + +test("parseArgs scales the flags into milliseconds and keeps the defaults", () => { + assert.deepEqual(parseArgs([]), { + workflow: "release-vale.yml", + timeoutMs: DEFAULTS.timeoutMs, + pollMs: DEFAULTS.pollMs, + attempts: DEFAULTS.attempts, + intervalMs: DEFAULTS.intervalMs, + }); + const options = parseArgs([ + "--workflow", + "other.yml", + "--timeout-minutes", + "2", + "--poll-seconds", + "5", + "--attempts", + "3", + "--interval-seconds", + "10", + ]); + assert.equal(options.workflow, "other.yml"); + assert.equal(options.timeoutMs, 120_000); + assert.equal(options.pollMs, 5_000); + assert.equal(options.attempts, 3); + assert.equal(options.intervalMs, 10_000); + assert.throws(() => parseArgs(["--attempts"]), /needs a value/); + assert.throws(() => parseArgs(["--attempts", "0"]), /positive number/); +}); + +test("release run: registers late, then succeeds", async () => { + const time = clock(); + const { gh, calls } = ghScript([[], [], [queued], [inProgress], [succeeded]]); + const result = await waitForReleaseRun({ + sha: SHA, + runGh: gh, + sleep: time.sleep, + now: time.now, + log: () => {}, + }); + assert.equal(result.outcome, "succeeded"); + assert.equal(calls.length, 5); + assert.deepEqual(time.slept, Array(4).fill(DEFAULTS.pollMs)); + // Exact commit, this workflow, push event: a run for another manifest commit + // still draining must never be mistaken for this one. + assert.deepEqual(calls[0], [ + "run", + "list", + "--workflow", + "release-vale.yml", + "--event", + "push", + "--commit", + SHA, + "--json", + "status,conclusion", + ]); +}); + +test("release run: a failed run is reported, not waited on further", async () => { + const time = clock(); + const { gh } = ghScript([[inProgress], [failed]]); + const result = await waitForReleaseRun({ + sha: SHA, + runGh: gh, + sleep: time.sleep, + now: time.now, + log: () => {}, + }); + assert.equal(result.outcome, "failed"); + assert.deepEqual(result.runs, [ + { status: "completed", conclusion: "failure" }, + ]); +}); + +test("release run: a run that never registers times out at the bound", async () => { + const time = clock(); + const { gh, calls } = ghScript([[]]); + const result = await waitForReleaseRun({ + sha: SHA, + runGh: gh, + sleep: time.sleep, + now: time.now, + log: () => {}, + }); + assert.equal(result.outcome, "timeout"); + assert.equal(result.detail, "no run found"); + // 25 minutes at 30 s: fifty sleeps, fifty-one polls, and the total slept + // time is exactly the bound. + assert.equal(time.slept.length, 50); + assert.equal(calls.length, 51); + assert.equal( + time.slept.reduce((sum, ms) => sum + ms, 0), + DEFAULTS.timeoutMs + ); +}); + +test("release run: gh errors twice, then the run is found and succeeds", async () => { + const time = clock(); + const logged = []; + const { gh } = ghScript([ + new Error("gh run list failed: HTTP 502"), + new Error("gh run list failed: API rate limit exceeded"), + [succeeded], + ]); + const result = await waitForReleaseRun({ + sha: SHA, + runGh: gh, + sleep: time.sleep, + now: time.now, + log: (line) => logged.push(line), + }); + assert.equal(result.outcome, "succeeded"); + assert.equal(time.slept.length, 2); + assert.match(logged[0], /HTTP 502; treating as not yet registered/); + assert.match( + logged[1], + /rate limit exceeded; treating as not yet registered/ + ); +}); + +test("release run: gh that always errors is a timeout naming the error", async () => { + const time = clock(); + const { gh } = ghScript([new Error("gh run list failed: HTTP 503")]); + const result = await waitForReleaseRun({ + sha: SHA, + runGh: gh, + sleep: time.sleep, + now: time.now, + log: () => {}, + }); + assert.equal(result.outcome, "timeout"); + assert.match(result.detail, /the last gh call failed: .*HTTP 503/); + assert.equal(time.slept.length, 50); +}); + +test("release run: a stale earlier answer does not survive a gh error", async () => { + // Registered and in progress, then gh breaks for good: the timeout must say + // gh failed, not describe the run it saw before it did. + const time = clock(); + const { gh } = ghScript([[inProgress], new Error("gh run list failed: 500")]); + const result = await waitForReleaseRun({ + sha: SHA, + runGh: gh, + sleep: time.sleep, + now: time.now, + log: () => {}, + }); + assert.equal(result.outcome, "timeout"); + assert.deepEqual(result.runs, []); + assert.match(result.detail, /the last gh call failed/); +}); + +test("release run: waits while any run for the commit is still going", async () => { + const time = clock(); + const { gh } = ghScript([ + [succeeded, inProgress], + [succeeded, succeeded], + ]); + const result = await waitForReleaseRun({ + sha: SHA, + runGh: gh, + sleep: time.sleep, + now: time.now, + log: () => {}, + }); + assert.equal(result.outcome, "succeeded"); + assert.equal(time.slept.length, 1); +}); + +test("registry: ahead after two stale probes", async () => { + const time = clock(); + const { probe, count } = probeScript([stale, stale, ahead]); + const result = await waitForRegistry({ + probe, + sleep: time.sleep, + log: () => {}, + }); + assert.equal(result.outcome, "ahead"); + assert.equal(result.attempt, 3); + assert.deepEqual(result.comparison, ahead); + assert.equal(count(), 3); + assert.deepEqual(time.slept, [DEFAULTS.intervalMs, DEFAULTS.intervalMs]); +}); + +test("registry: a probe that throws every time is 'probe-errored', not 'stale'", async () => { + const time = clock(); + const logged = []; + const { probe, count } = probeScript([ + new Error("GET https://registry.npmjs.org/x responded 503"), + ]); + const result = await waitForRegistry({ + probe, + sleep: time.sleep, + log: (line) => logged.push(line), + }); + assert.equal(result.outcome, "probe-errored"); + assert.equal(result.answered, 0); + assert.equal(count(), DEFAULTS.attempts); + // Four sleeps between five attempts; no pointless wait after the last. + assert.equal(time.slept.length, DEFAULTS.attempts - 1); + assert.equal( + logged.filter((line) => + /probe failed \(attempt \d of 5\): .*503/.test(line) + ).length, + DEFAULTS.attempts + ); +}); + +test("registry: never ahead is 'stale'", async () => { + const time = clock(); + const { probe } = probeScript([stale]); + const result = await waitForRegistry({ + probe, + sleep: time.sleep, + log: () => {}, + }); + assert.equal(result.outcome, "stale"); + assert.equal(result.answered, DEFAULTS.attempts); +}); + +test("registry: one answer among errors is still 'stale'", async () => { + const time = clock(); + const { probe } = probeScript([ + new Error("503"), + stale, + new Error("503"), + new Error("503"), + new Error("503"), + ]); + const result = await waitForRegistry({ + probe, + sleep: time.sleep, + log: () => {}, + }); + assert.equal(result.outcome, "stale"); + assert.equal(result.answered, 1); +}); + +/** Drive main() with everything injected and read back $GITHUB_OUTPUT. */ +async function run({ event = "push", gh, probe, argv = [] }) { + const directory = mkdtempSync(join(tmpdir(), "vale-upgrade-wait-test-")); + const outputPath = join(directory, "github-output"); + const time = clock(); + const logged = []; + try { + const result = await main({ + argv, + env: { + GITHUB_EVENT_NAME: event, + GITHUB_SHA: SHA, + GITHUB_OUTPUT: outputPath, + }, + runGh: gh ?? ghScript([[succeeded]]).gh, + probe: probe ?? probeScript([ahead]).probe, + sleep: time.sleep, + now: time.now, + log: (line) => logged.push(line), + }); + let outputs = {}; + try { + outputs = Object.fromEntries( + readFileSync(outputPath, "utf8") + .trim() + .split("\n") + .map((line) => line.split("=")) + ); + } catch { + // nothing written + } + return { + result, + outputs, + logged, + warnings: logged.filter((line) => line.startsWith("::warning::")), + slept: time.slept, + }; + } finally { + rmSync(directory, { recursive: true, force: true }); + } +} + +test("main: publish succeeded and the registry is ahead -> ready=true", async () => { + const { outputs, warnings } = await run({ + gh: ghScript([[], [inProgress], [succeeded]]).gh, + probe: probeScript([stale, ahead]).probe, + }); + assert.deepEqual(outputs, { ready: "true", outcome: "ahead" }); + assert.deepEqual(warnings, []); +}); + +test("main: publish failed -> warning, ready=false, registry never probed", async () => { + const probed = probeScript([ahead]); + const { outputs, warnings } = await run({ + gh: ghScript([[failed]]).gh, + probe: probed.probe, + }); + assert.deepEqual(outputs, { ready: "false", outcome: "publish-failed" }); + assert.equal(warnings.length, 1); + assert.match( + warnings[0], + new RegExp( + `Release Vale run for ${SHA} did not succeed \\(completed/failure\\)` + ) + ); + assert.match(warnings[0], /daily schedule will retry/); + assert.equal(probed.count(), 0); +}); + +test("main: publish never registers -> warning after the bound, ready=false", async () => { + const { outputs, warnings, slept } = await run({ + gh: ghScript([[]]).gh, + }); + assert.deepEqual(outputs, { ready: "false", outcome: "publish-unfinished" }); + assert.equal(warnings.length, 1); + assert.match( + warnings[0], + /gave up waiting .* after 25 minutes \(no run found\)/ + ); + assert.equal(slept.length, 50); +}); + +test("main: gh errors twice, then succeeds -> no warning", async () => { + const { outputs, warnings } = await run({ + gh: ghScript([new Error("502"), new Error("502"), [succeeded]]).gh, + }); + assert.deepEqual(outputs, { ready: "true", outcome: "ahead" }); + assert.deepEqual(warnings, []); +}); + +test("main: gh always errors -> warning naming the error, ready=false", async () => { + const { outputs, warnings } = await run({ + gh: ghScript([new Error("gh run list failed: HTTP 503")]).gh, + }); + assert.deepEqual(outputs, { ready: "false", outcome: "publish-unfinished" }); + assert.match(warnings[0], /the last gh call failed: .*HTTP 503/); +}); + +test("main: registry ahead after two probes -> ready=true", async () => { + const { outputs, warnings, slept } = await run({ + probe: probeScript([stale, ahead]).probe, + }); + assert.deepEqual(outputs, { ready: "true", outcome: "ahead" }); + assert.deepEqual(warnings, []); + assert.deepEqual(slept, [DEFAULTS.intervalMs]); +}); + +test("main: probe throws every time -> warning, but ready=true so detect fails loudly", async () => { + const { outputs, warnings } = await run({ + probe: probeScript([new Error("503")]).probe, + }); + assert.deepEqual(outputs, { ready: "true", outcome: "probe-errored" }); + assert.equal(warnings.length, 1); + assert.match(warnings[0], /every one of 5 registry probes failed/); + assert.match(warnings[0], /detect step runs the same read next/); +}); + +test("main: probe never ahead -> warning, ready=false", async () => { + const { outputs, warnings } = await run({ + probe: probeScript([stale]).probe, + }); + assert.deepEqual(outputs, { ready: "false", outcome: "registry-stale" }); + assert.equal(warnings.length, 1); + assert.match(warnings[0], /no probe in 5 attempts .* reported a newer set/); +}); + +test("main: a non-push event skips both waits with ready=true", async () => { + for (const event of ["schedule", "workflow_dispatch"]) { + const gh = ghScript([[]]); + const probed = probeScript([stale]); + const { outputs, warnings, slept } = await run({ + event, + gh: gh.gh, + probe: probed.probe, + }); + assert.deepEqual(outputs, { ready: "true", outcome: "skipped" }); + assert.deepEqual(warnings, []); + assert.equal(gh.calls.length, 0); + assert.equal(probed.count(), 0); + assert.deepEqual(slept, []); + } +}); + +test("main: flags shorten the bounds", async () => { + const { slept, outputs } = await run({ + argv: ["--timeout-minutes", "1", "--poll-seconds", "20", "--attempts", "2"], + gh: ghScript([[]]).gh, + }); + assert.deepEqual(outputs, { ready: "false", outcome: "publish-unfinished" }); + assert.deepEqual(slept, [20_000, 20_000, 20_000]); +}); diff --git a/.github/workflows/vale-upgrade.yml b/.github/workflows/vale-upgrade.yml index fb226898..2ba0eb4b 100644 --- a/.github/workflows/vale-upgrade.yml +++ b/.github/workflows/vale-upgrade.yml @@ -76,10 +76,10 @@ on: # Measured on 3.22.0: the manifest merged at 18:09:13Z, the publish run # started three seconds later, the packages were stamped 18:09:30 — and a run # of this workflow started at 18:09 would have compared the pins against the - # OLD latest, found nothing to do, and exited clean. The two wait steps - # before detect exist for that: the first holds until the `Release Vale` run - # for this same commit has concluded, the second holds until the registry - # actually serves a newer set. Neither can fail the run; see below. + # OLD latest, found nothing to do, and exited clean. The wait step before + # detect exists for that: vale-upgrade-wait.cjs holds until the `Release + # Vale` run for this same commit has concluded, then until the registry + # actually serves a newer set. It cannot fail the run; see below. push: branches: [main] paths: @@ -119,107 +119,38 @@ jobs: with: node-version-file: .nvmrc - # THE PUBLISH RACE, first half. On a push this run and the `Release Vale` - # run for the same commit started within seconds of each other, and the - # registry cannot serve packages that have not been published yet. Hold - # until that run has concluded, polling every 30 s for up to 25 minutes - # (on 3.22.0 the run had stamped the packages 14 s after it started; the - # bound is for a queued runner, not for the work). + # THE PUBLISH RACE. On a push this run and the `Release Vale` run for the + # same commit started within seconds of each other, and the registry + # cannot serve packages that have not been published yet. The script + # holds until that run has concluded (polling every 30 s for up to 25 + # minutes; on 3.22.0 the run had stamped the packages 14 s after it + # started, so the bound is for a queued runner, not for the work), then + # until the registry answers the exact question the detect step is about + # to ask with "a newer set" (five probes a minute apart, using the same + # script with `--json` alone, a read that changes nothing). # - # EVERY EXIT HERE IS 0. A run that concludes anything but success, or - # that never appears inside the bound, is a warning and a clean exit, - # never a failed check: this workflow must not go red over a race it did - # not cause, and a red here would say "the upgrade is broken" when the - # truth is "the publish is". The daily schedule above retries once the - # packages are actually there, which is what a backstop is for. + # EVERY EXIT HERE IS 0. A publish that concludes anything but success, + # one that never appears inside the bound, or a registry that still says + # "current" at the end is a `::warning::` and `ready=false`, never a + # failed check: this workflow must not go red over a race it did not + # cause, and a red here would say "the upgrade is broken" when the truth + # is "the publish is". The daily schedule above retries once the packages + # are actually there, which is what a backstop is for. # - # Only on `push`. A scheduled or dispatched run has no publish to wait - # for — its commit is whatever main is, and the run list for that commit - # is empty by construction — so waiting there would only burn the bound. - # `--commit` is exact, so a publish run for a DIFFERENT manifest commit - # (an earlier release still draining) is never mistaken for this one. - - name: Wait for the Release Vale run for this commit - if: github.event_name == 'push' + # Not `if: github.event_name == 'push'`: the script reads the event + # itself and skips both waits with `ready=true` on anything else, because + # a scheduled or dispatched run has no publish to wait for (its commit is + # whatever main is, and the run list for that commit is empty by + # construction). Deciding inside the script rather than on the step keeps + # `ready` defined on every event; a skipped step has no outputs, and the + # detect step gates on this one. The full table of outcomes, including + # why a probe that ERRORS every time is also `ready=true`, is in the + # script's header. + - id: wait + name: Wait for the Release Vale run and the registry env: GH_TOKEN: ${{ secrets.GITHUB_TOKEN }} - run: | - set -euo pipefail - - deadline=$(( SECONDS + 25 * 60 )) - while :; do - # Two fields, tab-separated, one line per run. Empty until the run - # is registered, which can lag the push by a few seconds. - # - # `|| runs=""` is load-bearing under `set -e`: a plain assignment - # from a command substitution is NOT one of errexit's exempt - # contexts, so without it one rate-limited or 5xx'd `gh` call in - # fifty polls would abort the step and turn the run red — the one - # outcome this step exists to rule out. A failed call is treated - # exactly like "not yet registered" and polled again. - runs="$(gh run list \ - --workflow release-vale.yml \ - --event push \ - --commit "$GITHUB_SHA" \ - --json status,conclusion \ - --jq '.[] | [.status, .conclusion] | @tsv')" || runs="" - - if [ -n "$runs" ] && ! grep -qv $'^completed\t' <<< "$runs"; then - if grep -qv $'\tsuccess$' <<< "$runs"; then - echo "::warning::the Release Vale run for ${GITHUB_SHA} did not succeed (${runs//$'\n'/; }); nothing to upgrade to yet. The daily schedule will retry once a publish lands." - exit 0 - fi - echo "Release Vale succeeded for ${GITHUB_SHA}." - break - fi - - if [ "$SECONDS" -ge "$deadline" ]; then - echo "::warning::gave up waiting for the Release Vale run for ${GITHUB_SHA} after 25 minutes (${runs:-no run found}). The daily schedule will retry." - exit 0 - fi - echo "Release Vale for ${GITHUB_SHA}: ${runs:-not yet registered}; retrying in 30 s." - sleep 30 - done - - # THE PUBLISH RACE, second half. `npm publish` returning is not the same - # as the registry's packument for the name serving the new dist-tag; that - # propagates, usually in seconds, occasionally longer. Ask the registry - # the exact question the detect step is about to ask, with the same - # script and no side effects, and give it a few minutes to say yes. Like - # the step above this cannot fail the run: if the registry still says - # "current" at the end, the detect step will say the same, do nothing, - # and the daily schedule picks it up. - # - # `--json` alone, no `--write` and no `--notes-out`; the script refuses - # that combination for exactly this use, a read that changes nothing. - # - # A probe that ERRORS is kept apart from a probe that answers "current". - # The script prints its error to stderr and nothing to stdout, so a bare - # grep on stdout would read a registry outage as "still the old version" - # and the closing warning would then blame propagation for something - # else. Each outcome is logged as what it was, and the closing warning - # claims only what was observed. An error that persists is not this - # step's to report: the detect step runs the same code next and fails - # loudly on it, which is right — a broken registry read is a real - # failure, not the race. - - name: Wait for the registry to serve the new set - if: github.event_name == 'push' - run: | - set -euo pipefail - - for attempt in 1 2 3 4 5; do - if comparison="$(node .github/scripts/vale-upgrade-detect.cjs --json)"; then - if grep -q '"ahead":true' <<< "$comparison"; then - echo "The registry serves a newer set than the pins: ${comparison}" - exit 0 - fi - echo "The registry still serves the pinned version (attempt ${attempt} of 5): ${comparison}" - else - echo "The registry probe failed (attempt ${attempt} of 5); see the error above." - fi - echo "Retrying in 60 s." - sleep 60 - done - echo "::warning::no probe in five minutes after the publish succeeded reported a newer set than the pins; each attempt is logged above with its result. The daily schedule will retry." + run: node .github/scripts/vale-upgrade-wait.cjs # No dependency install yet: the script is zero-dependency CommonJS, and # the install below has to come AFTER the bump so it resolves the new @@ -239,6 +170,10 @@ jobs: --write --notes-out "${RUNNER_TEMP}/vale-release-notes.md" env: GITHUB_TOKEN: ${{ secrets.GITHUB_TOKEN }} + # Skipped when the wait established there is nothing to upgrade to yet; + # every later step gates on this step's `update`, which a skipped step + # leaves empty, so they skip with it. + if: steps.wait.outputs.ready == 'true' # Resolution, not editing. `--lockfile-only` skips linking, so nothing is # downloaded and no lifecycle script runs. It fails if the six packages From 5410aaf6a372a1bd8e830539bba3fcee6c6b8d69 Mon Sep 17 00:00:00 2001 From: Jakob Heuser Date: Mon, 21 Sep 2026 17:43:33 -0700 Subject: [PATCH 2/3] test(ci): cover the vale-upgrade-wait exit-0 fallback and guard its output write --- .github/scripts/vale-upgrade-wait.cjs | 34 ++++++--- .github/scripts/vale-upgrade-wait.test.cjs | 81 ++++++++++++++++++++++ 2 files changed, 105 insertions(+), 10 deletions(-) diff --git a/.github/scripts/vale-upgrade-wait.cjs b/.github/scripts/vale-upgrade-wait.cjs index 0e282453..ce394b6d 100644 --- a/.github/scripts/vale-upgrade-wait.cjs +++ b/.github/scripts/vale-upgrade-wait.cjs @@ -384,6 +384,28 @@ async function main({ return finish(true, "probe-errored"); } +/** + * The last line of the "always exit 0" guarantee. A wait that cannot run + * (a malformed flag, GITHUB_SHA missing on a push, anything main() throws) + * must not also suppress the upgrade, so the detect step is told to go ahead, + * which is the behaviour before the wait existed, and the failure is a + * warning in the log. Exported so the test can drive it without spawning; + * the spawn test covers the wiring below. + */ +function recover(error, { env = process.env, log = console.log } = {}) { + log( + `::warning::vale-upgrade-wait failed: ${error.message}; running detect without waiting.` + ); + try { + setOutput("ready", "true", env); + setOutput("outcome", "wait-errored", env); + } catch (outputError) { + // An unwritable $GITHUB_OUTPUT is the one thing this cannot report + // through the output; say so and still exit 0. + log(`::warning::could not write GITHUB_OUTPUT: ${outputError.message}`); + } +} + // Exported so vale-upgrade-wait.test.cjs can drive each wait with `gh`, the // probe, and the clock replaced, and main() end to end the same way. module.exports = { @@ -391,19 +413,11 @@ module.exports = { main, parseArgs, parseRuns, + recover, waitForRegistry, waitForReleaseRun, }; if (require.main === module) { - main().catch((error) => { - // Still exit 0. A wait that cannot run must not also suppress the - // upgrade, so the detect step is told to go ahead — the behaviour before - // the wait existed — and the failure is a warning in the log. - console.log( - `::warning::vale-upgrade-wait failed: ${error.message}; running detect without waiting.` - ); - setOutput("ready", "true"); - setOutput("outcome", "wait-errored"); - }); + main().catch((error) => recover(error)); } diff --git a/.github/scripts/vale-upgrade-wait.test.cjs b/.github/scripts/vale-upgrade-wait.test.cjs index 275fad44..3c97d85f 100644 --- a/.github/scripts/vale-upgrade-wait.test.cjs +++ b/.github/scripts/vale-upgrade-wait.test.cjs @@ -15,6 +15,7 @@ const test = require("node:test"); const assert = require("node:assert/strict"); +const { execFileSync } = require("node:child_process"); const { mkdtempSync, readFileSync, rmSync } = require("node:fs"); const { tmpdir } = require("node:os"); const { join } = require("node:path"); @@ -24,10 +25,13 @@ const { main, parseArgs, parseRuns, + recover, waitForRegistry, waitForReleaseRun, } = require("./vale-upgrade-wait.cjs"); +const SCRIPT = join(__dirname, "vale-upgrade-wait.cjs"); + const SHA = "0123456789abcdef0123456789abcdef01234567"; /** A fake clock: `sleep` advances it instead of waiting. */ @@ -484,3 +488,80 @@ test("main: flags shorten the bounds", async () => { assert.deepEqual(outputs, { ready: "false", outcome: "publish-unfinished" }); assert.deepEqual(slept, [20_000, 20_000, 20_000]); }); + +test("recover: a thrown error is a warning and ready=true, never a failure", () => { + const directory = mkdtempSync(join(tmpdir(), "vale-upgrade-wait-test-")); + const outputPath = join(directory, "github-output"); + const logged = []; + try { + recover(new Error("GITHUB_SHA must be set on a push"), { + env: { GITHUB_OUTPUT: outputPath }, + log: (line) => logged.push(line), + }); + assert.match(logged[0], /^::warning::vale-upgrade-wait failed: GITHUB_SHA/); + assert.equal( + readFileSync(outputPath, "utf8"), + "ready=true\noutcome=wait-errored\n" + ); + } finally { + rmSync(directory, { recursive: true, force: true }); + } +}); + +test("recover: an unwritable GITHUB_OUTPUT is a second warning, not a throw", () => { + const logged = []; + assert.doesNotThrow(() => + recover(new Error("boom"), { + env: { GITHUB_OUTPUT: join(tmpdir(), "does-not-exist", "x", "output") }, + log: (line) => logged.push(line), + }) + ); + assert.equal(logged.length, 2); + assert.match(logged[1], /^::warning::could not write GITHUB_OUTPUT/); +}); + +/** + * The real entry point, spawned. Everything above drives the exports; this is + * the one test of the `require.main === module` wiring, and it is the property + * the script exists for: a run that cannot even start still exits 0. + */ +function spawnScript(env, argv = []) { + const directory = mkdtempSync(join(tmpdir(), "vale-upgrade-wait-test-")); + const outputPath = join(directory, "github-output"); + try { + const stdout = execFileSync(process.execPath, [SCRIPT, ...argv], { + encoding: "utf8", + env: { PATH: process.env.PATH, GITHUB_OUTPUT: outputPath, ...env }, + stdio: ["ignore", "pipe", "pipe"], + }); + let outputs = ""; + try { + outputs = readFileSync(outputPath, "utf8"); + } catch { + // nothing written + } + return { stdout, outputs }; + } finally { + rmSync(directory, { recursive: true, force: true }); + } +} + +test("entry point: GITHUB_SHA missing on a push exits 0 with ready=true", () => { + // execFileSync throws on a non-zero exit, so reaching the assertions is the + // exit-code check. + const { stdout, outputs } = spawnScript({ GITHUB_EVENT_NAME: "push" }); + assert.match( + stdout, + /::warning::vale-upgrade-wait failed: GITHUB_SHA must be set on a push; running detect without waiting\./ + ); + assert.equal(outputs, "ready=true\noutcome=wait-errored\n"); +}); + +test("entry point: a malformed flag exits 0 with ready=true", () => { + const { stdout, outputs } = spawnScript({ GITHUB_EVENT_NAME: "push" }, [ + "--attempts", + "0", + ]); + assert.match(stdout, /--attempts needs a positive number, got 0/); + assert.equal(outputs, "ready=true\noutcome=wait-errored\n"); +}); From e14c1b8b6955ba3ded0b253f80b86547e3fb6002 Mon Sep 17 00:00:00 2001 From: Jakob Heuser Date: Mon, 21 Sep 2026 20:37:49 -0700 Subject: [PATCH 3/3] fix(ci): bound each gh call and registry probe in vale-upgrade-wait --- .github/scripts/vale-upgrade-wait.cjs | 80 +++++++++++++--- .github/scripts/vale-upgrade-wait.test.cjs | 103 ++++++++++++++++++++- 2 files changed, 168 insertions(+), 15 deletions(-) diff --git a/.github/scripts/vale-upgrade-wait.cjs b/.github/scripts/vale-upgrade-wait.cjs index ce394b6d..1e38fa8a 100644 --- a/.github/scripts/vale-upgrade-wait.cjs +++ b/.github/scripts/vale-upgrade-wait.cjs @@ -63,7 +63,7 @@ * Usage: * node .github/scripts/vale-upgrade-wait.cjs * [--workflow ] [--timeout-minutes ] [--poll-seconds ] - * [--attempts ] [--interval-seconds ] + * [--attempts ] [--interval-seconds ] [--call-timeout-seconds ] * * Reads GITHUB_EVENT_NAME and GITHUB_SHA. `gh` needs GH_TOKEN with * `actions: read`. @@ -89,6 +89,7 @@ const DEFAULTS = { pollMs: 30 * SECOND, attempts: 5, intervalMs: 60 * SECOND, + callTimeoutMs: 60 * SECOND, }; function setOutput(key, value, env = process.env) { @@ -127,24 +128,53 @@ function parseArgs(argv) { DEFAULTS.intervalMs / SECOND, SECOND ), + callTimeoutMs: read( + "--call-timeout-seconds", + DEFAULTS.callTimeoutMs / SECOND, + SECOND + ), }; } +/** + * What a call that hit its `timeout` looks like, so the message says so + * rather than repeating the signal name. Node reports it as ETIMEDOUT on the + * error and kills the child with SIGTERM; either alone is enough. + */ +const timedOut = (error) => + error.code === "ETIMEDOUT" || error.signal === "SIGTERM"; + /** * `gh` as an argv array, never through a shell. A non-zero exit becomes a * thrown Error carrying stderr, which the poll loop treats as "not yet * registered": one rate-limited or 5xx'd call in fifty polls must not end the * wait, let alone the run. + * + * BOUNDED PER CALL, not only between calls. The 25-minute deadline is checked + * after each poll returns, so a single call that HANGS (a stalled TLS + * handshake, a DNS lookup that never answers) would otherwise sit on the + * runner until GitHub's six-hour job timeout, well past every bound this + * script advertises. A call past `timeoutMs` is killed and thrown, and from + * there it is an ordinary failed call: logged, polled again, exit 0. The + * bound lives here and not on the step as `timeout-minutes`, because a step + * timeout FAILS the check, which is the one outcome this script must never + * produce over a race it did not cause. */ -function runGh(args) { +function runGh( + args, + { timeoutMs = DEFAULTS.callTimeoutMs, command = "gh" } = {} +) { try { - return execFileSync("gh", args, { + return execFileSync(command, args, { encoding: "utf8", stdio: ["ignore", "pipe", "pipe"], + timeout: timeoutMs, }); } catch (error) { - const detail = error.stderr?.toString().trim() || error.message; - throw new Error(`gh ${args.join(" ")} failed: ${detail}`); + const detail = timedOut(error) + ? `timed out after ${timeoutMs / SECOND} s` + : error.stderr?.toString().trim() || error.message; + throw new Error(`${command} ${args.join(" ")} failed: ${detail}`); } } @@ -153,16 +183,33 @@ function runGh(args) { * reasons: its stderr passes straight through, so "see the error above" in the * log is literally true; and its own $GITHUB_OUTPUT writes stay out of THIS * step's outputs, which would otherwise pick up a stray `update=false`. + * + * Bounded per call for the same reason as runGh: the six registry reads + * inside it are network calls, and a hung one must count as a failed probe + * rather than stall the attempt loop. */ -function probeRegistry() { +function probeRegistry({ + timeoutMs = DEFAULTS.callTimeoutMs, + script = DETECT_SCRIPT, +} = {}) { const env = { ...process.env }; delete env.GITHUB_OUTPUT; - const stdout = execFileSync(process.execPath, [DETECT_SCRIPT, "--json"], { - encoding: "utf8", - env, - stdio: ["ignore", "pipe", "inherit"], - }); - return JSON.parse(stdout.trim()); + try { + const stdout = execFileSync(process.execPath, [script, "--json"], { + encoding: "utf8", + env, + stdio: ["ignore", "pipe", "inherit"], + timeout: timeoutMs, + }); + return JSON.parse(stdout.trim()); + } catch (error) { + if (timedOut(error)) { + throw new Error( + `the registry probe timed out after ${timeoutMs / SECOND} s` + ); + } + throw error; + } } const sleepFor = (ms) => new Promise((resolve) => setTimeout(resolve, ms)); @@ -338,12 +385,15 @@ async function main({ throw new Error("GITHUB_SHA must be set on a push"); } + // The per-call bound reaches the real runners through a second argument an + // injected fake is free to ignore. + const call = { timeoutMs: options.callTimeoutMs }; const release = await waitForReleaseRun({ sha, workflow: options.workflow, timeoutMs: options.timeoutMs, intervalMs: options.pollMs, - runGh: gh, + runGh: (args) => gh(args, call), sleep, log, now, @@ -365,7 +415,7 @@ async function main({ const registry = await waitForRegistry({ attempts: options.attempts, intervalMs: options.intervalMs, - probe, + probe: () => probe(call), sleep, log, }); @@ -413,7 +463,9 @@ module.exports = { main, parseArgs, parseRuns, + probeRegistry, recover, + runGh, waitForRegistry, waitForReleaseRun, }; diff --git a/.github/scripts/vale-upgrade-wait.test.cjs b/.github/scripts/vale-upgrade-wait.test.cjs index 3c97d85f..ed10101a 100644 --- a/.github/scripts/vale-upgrade-wait.test.cjs +++ b/.github/scripts/vale-upgrade-wait.test.cjs @@ -16,7 +16,7 @@ const test = require("node:test"); const assert = require("node:assert/strict"); const { execFileSync } = require("node:child_process"); -const { mkdtempSync, readFileSync, rmSync } = require("node:fs"); +const { mkdtempSync, readFileSync, rmSync, writeFileSync } = require("node:fs"); const { tmpdir } = require("node:os"); const { join } = require("node:path"); @@ -25,7 +25,9 @@ const { main, parseArgs, parseRuns, + probeRegistry, recover, + runGh, waitForRegistry, waitForReleaseRun, } = require("./vale-upgrade-wait.cjs"); @@ -105,6 +107,7 @@ test("parseArgs scales the flags into milliseconds and keeps the defaults", () = pollMs: DEFAULTS.pollMs, attempts: DEFAULTS.attempts, intervalMs: DEFAULTS.intervalMs, + callTimeoutMs: DEFAULTS.callTimeoutMs, }); const options = parseArgs([ "--workflow", @@ -117,7 +120,10 @@ test("parseArgs scales the flags into milliseconds and keeps the defaults", () = "3", "--interval-seconds", "10", + "--call-timeout-seconds", + "7", ]); + assert.equal(options.callTimeoutMs, 7_000); assert.equal(options.workflow, "other.yml"); assert.equal(options.timeoutMs, 120_000); assert.equal(options.pollMs, 5_000); @@ -565,3 +571,98 @@ test("entry point: a malformed flag exits 0 with ready=true", () => { assert.match(stdout, /--attempts needs a positive number, got 0/); assert.equal(outputs, "ready=true\noutcome=wait-errored\n"); }); + +/** A child that never exits on its own, for the per-call timeout tests. */ +const HANG = "setTimeout(() => {}, 30_000)"; + +test("runGh: a call that hangs is killed at the bound and thrown as a failure", () => { + const started = Date.now(); + assert.throws( + () => runGh(["-e", HANG], { command: process.execPath, timeoutMs: 300 }), + /failed: timed out after 0\.3 s/ + ); + // Killed at the bound, not at the child's own 30 s. + assert.ok(Date.now() - started < 5_000); +}); + +test("probeRegistry: a probe that hangs is a thrown failure, not a stall", () => { + const directory = mkdtempSync(join(tmpdir(), "vale-upgrade-wait-test-")); + const script = join(directory, "hang.cjs"); + writeFileSync(script, `${HANG};\n`); + try { + assert.throws( + () => probeRegistry({ script, timeoutMs: 300 }), + /registry probe timed out after 0\.3 s/ + ); + } finally { + rmSync(directory, { recursive: true, force: true }); + } +}); + +test("release run: a timed-out gh call is polled again like any failed call", async () => { + const time = clock(); + const logged = []; + const { gh, calls } = ghScript([ + new Error("gh run list failed: timed out after 60 s"), + [succeeded], + ]); + const result = await waitForReleaseRun({ + sha: SHA, + runGh: gh, + sleep: time.sleep, + now: time.now, + log: (line) => logged.push(line), + }); + assert.equal(result.outcome, "succeeded"); + assert.equal(calls.length, 2); + assert.match( + logged[0], + /timed out after 60 s; treating as not yet registered/ + ); +}); + +test("registry: a timed-out probe counts as a failed probe", async () => { + const time = clock(); + const logged = []; + const { probe } = probeScript([ + new Error("the registry probe timed out after 60 s"), + ahead, + ]); + const result = await waitForRegistry({ + probe, + sleep: time.sleep, + log: (line) => logged.push(line), + }); + assert.equal(result.outcome, "ahead"); + assert.equal(result.attempt, 2); + assert.match(logged[0], /probe failed \(attempt 1 of 5\): .*timed out/); +}); + +test("main: the call timeout reaches gh and the probe as a second argument", async () => { + const seen = { gh: [], probe: [] }; + const directory = mkdtempSync(join(tmpdir(), "vale-upgrade-wait-test-")); + try { + await main({ + argv: ["--call-timeout-seconds", "9"], + env: { + GITHUB_EVENT_NAME: "push", + GITHUB_SHA: SHA, + GITHUB_OUTPUT: join(directory, "github-output"), + }, + runGh: (args, options) => { + seen.gh.push(options); + return JSON.stringify([succeeded]); + }, + probe: async (options) => { + seen.probe.push(options); + return ahead; + }, + sleep: async () => {}, + log: () => {}, + }); + } finally { + rmSync(directory, { recursive: true, force: true }); + } + assert.deepEqual(seen.gh, [{ timeoutMs: 9_000 }]); + assert.deepEqual(seen.probe, [{ timeoutMs: 9_000 }]); +});