diff --git a/docs/IMPLEMENTATION.md b/docs/IMPLEMENTATION.md index 92dd447d2..1ba0d03cc 100644 --- a/docs/IMPLEMENTATION.md +++ b/docs/IMPLEMENTATION.md @@ -521,6 +521,7 @@ Run all three before declaring work complete. - **`tests/integration/`** holds the reactor permission / multi-turn harness (scripted models via `@intx/inference-testing`). **`tests/e2e/`** (fixture-repo runs) is still planned. Until e2e exists, broader harness coverage also lives in co-located `*.test.ts` files and `tests/unit/`. - **Capability evals** (`evals/capability/`) are **not** the integration harness: they drive the product path (`corbits exec` / `runExec`) with real models against fixture copies and objective `verify.sh` graders. Case format + loader tests live under `evals/capability/`; run with `bun run eval:capability` (see `evals/capability/README.md`). Use `--baseline` to detect improve/regress across models or commits. - **TUI tests** are co-located `*.test.ts` files under `src/tui/` (e.g. `shell.test.ts`, `runner-host.test.ts`, `stream.test.ts`), run as part of `bun test` along with everything else; there is no separate `test:tui` script or test-setup preload. +- **Parallel local runs** — `bun run test:parallel [N]` (default 4 workers) runs the same seeded suite with `--parallel=N`, wrapped in an output-stall watchdog (`scripts/test-parallel.ts`). Bun 1.4.x intermittently livelocks under `--parallel` (one worker spins at 100 % CPU holding a zombie git child while the main process idles; no output, no summary — upstream oven-sh/bun#36235), and `bun test` has no run-level timeout, so a stalled run hangs forever. The watchdog kills the suite's own process group after 90 s of silence and retries up to 3 times; a child that exits on its own (pass or fail) is never retried. CI keeps sharded sequential runs (`test:paths`) and does not use `--parallel`. ## Deployment diff --git a/package.json b/package.json index acb7ada7f..2635a81b7 100644 --- a/package.json +++ b/package.json @@ -34,6 +34,7 @@ "typecheck": "tsc --noEmit", "test": "bun test ./src ./tests ./evals ./scripts --randomize --seed 424242", "test:paths": "bun scripts/test-paths.ts", + "test:parallel": "bun scripts/test-parallel.ts", "lint": "oxfmt --check . && oxlint", "check:projects-dir-guard": "bun scripts/guard-real-projects-dir.ts", "check": "bun run lint && bun run typecheck && bun run build && bun run check:projects-dir-guard", diff --git a/scripts/test-parallel.test.ts b/scripts/test-parallel.test.ts new file mode 100644 index 000000000..8869da2e5 --- /dev/null +++ b/scripts/test-parallel.test.ts @@ -0,0 +1,135 @@ +import { describe, expect, test } from "bun:test"; +import { mkdtempSync, readFileSync } from "node:fs"; +import { tmpdir } from "node:os"; +import { join } from "node:path"; + +import { runWithWatchdog } from "./test-parallel.js"; + +function processAlive(pid: number): boolean { + try { + process.kill(pid, 0); + return true; + } catch { + return false; + } +} + +// These probes are `bun -e` one-liners, so they never import project modules +// and finish in milliseconds. Stall windows are tiny (300-500ms) to keep the +// file fast while still exercising the watchdog's timing logic. + +describe("runWithWatchdog", () => { + test("passes through a successful run without retrying", async () => { + const chunks: string[] = []; + const result = await runWithWatchdog({ + command: process.execPath, + args: ["-e", 'console.log("hello-parallel")'], + stallMs: 5_000, + onOutput: (chunk) => chunks.push(Buffer.from(chunk).toString("utf8")), + }); + expect(result.exitCode).toBe(0); + expect(result.stalled).toBe(false); + expect(result.attempts).toBe(1); + expect(chunks.join("")).toContain("hello-parallel"); + }); + + test("passes through a failing run without retrying", async () => { + const result = await runWithWatchdog({ + command: process.execPath, + args: ["-e", "process.exit(3)"], + stallMs: 5_000, + onStall: () => { + throw new Error("must not stall on a clean failure"); + }, + }); + expect(result.exitCode).toBe(3); + expect(result.stalled).toBe(false); + expect(result.attempts).toBe(1); + }); + + test("output resets the stall timer", async () => { + // Prints every 100ms for ~700ms against a 300ms stall window: a broken + // timer that never reset would fire on the second tick. + const result = await runWithWatchdog({ + command: process.execPath, + args: [ + "-e", + "for (let i = 0; i < 7; i++) { console.log('tick', i); await new Promise(r => setTimeout(r, 100)); }", + ], + stallMs: 300, + }); + expect(result.exitCode).toBe(0); + expect(result.stalled).toBe(false); + expect(result.attempts).toBe(1); + }); + + test("retries after a stall and returns the second attempt's result", async () => { + const dir = mkdtempSync(join(tmpdir(), "test-parallel-retry-")); + const flag = join(dir, "attempted"); + const code = ` + const fs = require("node:fs"); + if (fs.existsSync(${JSON.stringify(flag)})) { + console.log("second attempt"); + } else { + fs.writeFileSync(${JSON.stringify(flag)}, "1"); + setTimeout(() => {}, 30_000); + } + `; + const stalls: [number, number][] = []; + const result = await runWithWatchdog({ + command: process.execPath, + args: ["-e", code], + stallMs: 300, + onStall: (attempt, max) => stalls.push([attempt, max]), + }); + expect(result.exitCode).toBe(0); + expect(result.stalled).toBe(false); + expect(result.attempts).toBe(2); + expect(stalls).toEqual([[1, 3]]); + }); + + test("gives up after the final attempt with exit code 1", async () => { + const stalls: [number, number][] = []; + const result = await runWithWatchdog({ + command: process.execPath, + args: ["-e", "setTimeout(() => {}, 30_000)"], + stallMs: 300, + attempts: 2, + onStall: (attempt, max) => stalls.push([attempt, max]), + }); + expect(result.exitCode).toBe(1); + expect(result.stalled).toBe(true); + expect(result.attempts).toBe(2); + // The final stall is reported by the exit code, not a retry notice. + expect(stalls).toEqual([[1, 2]]); + }); + + test("kills the whole process group, including the child's own children", async () => { + const dir = mkdtempSync(join(tmpdir(), "test-parallel-group-")); + const pidFile = join(dir, "grandchild.pid"); + const code = ` + const { spawn } = require("node:child_process"); + const fs = require("node:fs"); + const grandchild = spawn("sleep", ["30"], { stdio: "ignore" }); + fs.writeFileSync(${JSON.stringify(pidFile)}, String(grandchild.pid)); + setTimeout(() => {}, 30_000); + `; + const result = await runWithWatchdog({ + command: process.execPath, + args: ["-e", code], + stallMs: 300, + attempts: 1, + }); + expect(result.exitCode).toBe(1); + expect(result.stalled).toBe(true); + + const grandchildPid = Number(readFileSync(pidFile, "utf8")); + // Reaped processes disappear from the pid namespace, but allow a brief + // window for the kernel to reap before concluding the kill failed. + const deadline = Date.now() + 2_000; + while (processAlive(grandchildPid) && Date.now() < deadline) { + await new Promise((r) => setTimeout(r, 50)); + } + expect(processAlive(grandchildPid)).toBe(false); + }); +}); diff --git a/scripts/test-parallel.ts b/scripts/test-parallel.ts new file mode 100644 index 000000000..2e8d3ca34 --- /dev/null +++ b/scripts/test-parallel.ts @@ -0,0 +1,189 @@ +#!/usr/bin/env bun +// Parallel test runner with a stall watchdog. +// +// `bun test --parallel` intermittently livelocks on Bun 1.4.x: a worker +// spins at 100% CPU while a git child it spawned is left as a zombie, and +// the suite produces no further output (upstream Bun issue #36235, still +// open as of 1.4.2). bun test has no run-level timeout, so this wrapper +// runs the suite in its own process group, watches for an output stall +// well beyond any healthy run's silence, kills the group, and retries. +// A child that exits on its own (pass or fail) is never retried. +// +// Usage: bun scripts/test-parallel.ts [workers] (default 4) + +export const DEFAULT_WORKERS = 4; +export const DEFAULT_STALL_MS = 90_000; +export const DEFAULT_ATTEMPTS = 3; +// SIGKILL a group that ignores SIGTERM this long. +const KILL_GRACE_MS = 5_000; + +export interface WatchdogOptions { + // Arguments after the bun binary, e.g. ["test", "./src", "--parallel", "4"]. + args: string[]; + // Bun binary to spawn. Defaults to the running binary. + command?: string; + stallMs?: number; + attempts?: number; + onOutput?: (chunk: Uint8Array, stream: "stdout" | "stderr") => void; + // Report a stall so the caller can log the retry. Defaults to stderr. + onStall?: (attempt: number, maxAttempts: number) => void; +} + +export interface WatchdogResult { + exitCode: number; + stalled: boolean; + attempts: number; +} + +const STALL_CODE = -1; + +function groupAlive(pid: number): boolean { + try { + process.kill(-pid, 0); + return true; + } catch { + return false; + } +} + +async function terminateGroup(pid: number): Promise { + try { + process.kill(-pid, "SIGTERM"); + } catch { + return; + } + const deadline = Date.now() + KILL_GRACE_MS; + while (Date.now() < deadline) { + if (!groupAlive(pid)) return; + await new Promise((r) => setTimeout(r, 200)); + } + try { + process.kill(-pid, "SIGKILL"); + } catch { + // group already gone + } +} + +interface AttemptOutcome { + exitCode: number; + stalled: boolean; +} + +async function runAttempt( + command: string, + args: string[], + stallMs: number, + onOutput: WatchdogOptions["onOutput"], +): Promise { + const child = Bun.spawn([command, ...args], { + stdout: "pipe", + stderr: "pipe", + // Own process group so a stall kills bun test, its workers, and any + // grandchild (e.g. git) together. + detached: true, + }); + + let lastOutput = Date.now(); + let stalled = false; + let exited = false; + + const touch = (chunk: Uint8Array, stream: "stdout" | "stderr") => { + lastOutput = Date.now(); + onOutput?.(chunk, stream); + }; + const pumpStream = async ( + stream: typeof child.stdout, + kind: "stdout" | "stderr", + ): Promise => { + const reader = stream.getReader(); + for (;;) { + const { done, value } = await reader.read(); + if (done) break; + touch(value, kind); + } + }; + const pumps = [ + pumpStream(child.stdout, "stdout"), + pumpStream(child.stderr, "stderr"), + ]; + + const tickMs = Math.max(100, Math.min(5_000, stallMs)); + const watchdog = setInterval(() => { + if (exited) return; + // Re-check liveness: the child may have exited between output and now. + if (!groupAlive(child.pid)) { + exited = true; + return; + } + if (Date.now() - lastOutput > stallMs) { + stalled = true; + clearInterval(watchdog); + void terminateGroup(child.pid); + } + }, tickMs); + + const raw = await child.exited; + exited = true; + clearInterval(watchdog); + await Promise.allSettled(pumps); + // null means killed by a signal; the stalled flag says who did it. + const exitCode = raw === null ? (stalled ? STALL_CODE : 1) : raw; + return { exitCode, stalled }; +} + +export async function runWithWatchdog( + opts: WatchdogOptions, +): Promise { + const stallMs = opts.stallMs ?? DEFAULT_STALL_MS; + const maxAttempts = opts.attempts ?? DEFAULT_ATTEMPTS; + const command = opts.command ?? process.execPath; + const reportStall = + opts.onStall ?? + ((attempt, max) => + console.error( + `[test:parallel] no output for ${Math.round(stallMs / 1000)}s — ` + + `killing stalled run (attempt ${attempt}/${max}); ` + + `Bun --parallel livelock, see Bun issue #36235`, + )); + + for (let attempt = 1; attempt <= maxAttempts; attempt++) { + const { exitCode, stalled } = await runAttempt( + command, + opts.args, + stallMs, + opts.onOutput, + ); + if (!stalled) { + return { exitCode, stalled: false, attempts: attempt }; + } + if (attempt < maxAttempts) reportStall(attempt, maxAttempts); + } + return { exitCode: 1, stalled: true, attempts: maxAttempts }; +} + +if (import.meta.main) { + const arg = process.argv[2]; + const workers = arg === undefined ? DEFAULT_WORKERS : Number(arg); + if (!Number.isInteger(workers) || workers < 1 || workers > 16) { + console.error("usage: bun scripts/test-parallel.ts [workers 1-16]"); + process.exit(2); + } + const result = await runWithWatchdog({ + args: [ + "test", + "./src", + "./tests", + "./evals", + "./scripts", + "--randomize", + "--seed", + "424242", + "--parallel", + String(workers), + ], + onOutput: (chunk, stream) => { + (stream === "stdout" ? process.stdout : process.stderr).write(chunk); + }, + }); + process.exit(result.exitCode); +} diff --git a/src/index.ts b/src/index.ts index 2b745d464..0e6f0a2c5 100644 --- a/src/index.ts +++ b/src/index.ts @@ -135,6 +135,21 @@ let terminating = false; export const RUNTIME_TEARDOWN_DEADLINE_MS = 2_000; +// Production keeps the default; install options let a test process shorten +// the bound so a deliberately never-settling dispose host doesn't pay the +// full 2s of wall clock per test (same pattern as the tool watchdog's +// salvageGraceMs override). +let teardownDeadlineMs = RUNTIME_TEARDOWN_DEADLINE_MS; + +export interface ProcessHandlerOptions { + /** + * Override the bounded-teardown deadline for this process. Production never + * sets it, keeping the 2s default; tests set it short so a never-settling + * dispose host doesn't pay the full deadline in wall clock. + */ + teardownDeadlineMs?: number; +} + async function awaitActiveDisposeHost(context: string): Promise { const dispose = getActiveDisposeHost(); if (dispose === null) return; @@ -145,11 +160,9 @@ async function awaitActiveDisposeHost(context: string): Promise { new Promise((_, reject) => { timer = setTimeout(() => { reject( - new Error( - `runtime teardown exceeded ${RUNTIME_TEARDOWN_DEADLINE_MS}ms`, - ), + new Error(`runtime teardown exceeded ${teardownDeadlineMs}ms`), ); - }, RUNTIME_TEARDOWN_DEADLINE_MS); + }, teardownDeadlineMs); if (typeof timer.unref === "function") timer.unref(); }), ]); @@ -247,7 +260,10 @@ async function finalizeActiveRunOnCrash(error: unknown): Promise { // invokes every registered listener for the event regardless of order, so // these still run and terminate the process even though OpenTUI's own // listener never exits or rethrows. -export function installCrashHandlers(): void { +export function installCrashHandlers(options?: ProcessHandlerOptions): void { + if (options?.teardownDeadlineMs !== undefined) { + teardownDeadlineMs = options.teardownDeadlineMs; + } process.on("uncaughtException", (err) => { void handleFatal("uncaughtException", err); }); @@ -315,7 +331,10 @@ const SIGNAL_EXIT_NUMBER: Record<"SIGINT" | "SIGTERM" | "SIGHUP", number> = { // even when OpenTUI's own listener also runs is harmless. // Exported so an integration test can register these process-level handlers // and send a real signal without spawning the full TUI stack. -export function installSignalHandlers(): void { +export function installSignalHandlers(options?: ProcessHandlerOptions): void { + if (options?.teardownDeadlineMs !== undefined) { + teardownDeadlineMs = options.teardownDeadlineMs; + } for (const signal of ["SIGINT", "SIGTERM", "SIGHUP"] as const) { process.on(signal, () => { if (terminating) return; diff --git a/src/permission/approval-log.test.ts b/src/permission/approval-log.test.ts index 41c6be992..819c669d0 100644 --- a/src/permission/approval-log.test.ts +++ b/src/permission/approval-log.test.ts @@ -53,8 +53,8 @@ describe("createApprovalLog", () => { now += 100; // operator decides ask.settle("allow-with-scope"); - // Appends are fire-and-forget; give the microtask queue a turn to flush. - await new Promise((r) => setTimeout(r, 10)); + // Appends are fire-and-forget; await the log's tail so the read sees them. + await log.flush(); const [record] = readRecords(dir); expect(record).toBeDefined(); @@ -76,7 +76,7 @@ describe("createApprovalLog", () => { const ask = log.ask({ tool: "write_file", mode: "auto" }); ask.settle("auto-allow"); ask.settle("deny"); - await new Promise((r) => setTimeout(r, 10)); + await log.flush(); expect(readRecords(dir)).toHaveLength(1); }); }); @@ -91,6 +91,7 @@ describe("approval-log wiring through the permission gate", () => { test("logs an auto-deny for a file-mutation shell command in auto mode, with no command text", async () => { const dir = mkdtempSync(join(tmpdir(), "approval-log-gate-")); const cwd = mkdtempSync(join(tmpdir(), "gate-cwd-")); + const log = createApprovalLog(dir); const gate = createPermissionGate({ approvals: [], interactive: false, @@ -98,14 +99,14 @@ describe("approval-log wiring through the permission gate", () => { reactorGated: false, auto: true, cwd, - approvalLog: createApprovalLog(dir), + approvalLog: log, }); const verdict = await gate.evaluate( shellCall("echo hunter2 > /tmp/leaked-secret-file.txt"), ); expect(verdict.allowed).toBe(false); - await new Promise((r) => setTimeout(r, 10)); + await log.flush(); const [record] = readRecords(dir); expect(record).toBeDefined(); expect(defined(record).mode).toBe("auto"); @@ -119,13 +120,14 @@ describe("approval-log wiring through the permission gate", () => { test("logs an interactive allow-once with no command text in the record", async () => { const dir = mkdtempSync(join(tmpdir(), "approval-log-gate-")); const cwd = mkdtempSync(join(tmpdir(), "gate-cwd-")); + const log = createApprovalLog(dir); const gate = createPermissionGate({ approvals: [], interactive: true, skipPermissions: false, reactorGated: false, cwd, - approvalLog: createApprovalLog(dir), + approvalLog: log, requestApproval: async (request) => { request.markDisplayed?.(); return { allow: true }; @@ -136,7 +138,7 @@ describe("approval-log wiring through the permission gate", () => { ); expect(verdict.allowed).toBe(true); - await new Promise((r) => setTimeout(r, 10)); + await log.flush(); const [record] = readRecords(dir); expect(record).toBeDefined(); expect(defined(record).mode).toBe("interactive"); @@ -150,18 +152,19 @@ describe("approval-log wiring through the permission gate", () => { test("logs deny with non-interactive rule when no operator is attached", async () => { const dir = mkdtempSync(join(tmpdir(), "approval-log-gate-")); const cwd = mkdtempSync(join(tmpdir(), "gate-cwd-")); + const log = createApprovalLog(dir); const gate = createPermissionGate({ approvals: [], interactive: false, skipPermissions: false, reactorGated: false, cwd, - approvalLog: createApprovalLog(dir), + approvalLog: log, }); const verdict = await gate.evaluate(shellCall("curl https://example.com")); expect(verdict.allowed).toBe(false); - await new Promise((r) => setTimeout(r, 10)); + await log.flush(); const [record] = readRecords(dir); expect(record).toBeDefined(); expect(defined(record).outcome).toBe("deny"); @@ -180,13 +183,14 @@ describe("approval-log wiring through the permission gate", () => { await import("../subagent/identity-context.js"); const dir = mkdtempSync(join(tmpdir(), "approval-log-gate-")); const cwd = mkdtempSync(join(tmpdir(), "gate-cwd-")); + const log = createApprovalLog(dir); const gate = createPermissionGate({ approvals: [], interactive: true, skipPermissions: false, reactorGated: false, cwd, - approvalLog: createApprovalLog(dir), + approvalLog: log, requestApproval: async (request) => { request.markDisplayed?.(); return { allow: true }; @@ -202,7 +206,7 @@ describe("approval-log wiring through the permission gate", () => { ); expect(verdict.allowed).toBe(true); - await new Promise((r) => setTimeout(r, 10)); + await log.flush(); const [record] = readRecords(dir); expect(record).toBeDefined(); expect(Object.keys(defined(record))).not.toContain("agentLabel"); @@ -225,7 +229,7 @@ describe("approval-log record size cap", () => { rule: "x".repeat(10_000), }); ask.settle("allow-once"); - await new Promise((r) => setTimeout(r, 10)); + await log.flush(); expect(readRecords(dir)).toHaveLength(0); }); }); diff --git a/src/permission/approval-log.ts b/src/permission/approval-log.ts index 538369fb5..027065a8f 100644 --- a/src/permission/approval-log.ts +++ b/src/permission/approval-log.ts @@ -133,7 +133,7 @@ export const NOOP_APPROVAL_LOG: ApprovalLog = { export function createApprovalLog( dir: string, now: () => Date = () => new Date(), -): ApprovalLog { +): ApprovalLog & { flush: () => Promise } { const path = join(dir, APPROVAL_LOG_FILE); const log = getLogger(`${LOG_NAMESPACE_ROOT}:approval-log`); let tail: Promise = Promise.resolve(); @@ -187,5 +187,9 @@ export function createApprovalLog( }, }; }, + // Resolves once every append issued so far has settled. The decision + // path never awaits it; tests use it instead of a sleep to read the + // log deterministically. + flush: () => tail, }; } diff --git a/src/plugins/permission-plugin.test.ts b/src/plugins/permission-plugin.test.ts index 84a51d6db..1d2f967ac 100644 --- a/src/plugins/permission-plugin.test.ts +++ b/src/plugins/permission-plugin.test.ts @@ -9,7 +9,11 @@ import { createApprovalLog, } from "../permission/approval-log.js"; import { BLOCKED_BY_POLICY_PREFIX } from "../permission/decline-markers.js"; -import { createPermissionGate } from "../permission/gate.js"; +import { + createPermissionGate, + type PermissionGate, + type PermissionGateOptions, +} from "../permission/gate.js"; import { gateToolCall, permissionPlugin } from "./permission-plugin.js"; function shellCall(command: string): ToolCall { @@ -48,6 +52,32 @@ function readApprovalRecords(dir: string): Record[] { .map((l) => JSON.parse(l) as Record); } +// requestApproval for the reactor-gated tests: it must never be invoked. +const refuseApproval = async () => { + throw new Error("requestApproval must not be invoked under reactor gating"); +}; + +// Gate bound to a fresh approval log so a test can await the log's +// fire-and-forget appends (log.flush) before reading the records file. +function approvalGate( + dir: string, + cwd: string, + overrides: Partial = {}, +): { gate: PermissionGate; log: ReturnType } { + const log = createApprovalLog(dir); + const gate = createPermissionGate({ + approvals: [], + interactive: true, + skipPermissions: false, + reactorGated: true, + auto: true, + cwd, + approvalLog: log, + ...overrides, + }); + return { gate, log }; +} + describe("gateToolCall", () => { test("reactor-gated authz hard-deny blocks and skips next", async () => { const gate = createPermissionGate({ @@ -157,19 +187,8 @@ describe("gateToolCall", () => { test("reactor-gated auto-allow records once across authorizeCall then gateToolCall", async () => { const dir = mkdtempSync(join(tmpdir(), "approval-log-reactor-")); const cwd = mkdtempSync(join(tmpdir(), "gate-cwd-")); - const gate = createPermissionGate({ - approvals: [], - interactive: true, - skipPermissions: false, - reactorGated: true, - auto: true, - cwd, - approvalLog: createApprovalLog(dir), - requestApproval: async () => { - throw new Error( - "requestApproval must not be invoked under reactor gating", - ); - }, + const { gate, log } = approvalGate(dir, cwd, { + requestApproval: refuseApproval, }); const call: ToolCall = { id: "write-1", @@ -187,7 +206,7 @@ describe("gateToolCall", () => { ); expect(result.isError).not.toBe(true); expect(wasCalled()).toBe(true); - await new Promise((r) => setTimeout(r, 10)); + await log.flush(); const records = readApprovalRecords(dir); expect(records).toHaveLength(1); expect(records[0]?.outcome).toBe("auto-allow"); @@ -196,19 +215,8 @@ describe("gateToolCall", () => { test("reactor-gated auto-shell deny records once across authorizeCall then gateToolCall", async () => { const dir = mkdtempSync(join(tmpdir(), "approval-log-reactor-")); const cwd = mkdtempSync(join(tmpdir(), "gate-cwd-")); - const gate = createPermissionGate({ - approvals: [], - interactive: true, - skipPermissions: false, - reactorGated: true, - auto: true, - cwd, - approvalLog: createApprovalLog(dir), - requestApproval: async () => { - throw new Error( - "requestApproval must not be invoked under reactor gating", - ); - }, + const { gate, log } = approvalGate(dir, cwd, { + requestApproval: refuseApproval, }); const call = shellCall("echo x | tee src/a.ts"); const first = await gate.authorizeCall(call); @@ -223,7 +231,7 @@ describe("gateToolCall", () => { expect(result.isError).toBe(true); expect(result.content).toContain(BLOCKED_BY_POLICY_PREFIX); expect(wasCalled()).toBe(false); - await new Promise((r) => setTimeout(r, 10)); + await log.flush(); const records = readApprovalRecords(dir); expect(records).toHaveLength(1); expect(records[0]?.outcome).toBe("auto-deny"); @@ -232,13 +240,9 @@ describe("gateToolCall", () => { test("reactor-gated headless deny records once across authorizeCall then gateToolCall", async () => { const dir = mkdtempSync(join(tmpdir(), "approval-log-reactor-")); const cwd = mkdtempSync(join(tmpdir(), "gate-cwd-")); - const gate = createPermissionGate({ - approvals: [], + const { gate, log } = approvalGate(dir, cwd, { interactive: false, - skipPermissions: false, - reactorGated: true, - cwd, - approvalLog: createApprovalLog(dir), + auto: false, }); const call = shellCall("curl https://example.com"); const first = await gate.authorizeCall(call); @@ -253,7 +257,7 @@ describe("gateToolCall", () => { expect(result.isError).toBe(true); expect(result.content).toContain(BLOCKED_BY_POLICY_PREFIX); expect(wasCalled()).toBe(false); - await new Promise((r) => setTimeout(r, 10)); + await log.flush(); const records = readApprovalRecords(dir); expect(records).toHaveLength(1); expect(records[0]?.outcome).toBe("deny"); @@ -262,19 +266,8 @@ describe("gateToolCall", () => { test("nested posix with reused call.id records each auto-allow", async () => { const dir = mkdtempSync(join(tmpdir(), "approval-log-reactor-")); const cwd = mkdtempSync(join(tmpdir(), "gate-cwd-")); - const gate = createPermissionGate({ - approvals: [], - interactive: true, - skipPermissions: false, - reactorGated: true, - auto: true, - cwd, - approvalLog: createApprovalLog(dir), - requestApproval: async () => { - throw new Error( - "requestApproval must not be invoked under reactor gating", - ); - }, + const { gate, log } = approvalGate(dir, cwd, { + requestApproval: refuseApproval, }); const first: ToolCall = { id: "codex-proxy", @@ -296,7 +289,7 @@ describe("gateToolCall", () => { .isError, ).not.toBe(true); expect(wasCalled()).toBe(true); - await new Promise((r) => setTimeout(r, 10)); + await log.flush(); const records = readApprovalRecords(dir); expect(records).toHaveLength(2); expect(records[0]?.outcome).toBe("auto-allow"); @@ -306,19 +299,8 @@ describe("gateToolCall", () => { test("nested posix with reused call.id records each auto-deny and blocks", async () => { const dir = mkdtempSync(join(tmpdir(), "approval-log-reactor-")); const cwd = mkdtempSync(join(tmpdir(), "gate-cwd-")); - const gate = createPermissionGate({ - approvals: [], - interactive: true, - skipPermissions: false, - reactorGated: true, - auto: true, - cwd, - approvalLog: createApprovalLog(dir), - requestApproval: async () => { - throw new Error( - "requestApproval must not be invoked under reactor gating", - ); - }, + const { gate, log } = approvalGate(dir, cwd, { + requestApproval: refuseApproval, }); const first: ToolCall = { id: "codex-proxy", @@ -348,7 +330,7 @@ describe("gateToolCall", () => { expect(firstResult.content).toContain(BLOCKED_BY_POLICY_PREFIX); expect(secondResult.content).toContain(BLOCKED_BY_POLICY_PREFIX); expect(run.wasCalled()).toBe(false); - await new Promise((r) => setTimeout(r, 10)); + await log.flush(); const records = readApprovalRecords(dir); expect(records).toHaveLength(2); expect(records[0]?.outcome).toBe("auto-deny"); @@ -358,19 +340,9 @@ describe("gateToolCall", () => { test("colliding reused call.id does not inherit allow onto a different tool", async () => { const dir = mkdtempSync(join(tmpdir(), "approval-log-reactor-")); const cwd = mkdtempSync(join(tmpdir(), "gate-cwd-")); - const gate = createPermissionGate({ + const { gate, log } = approvalGate(dir, cwd, { approvals: [{ tool: "shell", pattern: "shell" }], - interactive: true, - skipPermissions: false, - reactorGated: true, - auto: true, - cwd, - approvalLog: createApprovalLog(dir), - requestApproval: async () => { - throw new Error( - "requestApproval must not be invoked under reactor gating", - ); - }, + requestApproval: refuseApproval, }); const outer: ToolCall = { id: "codex-proxy", @@ -393,7 +365,7 @@ describe("gateToolCall", () => { expect(result.isError).toBe(true); expect(result.content).toContain(BLOCKED_BY_POLICY_PREFIX); expect(wasCalled()).toBe(false); - await new Promise((r) => setTimeout(r, 10)); + await log.flush(); const records = readApprovalRecords(dir); expect(records).toHaveLength(1); expect(records[0]?.outcome).toBe("auto-deny"); @@ -402,19 +374,9 @@ describe("gateToolCall", () => { test("colliding reused call.id does not inherit allow onto different args", async () => { const dir = mkdtempSync(join(tmpdir(), "approval-log-reactor-")); const cwd = mkdtempSync(join(tmpdir(), "gate-cwd-")); - const gate = createPermissionGate({ + const { gate, log } = approvalGate(dir, cwd, { approvals: [{ tool: "run_shell", pattern: "echo hello" }], - interactive: true, - skipPermissions: false, - reactorGated: true, - auto: true, - cwd, - approvalLog: createApprovalLog(dir), - requestApproval: async () => { - throw new Error( - "requestApproval must not be invoked under reactor gating", - ); - }, + requestApproval: refuseApproval, }); const granted: ToolCall = { id: "codex-proxy", @@ -437,7 +399,7 @@ describe("gateToolCall", () => { expect(result.isError).toBe(true); expect(result.content).toContain(BLOCKED_BY_POLICY_PREFIX); expect(wasCalled()).toBe(false); - await new Promise((r) => setTimeout(r, 10)); + await log.flush(); const records = readApprovalRecords(dir); expect(records).toHaveLength(1); expect(records[0]?.outcome).toBe("auto-deny"); @@ -446,19 +408,8 @@ describe("gateToolCall", () => { test("authorizeCall apply_patch then nested posix with reused id each record", async () => { const dir = mkdtempSync(join(tmpdir(), "approval-log-reactor-")); const cwd = mkdtempSync(join(tmpdir(), "gate-cwd-")); - const gate = createPermissionGate({ - approvals: [], - interactive: true, - skipPermissions: false, - reactorGated: true, - auto: true, - cwd, - approvalLog: createApprovalLog(dir), - requestApproval: async () => { - throw new Error( - "requestApproval must not be invoked under reactor gating", - ); - }, + const { gate, log } = approvalGate(dir, cwd, { + requestApproval: refuseApproval, }); const outer: ToolCall = { id: "apply-1", @@ -488,7 +439,7 @@ describe("gateToolCall", () => { .isError, ).not.toBe(true); expect(wasCalled()).toBe(true); - await new Promise((r) => setTimeout(r, 10)); + await log.flush(); const records = readApprovalRecords(dir); expect(records).toHaveLength(3); expect(records.map((r) => r.outcome)).toEqual([ @@ -501,19 +452,8 @@ describe("gateToolCall", () => { test("leftover authorizeCall is cleared by reset so a later gateToolCall records", async () => { const dir = mkdtempSync(join(tmpdir(), "approval-log-reactor-")); const cwd = mkdtempSync(join(tmpdir(), "gate-cwd-")); - const gate = createPermissionGate({ - approvals: [], - interactive: true, - skipPermissions: false, - reactorGated: true, - auto: true, - cwd, - approvalLog: createApprovalLog(dir), - requestApproval: async () => { - throw new Error( - "requestApproval must not be invoked under reactor gating", - ); - }, + const { gate, log } = approvalGate(dir, cwd, { + requestApproval: refuseApproval, }); const call: ToolCall = { id: "write-1", @@ -531,7 +471,7 @@ describe("gateToolCall", () => { ); expect(result.isError).not.toBe(true); expect(wasCalled()).toBe(true); - await new Promise((r) => setTimeout(r, 10)); + await log.flush(); const records = readApprovalRecords(dir); expect(records).toHaveLength(2); expect(records[0]?.outcome).toBe("auto-allow"); diff --git a/src/subagent/nudge-director.test.ts b/src/subagent/nudge-director.test.ts index 81de176d9..8b70fc41f 100644 --- a/src/subagent/nudge-director.test.ts +++ b/src/subagent/nudge-director.test.ts @@ -26,6 +26,12 @@ const longState = { ), } as unknown as ReactorState; +// These tests are not about stall timing. With the default real clock, a +// parallel-run load gap over the 30 ms stall window between awaited +// decides would trip a spurious stall nudge on the empty continuation +// pings, so freeze time instead. +const frozenNow = () => 0; + function capabilities(): ReactorCapabilities { return { infer: (options) => @@ -314,6 +320,7 @@ describe("SubAgentDirector tool failure recovery", () => { continuations++; }, 30, + frozenNow, ); const caps = capabilities(); @@ -437,6 +444,7 @@ describe("SubAgentDirector tool failure recovery", () => { continuations++; }, 30, + frozenNow, ); const caps = capabilities(); @@ -489,6 +497,7 @@ describe("SubAgentDirector tool failure recovery", () => { continuations++; }, 30, + frozenNow, ); const caps = capabilities(); diff --git a/src/tui/chrome-state.ts b/src/tui/chrome-state.ts index 11b8d271f..1e906ab5f 100644 --- a/src/tui/chrome-state.ts +++ b/src/tui/chrome-state.ts @@ -186,10 +186,18 @@ export interface ChromeZoneContent { export function formatChromeZones( state: ChromeLiveState, nowMs: number = Date.now(), + lingerMs: number = AGENTS_PANEL_LINGER_MS, ): FormattedChromeZones { return { task: null, - agents: formatAgentsPanel(state.agents, state.observe, nowMs), + agents: formatAgentsPanel( + state.agents, + state.observe, + nowMs, + AGENTS_PANEL_MAX_VISIBLE, + DEFAULT_STALL_MS, + lingerMs, + ), }; } diff --git a/src/tui/dynamic-tool-runner.ts b/src/tui/dynamic-tool-runner.ts index 1cf523de1..79e0972a6 100644 --- a/src/tui/dynamic-tool-runner.ts +++ b/src/tui/dynamic-tool-runner.ts @@ -117,7 +117,12 @@ export function createDynamicToolRunner( }; } }, - { waitForApproval }, + { + waitForApproval, + ...(watchdogConfig?.salvageGraceMs !== undefined + ? { salvageGraceMs: watchdogConfig.salvageGraceMs } + : {}), + }, ); // Every tool result — posix, MCP, or built-in — passes through this single // dispatch point before reaching the reactor/renderer, so it is the one diff --git a/src/tui/product-host.test.ts b/src/tui/product-host.test.ts index 343428c90..eb1e47153 100644 --- a/src/tui/product-host.test.ts +++ b/src/tui/product-host.test.ts @@ -6,7 +6,6 @@ import { EventEmitter } from "node:events"; import { describe, expect, test } from "bun:test"; import type { KeyEvent } from "@opentui/core"; import type { PermissionRequest } from "../permission/types.js"; -import { AGENTS_PANEL_LINGER_MS } from "./chrome-state.js"; import { createHarness } from "./harness.js"; import { acceptOverlaySelection } from "./shell/overlay-host.js"; import { @@ -297,10 +296,16 @@ describe("mountProductHost", () => { } }); + // Production holds finished rows for 4s; a short override keeps the + // assertion (sticky poll clears the zone once linger expires, no + // setChrome) identical without paying the full window in wall clock. + const TEST_AGENTS_PANEL_LINGER_MS = 300; + test("sticky ticks clear the agents zone after linger without setChrome", async () => { const now = Date.now(); const { host, renderOnce, captureCharFrame, destroyHarness } = await mountHeadless({ + agentsPanelLingerMs: TEST_AGENTS_PANEL_LINGER_MS, chrome: { agents: [ { @@ -321,7 +326,9 @@ describe("mountProductHost", () => { expect(captureCharFrame()).toContain("map callers"); // Only sticky poll may clear — no setChrome. Wait past linger + one tick. - await new Promise((r) => setTimeout(r, AGENTS_PANEL_LINGER_MS + 500)); + await new Promise((r) => + setTimeout(r, TEST_AGENTS_PANEL_LINGER_MS + 500), + ); await renderOnce(); expect(host.shell.layout.heights.agents).toBe(0); expect(captureCharFrame()).not.toContain("map callers"); diff --git a/src/tui/product-host.ts b/src/tui/product-host.ts index a54a6be6c..b88bff653 100644 --- a/src/tui/product-host.ts +++ b/src/tui/product-host.ts @@ -19,6 +19,7 @@ import { openAddProviderOverlay, openModelPickerOverlay } from "./overlays.js"; import { wireGates } from "./gate-wire.js"; import { createSystemClipboard } from "./system-clipboard.js"; import { + AGENTS_PANEL_LINGER_MS, agentsChromeNeedsSticky, formatChromeZones, type ChromeLiveState, @@ -165,6 +166,13 @@ export interface ProductHostConfig { readonly onCommand?: (name: string) => void; /** Optional initial chrome snapshot. */ readonly chrome?: ChromeLiveState | null; + /** + * Override the agents-strip post-finish linger window. Production never sets + * it, keeping the 4s default; tests set it short so the sticky-poll linger + * test doesn't pay the full window in wall clock (same pattern as the tool + * watchdog's salvageGraceMs override). + */ + readonly agentsPanelLingerMs?: number; /** * Resolves the live subagent session for the palette "observe" action. * Unset falls back to the shell's demo fixture — production must supply @@ -339,13 +347,18 @@ export async function mountProductHost( // Live chrome is pushed by the caller; the subagent store owns per-agent // tool state (name + clock), so the host paints zones straight from it. + const agentsPanelLingerMs = + config.agentsPanelLingerMs ?? AGENTS_PANEL_LINGER_MS; let chromeState: ChromeLiveState | null = config.chrome ?? null; const paintChromeZones = (): void => { if (chromeState === null) { setChromeZones(shell, { task: null, agents: null }); return; } - setChromeZones(shell, formatChromeZones(chromeState)); + setChromeZones( + shell, + formatChromeZones(chromeState, Date.now(), agentsPanelLingerMs), + ); }; if (chromeState !== null) paintChromeZones(); @@ -362,7 +375,11 @@ export async function mountProductHost( // strip never clears when linger expires without a store notify. let stickyWasNeeded = chromeState !== null && - agentsChromeNeedsSticky(chromeState.agents, Date.now()); + agentsChromeNeedsSticky( + chromeState.agents, + Date.now(), + agentsPanelLingerMs, + ); const stickyPoll = setInterval(() => { if (disposed) return; try { @@ -372,7 +389,11 @@ export async function mountProductHost( // false→true edges both paint via the stickyWasNeeded latch below. const stickyNeeded = chromeState !== null && - agentsChromeNeedsSticky(chromeState.agents, Date.now()); + agentsChromeNeedsSticky( + chromeState.agents, + Date.now(), + agentsPanelLingerMs, + ); if (stickyNeeded || stickyWasNeeded) { paintChrome(shell); } diff --git a/src/tui/tool-execution-watchdog.test.ts b/src/tui/tool-execution-watchdog.test.ts index 0f4264bef..09ed0adfa 100644 --- a/src/tui/tool-execution-watchdog.test.ts +++ b/src/tui/tool-execution-watchdog.test.ts @@ -347,7 +347,7 @@ describe("tool execution watchdog", () => { () => new Promise(() => undefined), // never resolves — wedged server ), ], - { mcpTimeoutMs: 30 }, + { mcpTimeoutMs: 30, salvageGraceMs: TEST_SALVAGE_GRACE_MS }, ); const result = await runner.run( { id: "1", name: "mcp__linear__get_issue", arguments: {} }, @@ -369,7 +369,7 @@ describe("tool execution watchdog", () => { ), stringTool("mcp__linear__list_issues", async () => "ok"), ], - { mcpTimeoutMs: 30 }, + { mcpTimeoutMs: 30, salvageGraceMs: TEST_SALVAGE_GRACE_MS }, ); const signal = new AbortController().signal; const [hung1, hung2, fast] = await Promise.all([ diff --git a/src/tui/tool-execution-watchdog.ts b/src/tui/tool-execution-watchdog.ts index f958689c5..01069d57f 100644 --- a/src/tui/tool-execution-watchdog.ts +++ b/src/tui/tool-execution-watchdog.ts @@ -31,6 +31,13 @@ export interface ToolWatchdogConfig { * changes the bound, it never leaves it unarmed. */ mcpTimeoutMs?: number; + /** + * Override the post-abort salvage grace for runs dispatched through a + * runner built from this config. Production never sets it, keeping the + * 5s default; tests set it short so never-settling tool cases don't pay + * the full grace in wall clock. + */ + salvageGraceMs?: number; } // Default wall-clock budget for a single MCP tool call when settings.mcp.timeoutMs diff --git a/src/tui/transcript-anchor.test.ts b/src/tui/transcript-anchor.test.ts index 52d411afd..7a8baf7f1 100644 --- a/src/tui/transcript-anchor.test.ts +++ b/src/tui/transcript-anchor.test.ts @@ -6,10 +6,30 @@ */ import { describe, expect, test } from "bun:test"; import { withTestRenderer } from "./harness"; +import type { Harness } from "./harness"; import { appendStreamRow } from "./shell/chrome"; import { createAppShell } from "./shell/index"; import type { AppShell } from "./shell/internals"; +/** + * Render until `needle` appears in the character frame, or the deadline + * elapses. Markdown bodies highlight asynchronously via the tree-sitter + * worker, whose startup/IPC can exceed a fixed sleep under --parallel load. + */ +async function frameWith( + h: Harness, + needle: string, + timeoutMs = 3_000, +): Promise { + const deadline = Date.now() + timeoutMs; + for (;;) { + await h.renderOnce(); + const frame = h.captureCharFrame(); + if (frame.includes(needle) || Date.now() > deadline) return frame; + await new Promise((resolve) => setTimeout(resolve, 25)); + } +} + /** Index of the first line whose trimmed content starts with `needle`. */ function lineIndex(frame: string, needle: string): number { return frame.split("\n").findIndex((l) => l.trimStart().startsWith(needle)); @@ -43,10 +63,10 @@ async function paint( for (let i = 0; i < rowCount; i++) { appendStreamRow(shell, { role: "assistant", text: `line ${i}` }); } - // Markdown bodies highlight asynchronously. - await new Promise((resolve) => setTimeout(resolve, 250)); - await h.renderOnce(); - inspect(h.captureCharFrame(), shell); + // Markdown bodies highlight asynchronously; wait for the newest row + // to actually paint instead of sleeping a fixed window. + const frame = await frameWith(h, `line ${rowCount - 1}`); + inspect(frame, shell); } finally { shell.dispose(); } @@ -98,16 +118,12 @@ describe("transcript bottom-anchoring", () => { for (let i = 0; i < 3; i++) { appendStreamRow(shell, { role: "assistant", text: `line ${i}` }); } - await new Promise((resolve) => setTimeout(resolve, 250)); - await h.renderOnce(); - const before = h.captureCharFrame(); + const before = await frameWith(h, "line 2"); const promptTopBefore = promptTopIndex(before); const rowTwoBefore = before.split("\n")[promptTopBefore - 1] ?? ""; appendStreamRow(shell, { role: "assistant", text: "line 3" }); - await new Promise((resolve) => setTimeout(resolve, 250)); - await h.renderOnce(); - const after = h.captureCharFrame(); + const after = await frameWith(h, "line 3"); const promptTopAfter = promptTopIndex(after); const rowTwoAfter = after.split("\n")[promptTopAfter - 2] ?? ""; diff --git a/tests/fixtures/exec-shutdown-reap/simulate-reap.ts b/tests/fixtures/exec-shutdown-reap/simulate-reap.ts index 559c3c5a9..ba9f03b95 100644 --- a/tests/fixtures/exec-shutdown-reap/simulate-reap.ts +++ b/tests/fixtures/exec-shutdown-reap/simulate-reap.ts @@ -23,12 +23,18 @@ const disposeCountPath = countPath; // Handlers must be installed before READY. Importing src/index.js is slow, and // the parent sends the signal as soon as it sees READY. +// +// The dispose host's agent.close() deliberately never settles, so the +// handler's bounded-teardown deadline is the only exit for the crash and +// signal paths. Shorten it so those tests don't pay the production 2s in +// wall clock; production never sets the option and keeps the 2s default. +const TEST_TEARDOWN_DEADLINE_MS = 200; if (exitPath === "crash") { const { installCrashHandlers } = await import("../../../src/index.js"); - installCrashHandlers(); + installCrashHandlers({ teardownDeadlineMs: TEST_TEARDOWN_DEADLINE_MS }); } else if (exitPath === "signal") { const { installSignalHandlers } = await import("../../../src/index.js"); - installSignalHandlers(); + installSignalHandlers({ teardownDeadlineMs: TEST_TEARDOWN_DEADLINE_MS }); } const fallback = async (call: ToolCall): Promise => ({