diff --git a/docs/pregate.md b/docs/pregate.md index 6632ed79d..9a962cf8e 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 and use no CPU 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)) | +| `stall_timeout_s` | seconds a test command may print nothing while using under a tenth of one CPU 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)) | | `run_profiles` | name → `{ workflow, events, jobs, artifact, max_age_hours?, os? }`: the GitHub Actions runs `clear --run` verifies as evidence on the identical tree; a profile named after a lane (`free-tests.yml/macos-named-regressions`) clears that lane (see [run evidence](#run-evidence)). `--from-run` and the main-push reuse job verify runs against them too ([from-run](#from-run), [CI reuse](#ci-reuse)) | @@ -455,7 +455,9 @@ test-tier command: grew by at least a tenth of the wall time, so a quiet suite that is working (FOUN-63: a parallel `check.sh` silent for 9 minutes) is not killed, while a hang that waits on nothing is. A hang that keeps burning CPU is left to - the timeout. Windows reads no CPU time here and uses log growth alone. The `--remote` gate is exempt: a + the timeout. Linux reads `/proc` (exited children's time included once + reaped); macOS and other BSDs read `ps -S`; a failed read skips that + sample. Windows reads no CPU time here and uses log growth alone. 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 diff --git a/docs/troubleshooting.md b/docs/troubleshooting.md index 37c73ac6c..ca0bfd2f3 100644 --- a/docs/troubleshooting.md +++ b/docs/troubleshooting.md @@ -3843,7 +3843,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) launched wrote nothing to its log and its process group used no CPU for the stall timeout (default 300 s, +**Meaning.** A test command the lanes check (or a guard) launched wrote nothing to its log, and its process group used under a tenth of one CPU (Windows: log growth alone), 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. diff --git a/lib/pregate/checks/guards.ts b/lib/pregate/checks/guards.ts index 7d24d0b6d..1a67ff05a 100644 --- a/lib/pregate/checks/guards.ts +++ b/lib/pregate/checks/guards.ts @@ -20,7 +20,7 @@ import { baseInputs, sha256 } from '../context'; import { classifyCommandEnvironment, classifyEnvironment, environmentLine, environmentResult, launchCause } from '../environment'; import { launchRuntime } from '../runtime'; import { checkScratch } from '../run-scratch'; -import { readRange, supervise } from '../supervise'; +import { readRange, STALL_IDLE, supervise } from '../supervise'; import type { EnvironmentCause } from '../types'; import type { CheckDef, CheckResult, PregateContext } from '../types'; @@ -56,7 +56,7 @@ async function run(ctx: PregateContext): Promise { for (const g of selected) runs.push(await runGuard(ctx, g, runtime.env, dir)); const lines = [`runtime: ${runtime.label}`]; for (const r of runs) { - lines.push(r.stalled ? `GUARD: ${r.guard.id} stalled: no output for ${ctx.stallTimeoutMs / 1000} s and its process group used no CPU; process group killed (log ${r.log})` : r.timedOut ? `GUARD: ${r.guard.id} timed out after ${r.guard.timeout_s ?? ctx.timeoutMs / 1000} s (log ${r.log})` : `GUARD: ${r.guard.id} exit=${r.exit} (log ${r.log})`); + lines.push(r.stalled ? `GUARD: ${r.guard.id} stalled: no output for ${ctx.stallTimeoutMs / 1000} s${STALL_IDLE}; process group killed (log ${r.log})` : r.timedOut ? `GUARD: ${r.guard.id} timed out after ${r.guard.timeout_s ?? ctx.timeoutMs / 1000} s (log ${r.log})` : `GUARD: ${r.guard.id} exit=${r.exit} (log ${r.log})`); if (r.exit !== 0) lines.push(...r.tail.map(l => ` ${l}`)); if (r.environment) lines.push(` ${r.guard.id} ${environmentLine(r.environment)}`); } diff --git a/lib/pregate/checks/lanes.ts b/lib/pregate/checks/lanes.ts index 15b84e379..2e16b61f5 100644 --- a/lib/pregate/checks/lanes.ts +++ b/lib/pregate/checks/lanes.ts @@ -39,7 +39,7 @@ import { isDeviceDart, listRepoFiles, readRepoFile } from '../import-graph'; import { selectLanes, type Selection } from '../lane-selection'; import { launchRuntime } from '../runtime'; import { cargoModel, type CargoModel } from '../rust'; -import { adapterFor, readRange, supervise, type Counter, type Supervised } from '../supervise'; +import { adapterFor, readRange, STALL_IDLE, supervise, type Counter, type Supervised } from '../supervise'; import { verifyFromRun } from '../../run-evidence'; import { matchesAny } from '../../ship-policy'; import type { CheckDef, CheckResult, PregateContext, RemoteObligation } from '../types'; @@ -401,7 +401,7 @@ function unfinished(ctx: PregateContext, r: Awaited> const timedOut = r.runs.filter(x => x.outcome === 'timeout'); const rest = r.failed ? `; ${r.failed} failed` : ''; if (stalled.length) { - return { code: 'PREGATE_STALLED', detail: `no test output for ${ctx.stallTimeoutMs / 1000} s and its process group used no CPU; process group killed; last file started: ${stalled.map(x => x.lastFile ?? `(none reported; ${x.files.length} file(s))`).join(', ')}${rest}`, fix: `read ${r.log} for the stalled file; fix the hang, or raise --stall-timeout (stall_timeout_s in ${ctx.configFile}; 0 disables) for a test that waits quietly for longer` }; + return { code: 'PREGATE_STALLED', detail: `no test output for ${ctx.stallTimeoutMs / 1000} s${STALL_IDLE}; process group killed; last file started: ${stalled.map(x => x.lastFile ?? `(none reported; ${x.files.length} file(s))`).join(', ')}${rest}`, fix: `read ${r.log} for the stalled file; fix the hang, or raise --stall-timeout (stall_timeout_s in ${ctx.configFile}; 0 disables) for a test that waits quietly for longer` }; } const launch = r.runs.find(x => x.outcome === 'spawn-failed'); if (launch) { diff --git a/lib/pregate/supervise.ts b/lib/pregate/supervise.ts index 9aa12d722..3c4c3412e 100644 --- a/lib/pregate/supervise.ts +++ b/lib/pregate/supervise.ts @@ -68,6 +68,8 @@ const ACTIVE = new Set(); const USER_HZ = 100; const CPU_SAMPLE_MS = 1_000; const CPU_BUSY_SHARE = 0.1; +/** What a stall means beyond silence, for the PREGATE_STALLED detail and the guard line; Windows reads no CPU time. */ +export const STALL_IDLE = process.platform === 'win32' ? '' : ' and its process group used under a tenth of one CPU'; /** SIGKILL every supervised process group still running (the CLI's SIGINT/SIGTERM handler, before it exits). */ export function cancelActive(): number { @@ -99,7 +101,7 @@ export function groupCpuMs(pgid: number): number | null { } return ticks * 1000 / USER_HZ; } - const ps = spawnSync('ps', ['-A', '-o', 'pgid=,time='], { encoding: 'utf8', timeout: 15_000 }); + const ps = spawnSync('ps', ['-A', '-S', '-o', 'pgid=,time='], { encoding: 'utf8', timeout: 15_000 }); if (ps.status !== 0) return null; let ms = 0; for (const line of ps.stdout.split('\n')) { @@ -141,7 +143,7 @@ export function supervise(o: SuperviseOptions): Promise { let partial = ''; let lastGrowth = started; let lastBusy = started; - let cpu: { at: number; ms: number } | null = { at: started, ms: 0 }; + let cpu = { at: started, ms: 0 }; let lastProgress = started; let current: { file: string; at: number; failed: boolean } | null = null; let lastFile: string | null = null; @@ -216,10 +218,12 @@ export function supervise(o: SuperviseOptions): Promise { if (grown > size) { size = grown; lastGrowth = now; readNew(); } if (outcome) return; if (now >= o.deadline) { stop('timeout'); return; } - if (o.stallMs > 0 && cpu && now - cpu.at >= CPU_SAMPLE_MS) { + if (o.stallMs > 0 && process.platform !== 'win32' && now - cpu.at >= CPU_SAMPLE_MS) { const used = groupCpuMs(child.pid!); - if (used !== null && used - cpu.ms >= CPU_BUSY_SHARE * (now - cpu.at)) lastBusy = now; - cpu = used === null ? null : { at: now, ms: used }; + if (used !== null) { + if (used - cpu.ms >= CPU_BUSY_SHARE * (now - cpu.at)) lastBusy = now; + cpu = { at: now, ms: used }; + } } if (o.stallMs > 0 && now - Math.max(lastGrowth, lastBusy) >= o.stallMs) { stop('stalled'); return; } if (now - lastProgress < heartbeatMs) return; diff --git a/lib/result-codes.ts b/lib/result-codes.ts index ea0a69d1f..8bb6f4089 100644 --- a/lib/result-codes.ts +++ b/lib/result-codes.ts @@ -410,7 +410,7 @@ export const RESULT_CODES = { }, PREGATE_STALLED: { anchor: 'pregate-stalled', - summary: 'a test command printed nothing and used no CPU for the stall timeout, so its process group was killed; the check is incomplete, never pass', + summary: 'a test command printed nothing for the stall timeout while its process group used under a tenth of one CPU (log growth alone on Windows), so the group was killed; the check is incomplete, never pass', fix: 'read the lane log for the last file started, fix the hang, or raise `--stall-timeout` (`stall_timeout_s`; 0 disables) for a test that waits quietly for longer, then rerun `gstack-pregate --stage tests`', }, PREGATE_RECEIPT_INVALID: {