diff --git a/CHANGELOG.md b/CHANGELOG.md index 3bc22ba5a..3ac49e79c 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,17 @@ # Changelog +## [1.91.368.0] - 2026-10-31 + +**`gstack-pregate --remote` no longer dies at 300 s while its gate waits on CI.** CAPY-1 (qm#2837) had a remote gate that waits for a CI run and prints nothing while it waits, so pregate killed it as stalled after 300 s, whatever `--timeout` said, and the heartbeat gave no hint of what the gate was doing (GST-431). + +### Fixed +- **The remote gate is bounded by its timeout only** (`--timeout`, else `timeout_s`, else 600 s; the gate also gets it as `PREGATE_TIMEOUT_S`). The stall timer still applies to the lanes runner and guards. +- **The remote gate's heartbeat names its last output line**, so a gate that prints the CI run it is waiting on shows it every 60 s. + +### Tests +- `test/pregate-remote.test.ts`: a gate quiet past `--stall-timeout` but inside `--timeout` clears its obligation; a gate past `--timeout` stays uncleared with `PREGATE_INCOMPLETE`. +- `test/pregate-supervise.test.ts`: a heartbeat with `lastLine` names the command's last output line. + ## [1.91.367.0] - 2026-10-31 **/ship's review collection no longer counts a reviewer that says it could not review as clean.** In the GSTA-196 replay a specialist replied in prose that the diff base did not exist and it was not returning NO FINDINGS. `collect` parsed that reply to zero findings, and `verify` marked the brief collected, so the review would have read clean from a reader that never saw the diff. What reviewers see is unchanged: every brief renders byte for byte as before. diff --git a/VERSION b/VERSION index 3a3edfea1..c98e127c5 100644 --- a/VERSION +++ b/VERSION @@ -1 +1 @@ -1.91.367.0 +1.91.368.0 diff --git a/agents-digest/gstack-AGENTS.md b/agents-digest/gstack-AGENTS.md index bb86af787..982707a37 100644 --- a/agents-digest/gstack-AGENTS.md +++ b/agents-digest/gstack-AGENTS.md @@ -1,4 +1,4 @@ -# gstack digest v1.91.367.0 — regenerate/re-copy after upgrading gstack +# gstack digest v1.91.368.0 — regenerate/re-copy after upgrading gstack Behavioral rules from gstack (https://github.com/garrytan/gstack), compressed for agent hosts without a full skill install. The full skills add workflows, diff --git a/bin/gstack-pregate b/bin/gstack-pregate index d11a0730c..b3f5297eb 100755 --- a/bin/gstack-pregate +++ b/bin/gstack-pregate @@ -75,7 +75,7 @@ const HELP = `gstack-pregate — cheap checks before anything paid or remote (do timeout catches a silent one sooner --stall-timeout kill a test command's process group after this long with no output and record the check incomplete (PREGATE_STALLED); default stall_timeout_s from the base .gstack/pregate.json, - else ${DEFAULT_STALL_TIMEOUT_S}; 0 disables + else ${DEFAULT_STALL_TIMEOUT_S}; 0 disables; the --remote gate is exempt (only --timeout bounds it) --remote run the base branch's remote_gate now instead of local tests (needs --allow-repo-commands; under --policy-from head the gate is still the base copy's); it clears the requires-remote obligation only on its PREGATE_REMOTE: tree= tests= failed=0 line with n > 0 diff --git a/docs/pregate.md b/docs/pregate.md index b3b5ef4ed..b9d7596a3 100644 --- a/docs/pregate.md +++ b/docs/pregate.md @@ -85,7 +85,7 @@ the byte-pinned `/ship` renders in `test/fixtures/golden/`). | `serial_patterns` | test-file globs the `lanes` check runs one process per file, apart from the unit files (default `**/*.serial.test.*`) | | `sealed` | sealed or eval output that must never reach a public destination; read by the pre-push hook and `gstack-pregate sealed` (see [sealed output](#sealed)) | | `price_file` | repo-relative path of the paid gate's call-plan data file (`GSTACK_EVAL_CALLS v1`); `gstack-eval-plan price-gate` prices from it and never executes anything ([docs/eval-calls.md](eval-calls.md)) | -| `stall_timeout_s` | seconds a test command may print nothing before its process group is killed and the check is `incomplete` (`PREGATE_STALLED`); default 300, `0` disables; `--stall-timeout` overrides (see [supervision](#supervision)) | +| `stall_timeout_s` | seconds a test command may print nothing before its process group is killed and the check is `incomplete` (`PREGATE_STALLED`); default 300, `0` disables; `--stall-timeout` overrides; the `--remote` gate is exempt (see [supervision](#supervision)) | | `timeout_s` | seconds each runner process may take (the unit-file group, each serial file, each guard without its own `timeout_s`, and the remote gate's deadline) when `--timeout` is not passed; 1 to 3600, default 600. `gstack-ship-preflight` and the `finish` fallback run pregate without `--timeout`, so this is how a repo with long lanes sets theirs | | `remote_gate` | the repo's remote test gate command; under 8 cores the local test tier becomes a `requires-remote` obligation naming it, and `--remote` runs it (see [remote gate](#remote-gate)) | | `allowlist` | `[{ finding, paths?, pattern?, reason }]`: benign findings the `secrets` check accepts and names as allowlisted, by gstack-redact finding id or non-secret category, path globs and a pattern anchored at the finding; never `env.value` (see [allowlist](#allowlist)) | @@ -411,7 +411,9 @@ test-tier command: - is killed as **stalled** when its log does not grow for the stall timeout (`--stall-timeout `, else `stall_timeout_s`, else 300; `0` disables): the check is `incomplete` with `PREGATE_STALLED` and names the last file - started; the next serial file still runs; + started; the next serial file still runs. The `--remote` gate is exempt: a + gate that waits on CI is quiet by design, so only its timeout bounds it, and + its heartbeats add `; last output: `; - is killed as **timed out** when that runner process reaches its timeout (`--timeout `, else `timeout_s`, else 600; per runner process, so many serial files that each fit still pass): the check is `incomplete`, its detail @@ -452,7 +454,11 @@ the supervision above. Close the obligation one of two ways: `PREGATE_REMOTE: tree= tests= failed= [spent=]`, reporting the tree it actually tested. The obligation clears only when that tree is `PREGATE_TREE`, `tests` > 0, `failed` = 0 and the gate exits 0; anything else - leaves it uncleared and the check `incomplete`. The cap defaults to + leaves it uncleared and the check `incomplete`. The gate runs until it exits + or reaches the timeout (`--timeout`, else `timeout_s`, else 600 s); the stall + timer does not apply, and each 60 s heartbeat names the gate's last output + line, so a gate that prints what it is waiting on (a CI run id and its + status) shows it. The cap defaults to `$GSTACK_SPEND_CAP_USD`; there is no default spend. Spend prints as `spent, reserved, unknown`: a gate that prints no `spent=` is `unknown`, counted at the cap. diff --git a/docs/troubleshooting.md b/docs/troubleshooting.md index 54e69b906..c33b6a56a 100644 --- a/docs/troubleshooting.md +++ b/docs/troubleshooting.md @@ -3467,8 +3467,7 @@ the lane log, then rerun or split the selection. A tool missing from PATH is ### `PREGATE_STALLED` -**Meaning.** A test command the lanes check (or a guard, or the `--remote` -gate) launched wrote nothing to its log for the stall timeout (default 300 s, +**Meaning.** A test command the lanes check (or a guard) launched wrote nothing to its log for the stall timeout (default 300 s, `stall_timeout_s` in the base branch's `.gstack/pregate.json` or the user-owned file, or `--stall-timeout`). pregate killed its process group and names the last test file started. The check is incomplete, never pass. @@ -3477,7 +3476,9 @@ file started. The check is incomplete, never pass. child, a server that never exits, a synchronous wait), fix it and rerun `gstack-pregate --stage tests`. A test that is legitimately quiet for longer needs a larger `--stall-timeout`; `0` disables the stall kill and leaves only -`--timeout`. +`--timeout`. The `--remote` gate never stalls: it is bounded by `--timeout` +(else `timeout_s`), so a gate that waits on CI needs a timeout long enough for +the CI run. ### `PREGATE_RECEIPT_INVALID` diff --git a/lib/pregate/checks/lanes.ts b/lib/pregate/checks/lanes.ts index 759b3588a..f1206404c 100644 --- a/lib/pregate/checks/lanes.ts +++ b/lib/pregate/checks/lanes.ts @@ -406,7 +406,9 @@ export function remoteReportProblem(report: RemoteReport, tree: string): string * must print `PREGATE_REMOTE: tree= tests= failed= [spent=]`; * the obligation clears only when that tree is the tested tree, tests > 0, * failed = 0 and the gate exited 0. Anything else leaves it uncleared and - * the check incomplete. + * the check incomplete. The gate is bounded by that timeout only: a gate + * that waits on CI is quiet by design, so the stall timer does not apply, + * and its heartbeat names the gate's last output line. */ async function runRemote(ctx: PregateContext, sel: Selection, base: CheckResult): Promise { const lines = base.lines ?? []; @@ -418,7 +420,7 @@ async function runRemote(ctx: PregateContext, sel: Selection, base: CheckResult) const filesFile = path.join(dir, 'files.txt'); fs.writeFileSync(log, ''); fs.writeFileSync(filesFile, sel.localTests.join('\n') + '\n'); - const r = await supervise({ command: obligation.command!, cwd: ctx.repoRoot, env: { ...ctx.env, PREGATE_TREE: ctx.wtree, PREGATE_FILES_FILE: filesFile, PREGATE_SPEND_CAP_USD: String(cap), PREGATE_TIMEOUT_S: String(Math.floor(ctx.timeoutMs / 1000)) }, log, deadline: Date.now() + ctx.timeoutMs, stallMs: ctx.stallTimeoutMs, label: `remote gate ${obligation.lane}`, progress: ctx.progress }); + const r = await supervise({ command: obligation.command!, cwd: ctx.repoRoot, env: { ...ctx.env, PREGATE_TREE: ctx.wtree, PREGATE_FILES_FILE: filesFile, PREGATE_SPEND_CAP_USD: String(cap), PREGATE_TIMEOUT_S: String(Math.floor(ctx.timeoutMs / 1000)) }, log, deadline: Date.now() + ctx.timeoutMs, stallMs: 0, lastLine: true, label: `remote gate ${obligation.lane}`, progress: ctx.progress }); const output = readRange(log, r.start, r.end); const reported = parseRemoteReport(output); const spent = reported?.spent; @@ -426,16 +428,17 @@ async function runRemote(ctx: PregateContext, sel: Selection, base: CheckResult) ctx.progress(`PREGATE_REMOTE_SPEND: ${spend.slice('spend: '.length)}`); const runLines = [...lines, `remote gate: ${obligation.command}`, `log: ${log}`, spend, ...output.trim().split('\n').slice(-15).map(l => ` ${l}`)]; const inputs = { ...base.inputs, command: sha256(obligation.command!) }; - const why = r.outcome !== 'exited' ? `the remote gate did not finish (${r.outcome === 'stalled' ? `no output for ${ctx.stallTimeoutMs / 1000} s` : r.outcome})` + const why = r.outcome === 'timeout' ? `the remote gate did not finish (timed out after ${ctx.timeoutMs / 1000} s, ${ctx.timeoutSource})` + : r.outcome !== 'exited' ? `the remote gate did not finish (${r.outcome})` : !reported ? `the remote gate exited ${r.exit} without a PREGATE_REMOTE: line` : remoteReportProblem(reported, ctx.wtree) ?? (r.exit !== 0 ? `the remote gate exited ${r.exit}` : null); // A gate that printed no report and names a quota, network or missing-tool error in its preamble never ran the tests: the environment, not the diff. // Only the gate's first lines are read (a VM refusal or a network error comes before any test streams); exit 127 counts only when the gate's own binary is off PATH. - const environment = why && !reported && r.outcome !== 'stalled' && r.outcome !== 'timeout' + const environment = why && !reported && r.outcome !== 'timeout' ? r.outcome === 'spawn-failed' ? { ...(classifyEnvironment(r.error ?? '', null) ?? launchCause('missing-binary', r.error ?? 'the remote gate could not be started')), proof: 'launch' as const } : classifyCommandEnvironment(obligation.command!, output.split('\n').slice(0, REMOTE_PREAMBLE_LINES).join('\n'), r.exit, ctx.env) : null; if (environment) return environmentResult({ ...base, inputs, lines: runLines, remote: [...sel.remote, obligation] }, environment, `${why}; requires-remote ${obligation.lane} stays uncleared`); - if (why) return { ...base, inputs, lines: runLines, status: 'incomplete', remote: [...sel.remote, obligation], code: r.outcome === 'stalled' ? 'PREGATE_STALLED' : 'PREGATE_INCOMPLETE', detail: `${why}; requires-remote ${obligation.lane} stays uncleared`, fix: `read ${log}; the obligation clears only on PREGATE_REMOTE: tree=${ctx.wtree.slice(0, 12)}… tests>0 failed=0 with exit 0` }; + if (why) return { ...base, inputs, lines: runLines, status: 'incomplete', remote: [...sel.remote, obligation], code: 'PREGATE_INCOMPLETE', detail: `${why}; requires-remote ${obligation.lane} stays uncleared`, fix: `read ${log}; the obligation clears only on PREGATE_REMOTE: tree=${ctx.wtree.slice(0, 12)}… tests>0 failed=0 with exit 0` }; const cleared = { ...obligation, receipt: `remote-gate tree=${ctx.wtree.slice(0, 12)} tests=${reported!.tests}`, cleared_by: `gstack-pregate --remote ${new Date().toISOString()}` }; return { ...base, inputs, lines: runLines, status: 'requires-remote', remote: [...sel.remote, cleared], detail: `remote gate ${obligation.lane}: ${reported!.tests} tests, 0 failed on tree ${ctx.wtree.slice(0, 12)}; ${spend}` }; } diff --git a/lib/pregate/supervise.ts b/lib/pregate/supervise.ts index 17639f97f..a7ff3ed88 100644 --- a/lib/pregate/supervise.ts +++ b/lib/pregate/supervise.ts @@ -11,7 +11,7 @@ * headers) reports `PREGATE_TEST: / start|pass|fail ` * per file; a run of one file reports it from the launch itself for any * runner. Without either, only heartbeats: a line after each `heartbeatMs` - * with no progress line. + * with no progress line; with `lastLine` it names the last line the command printed. * * Platforms: POSIX signals the negative pid (the group `detached` creates * with setsid). Windows has no process groups here: the kill is @@ -43,6 +43,8 @@ export interface SuperviseOptions { files?: readonly string[]; adapter?: ProgressAdapter | null; counter?: Counter; + /** Heartbeats name the command's last output line (the remote gate, which has no per-file progress). */ + lastLine?: boolean; progress: (line: string) => void; } @@ -183,7 +185,13 @@ export function supervise(o: SuperviseOptions): Promise { if (outcome) return; if (now >= o.deadline) { stop('timeout'); return; } if (o.stallMs > 0 && now - lastGrowth >= o.stallMs) { stop('stalled'); return; } - if (now - lastProgress >= heartbeatMs) emit(`PREGATE_HEARTBEAT: ${o.label} running ${Math.round((now - started) / 1000)}s; last file ${lastFile ?? 'none reported'}; log ${size - start} bytes, last growth ${Math.round((now - lastGrowth) / 1000)}s ago (${o.log})`); + if (now - lastProgress < heartbeatMs) return; + let last: string | undefined; + if (o.lastLine) { + try { last = readRange(o.log, start, size, 4096).replace(/\x1b\[[0-9;?]*[A-Za-z]/g, '').split(/\r\n?|\n/).map(l => l.replace(/[\x00-\x1f\x7f]/g, '').trim()).filter(Boolean).at(-1); } + catch { /* log removed */ } + } + emit(`PREGATE_HEARTBEAT: ${o.label} running ${Math.round((now - started) / 1000)}s; last file ${lastFile ?? 'none reported'}; log ${size - start} bytes, last growth ${Math.round((now - lastGrowth) / 1000)}s ago (${o.log})${last ? `; last output: ${last.slice(0, 160)}` : ''}`); }, pollMs); if (child.pid) ACTIVE.add(child.pid); child.on('error', e => finish(null, null, e.message)); diff --git a/package.json b/package.json index 1ab4584df..4bfb7eb80 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "gstack", - "version": "1.91.367", + "version": "1.91.368", "description": "Garry's Stack — Claude Code skills + fast headless browser. One repo, one install, entire AI engineering workflow.", "license": "MIT", "type": "module", diff --git a/scripts/ubicloud/pregate-remote.sh b/scripts/ubicloud/pregate-remote.sh index 0759ee9b1..68e5b5692 100755 --- a/scripts/ubicloud/pregate-remote.sh +++ b/scripts/ubicloud/pregate-remote.sh @@ -185,7 +185,7 @@ args=(run -s "$size" --src "$root" --setup "$prelude" [ -z "${GSTACK_FREE_JOBS:-}" ] || args+=(--env "GSTACK_FREE_JOBS=$GSTACK_FREE_JOBS") # The VM run gets its own session (python3, which ubi-runner already needs, for -# setsid on Linux and macOS): pregate's --timeout and stall kill signal this +# setsid on Linux and macOS): pregate's --timeout kill signals this # script's process group and then SIGKILL it, which must never cut ubi-runner's # teardown short. Output goes to files (a dead reader would SIGPIPE ubi-runner), # stamped for the phase timings; this script streams it. A watchdog sends diff --git a/test/pregate-remote.test.ts b/test/pregate-remote.test.ts index 88308ed8a..ca781b02e 100644 --- a/test/pregate-remote.test.ts +++ b/test/pregate-remote.test.ts @@ -22,6 +22,7 @@ const GATE = 'node scripts/remote-gate.js'; const GATE_SCRIPT = [ "const fs = require('node:fs');", "fs.writeFileSync('../gate-env.json', JSON.stringify({ tree: process.env.PREGATE_TREE, cap: process.env.PREGATE_SPEND_CAP_USD, timeout: process.env.PREGATE_TIMEOUT_S, files: fs.readFileSync(process.env.PREGATE_FILES_FILE, 'utf8') }));", + "if (process.env.GATE_QUIET_MS) Atomics.wait(new Int32Array(new SharedArrayBuffer(4)), 0, 0, Number(process.env.GATE_QUIET_MS));", "if (process.env.GATE_SILENT) process.exit(0);", "const spent = process.env.GATE_SPENT ? ` spent=${process.env.GATE_SPENT}` : '';", "console.log(`PREGATE_REMOTE: tree=${process.env.GATE_TREE || process.env.PREGATE_TREE} tests=${process.env.GATE_TESTS ?? 3} failed=${process.env.GATE_FAILED ?? 0}${spent}`);", @@ -187,6 +188,22 @@ describe('gstack-pregate --remote (C-c)', () => { expect(fs.existsSync(path.join(repo.root, 'gate-env.json'))).toBe(false); }, 60_000); + // Value: protects=a remote gate that waits quietly on CI is bounded by its deadline (--timeout, else timeout_s), not killed by the + // test-output stall timer; a gate past its deadline still stays uncleared (GST-431); fails_when=the stall timer kills a quiet gate + // inside its deadline, or a gate past --timeout clears; why_new=a CI-waiting gate died at 300 s on qm (CAPY-1); seam=fake gate; + // no_claim=the Ubicloud VM + test('a gate that is quiet past the stall timeout but inside its deadline clears; past --timeout it stays uncleared', () => { + const repo = gated(); + const quiet = remote(repo, ['--remote', '--allow-repo-commands', '--spend-cap', '2', '--stall-timeout', '1', '--timeout', '60'], { GATE_QUIET_MS: '2500' }); + expect(quiet.status).toBe(EXIT.ok); + expect(pregateFile(repo).verdict).toBe('requires-remote cleared'); + const late = remote(repo, ['--remote', '--allow-repo-commands', '--spend-cap', '2', '--timeout', '2'], { GATE_QUIET_MS: '8000' }); + expect(late.status).toBe(EXIT.fail); + expect(lanes(repo)).toMatchObject({ status: 'incomplete', code: 'PREGATE_INCOMPLETE' }); + expect(lanes(repo).detail).toContain('the remote gate did not finish (timed out after 2 s, --timeout)'); + expect(pregateFile(repo).requires_remote[0].receipt).toBeNull(); + }, 60_000); + test('a wrong tree, zero tests, a failure, a missing line or a non-zero exit leaves the obligation uncleared and the check incomplete; unreported spend counts at the cap', () => { const repo = gated(); const cases: Array<[Record, string]> = [ diff --git a/test/pregate-supervise.test.ts b/test/pregate-supervise.test.ts index abdf3909b..70921184a 100644 --- a/test/pregate-supervise.test.ts +++ b/test/pregate-supervise.test.ts @@ -91,6 +91,28 @@ describe('supervise: process group, log file, stall and deadline', () => { expect(r.lines.filter(l => l.startsWith('PREGATE_HEARTBEAT: fixture running ')).length).toBeGreaterThanOrEqual(2); expect(r.lines.some(l => l.startsWith('PREGATE_TEST:'))).toBe(false); }); + + // Value: protects=a remote gate's heartbeat says what the gate last printed (GST-431); fails_when=the heartbeat for a gate that + // reports its CI wait shows only "last file none reported"; why_new=a CI-waiting gate looked dead on qm (CAPY-1); seam=none; no_claim=none + test('with lastLine, a heartbeat names the command\'s last output line', async () => { + const dir = scratch(); + const r = await run(dir, 'echo "waiting on run 7 (in_progress)"; sleep 1.2; echo done', { heartbeatMs: 300, lastLine: true }); + expect(r.outcome).toBe('exited'); + expect(r.lines.some(l => l.startsWith('PREGATE_HEARTBEAT: fixture running ') && l.includes('last output: waiting on run 7 (in_progress)'))).toBe(true); + const redraw = await run(dir, "printf 'run 7 queued\\r\\033[2Krun 7 in_progress\\n'; sleep 1.2", { heartbeatMs: 300, lastLine: true }); + expect(redraw.lines.some(l => l.endsWith('last output: run 7 in_progress'))).toBe(true); + expect(redraw.lines.some(l => l.includes('\x1b') || l.includes('\r'))).toBe(false); + }); + + // Value: protects=reading the last line is best effort: a log that disappears mid-run never throws out of the supervisor's timer, which would + // abandon the gate's deadline and cleanup (GST-431 review); fails_when=lastLine sampling throws ENOENT; why_new=lastLine is new; seam=none; no_claim=none + test('with lastLine, a log removed mid-run still ends in a normal outcome', async () => { + const dir = scratch(); + const log = path.join(dir, 'run.log'); + fs.writeFileSync(log, ''); + const r = await supervise({ command: `echo hi; sleep 0.4; rm -f "${log}"; sleep 1.2; echo done`, cwd: dir, env: process.env, log, deadline: Date.now() + 30_000, stallMs: 0, graceMs: 300, pollMs: 50, heartbeatMs: 300, lastLine: true, label: 'fixture', progress: () => {} }); + expect(r.outcome).toBe('exited'); + }); }); describe('supervise: per-file progress adapters', () => {