diff --git a/src/studio/auto-launch.ts b/src/studio/auto-launch.ts index 787e1ac8..3908b46d 100644 --- a/src/studio/auto-launch.ts +++ b/src/studio/auto-launch.ts @@ -42,6 +42,34 @@ const AUTO_LAUNCH_ENV = 'WIGOLO_STUDIO_AUTO_LAUNCH'; const DEFAULT_TIMEOUT_MS = 30_000; const DEFAULT_POLL_MS = 250; +/** + * How long a launch that produced no handle is remembered. + * + * SHORT ON PURPOSE. Every failure mode behind it is one a human fixes in seconds — `chmod +x`, an + * approved Gatekeeper dialog, a reinstall, starting the app by hand — so the memo must not outlive + * the fix. Long enough that one fan-out pays the timeout once; short enough that the next fan-out + * re-checks. A handle appearing invalidates it immediately, which is what keeps it a memo rather + * than a lockout, so this number only bounds the no-signal case. + */ +const DEFAULT_NO_HANDLE_MEMO_MS = 60_000; + +/** + * What a launcher reports back, and the reason it is not a bare boolean. + * + * A boolean can only answer "did I attempt a start", which leaves the caller blind to the failure + * that arrives AFTER the attempt: `spawn` reports ENOENT/EACCES/EPERM by emitting `'error'` on a + * later tick, so by then the launcher has returned `true` and the handle poll is already running + * against a process that is already dead. That failure is observed — the listener {@link + * defaultLaunch} must attach anyway sees it — it just had nowhere to be reported to. `failed()` is + * that somewhere: a probe the poll reads each tick. + */ +export interface LaunchOutcome { + /** False means DECLINED — nothing was started, so there is nothing to wait for. */ + started: boolean; + /** True once the spawn has reported an asynchronous failure. Polled, not awaited. */ + failed: () => boolean; +} + export interface AutoLaunchDeps { dataDir?: string; /** @@ -49,14 +77,20 @@ export interface AutoLaunchDeps { * * Returning `false` means DECLINED — nothing was started, so there is nothing to wait for. Any * other return (including `void`) means a start was attempted and the handle poll is worth - * running. See {@link defaultLaunch} for why a launcher that answered `launchable` can still - * decline. + * running. A {@link LaunchOutcome} says both, and additionally lets the poll give up early on a + * start that has since died. See {@link defaultLaunch} for why a launcher that answered + * `launchable` can still decline. */ - launch?: () => boolean | void; + launch?: () => boolean | void | LaunchOutcome; /** True when the substrate can actually be started on this machine. Injectable. */ launchable?: () => boolean; timeoutMs?: number; pollMs?: number; + /** + * How long a launch that produced no handle is remembered. `0` disables the memo — the shape the + * pre-memo suite asserts, and the escape hatch for a caller that genuinely wants every attempt. + */ + memoMs?: number; sleep?: (ms: number) => Promise; readHandleFn?: (dataDir?: string) => SessionHandle | null; } @@ -140,20 +174,33 @@ export function studioLaunchable(): boolean { * find nothing. It declines rather than throwing, for the same reason `ensureStudioRunning` never throws — * a launch problem must not become the caller's error. * - * ⚠ THE DECLINE IS RETURNED, and that return is load-bearing. `studioLaunchable()` answers from - * `substratePresent()`, which memoizes for 5 s; this function reads the record uncached. Uninstall the - * substrate and for the rest of that TTL window the gate says yes and the launcher finds nothing — - * so a decline here is a NORMAL outcome, not a defect. When it was a bare `return`, the caller could - * not tell it apart from a spawn that had yet to publish and sat out the entire 30 s poll budget with - * no process running, once per TTL window, on the fetch path. Saying "declined" costs one boolean and - * closes the window; widening the presence TTL or plumbing a shared probe would both reach further - * than this file. + * ⚠ THIS RETURN IS LOAD-BEARING, AND IT CLOSES TWO DIFFERENT WINDOWS — one each, by a different + * mechanism. Unreported, both end the same way: `ensureStudioRunning` enters the handle poll and + * waits out the full 30 s budget for a handle no live process will ever write, on the fetch path. + * + * 1. NOTHING WAS STARTED — closed by `started: false`. `studioLaunchable()` answers from + * `substratePresent()`, which memoizes for 5 s; this function reads the record uncached. + * Uninstall the substrate and for the rest of that TTL window the gate says yes and the launcher + * finds nothing, so a decline here is a NORMAL outcome rather than a defect. Reported, the caller + * skips the poll entirely and pays zero ticks. Widening the presence TTL or plumbing a shared + * probe would both reach further than this file. + * 2. SOMETHING WAS STARTED AND DIED — closed by `failed()`. `spawn` does not throw for ENOENT, + * EACCES or EPERM; it hands back a child and emits `'error'` on a later tick, by which point + * this function has already returned "started". The listener below has to exist regardless — an + * unlistened `'error'` is a dead MCP process, not a logged one — so the failure is already + * observed, and `failed()` is only what carries it to the poll. The poll reads the probe each + * tick and gives up on the tick after the failure lands instead of on tick 120. This is the + * commoner real-world shape: a lost +x bit, a Gatekeeper EPERM, an uninstall mid-crawl. + * + * Neither reaches the residual case — a start that neither declines nor errors and simply never + * publishes, i.e. a genuinely wedged app. That one is bounded by the timeout and then REMEMBERED, so + * a fan-out pays it once rather than per URL; see the negative memo in `ensureStudioRunning`. */ -export function defaultLaunch(deps: DefaultLaunchDeps = {}): boolean { +export function defaultLaunch(deps: DefaultLaunchDeps = {}): LaunchOutcome { const acquired = readSubstrateRecord(deps.dataDir); if (!acquired) { log.debug('studio auto-launch found no acquired substrate to start — declining'); - return false; + return { started: false, failed: () => false }; } // Hidden: an auto-launched session is for the agent's benefit, not a window the human asked for. The // human summons a visible one themselves; a card that needs answering is surfaced by the app. @@ -175,46 +222,95 @@ export function defaultLaunch(deps: DefaultLaunchDeps = {}): boolean { // // The window is narrow — the record's executable was probed on disk at read time — but it is // real: an uninstall between the read and the exec, a lost +x bit, or a Gatekeeper EPERM. + let spawnFailed = false; child.on('error', (err) => { + spawnFailed = true; log.warn('studio auto-launch could not start the desktop component', { error: err instanceof Error ? err.message : String(err), }); }); child.unref(); - return true; + return { started: true, failed: () => spawnFailed }; +} + +const NEVER_FAILED = (): boolean => false; + +/** + * Read any launcher's answer as a {@link LaunchOutcome}. + * + * The three legacy shapes stay legal because `deps.launch` is a test seam and most of the suite has + * no interest in spawn failures: `false` is the decline, `true`/`void` is "started, no failure + * reporting". Only a launcher that actually spawns something can say more, and only `defaultLaunch` + * does. + */ +function normalizeLaunch(result: boolean | void | LaunchOutcome): LaunchOutcome { + if (result === false) return { started: false, failed: NEVER_FAILED }; + if (result && typeof result === 'object') { + return { started: result.started, failed: result.failed ?? NEVER_FAILED }; + } + return { started: true, failed: NEVER_FAILED }; } let inFlight: Promise | null = null; +/** + * When the last launch that produced no handle stops being remembered. `0` means nothing to remember. + * + * `inFlight` IS NOT THIS. Single-flight only collapses launches that OVERLAP — it clears in the + * `finally` — and a crawl does not overlap: `src/fetch/router.ts` reaches the bridge rung once per + * page, sequentially, and `src/fetch/studio-bridge.ts` awaits `ensureStudioRunning` each time. So + * against a substrate that cannot start, 20 challenged pages paid 20 separate budgets: ~10 minutes + * of sleeping and 20 dead spawn attempts for one broken install. The memo is what makes a fan-out + * pay it once. + */ +let noHandleUntil = 0; + /** * Return a live session handle, starting the substrate if it is not running. Returns null when auto-launch is - * disabled, the substrate is absent, or it did not publish a handle inside the budget — never throws, because - * every caller has a degraded path and a launch problem must not become the user's error. + * disabled, the substrate is absent, a recent launch produced no handle, or this one did not publish a handle + * inside the budget — never throws, because every caller has a degraded path and a launch problem must not + * become the user's error. */ export async function ensureStudioRunning(deps: AutoLaunchDeps = {}): Promise { const read = deps.readHandleFn ?? readHandle; const existing = read(deps.dataDir); - if (existing) return existing; + if (existing) { + // AHEAD OF THE MEMO CHECK, and it clears it: a handle on disk is direct evidence that whatever + // stopped the last launch has been resolved — most often a human who started the app by hand + // mid-crawl. Remembering a failure past its own disproof is a lockout, not a memo. + noHandleUntil = 0; + return existing; + } if (process.env[AUTO_LAUNCH_ENV] === '0' || process.env[AUTO_LAUNCH_ENV] === 'false') return null; if (!(deps.launchable ?? studioLaunchable)()) { log.debug('studio substrate not launchable on this machine — declining auto-launch'); return null; } + // AFTER the launchable gate, so an absent substrate is never what gets remembered: that case + // already declines in zero ticks, and folding it in would make a substrate installed mid-session + // wait out a window for no reason. + if (noHandleUntil > Date.now()) { + log.debug('studio auto-launch recently produced no handle — declining without re-launching'); + return null; + } if (inFlight) return inFlight; + const memoMs = deps.memoMs ?? DEFAULT_NO_HANDLE_MEMO_MS; inFlight = (async () => { const timeoutMs = deps.timeoutMs ?? DEFAULT_TIMEOUT_MS; const pollMs = deps.pollMs ?? DEFAULT_POLL_MS; const sleep = deps.sleep ?? ((ms: number) => new Promise((r) => { const t = setTimeout(r, ms); if (typeof t.unref === 'function') t.unref(); })); + let failed: () => boolean; try { - const started = (deps.launch ?? (() => defaultLaunch({ dataDir: deps.dataDir })))(); + const outcome = normalizeLaunch((deps.launch ?? (() => defaultLaunch({ dataDir: deps.dataDir })))()); // An explicit decline means nothing was started, so there is nothing the poll below could ever // see. Waiting out the budget on it is the 30 s stall this branch exists to prevent. - if (started === false) { + if (!outcome.started) { log.debug('studio auto-launch declined — nothing was started, so nothing is polled for'); return null; } + failed = outcome.failed; } catch (err) { log.debug('studio auto-launch failed to spawn', { error: err instanceof Error ? err.message : String(err) }); return null; @@ -225,13 +321,27 @@ export async function ensureStudioRunning(deps: AutoLaunchDeps = {}): Promise= deadline) { log.debug('studio auto-launch did not publish a handle within budget'); return null; } await sleep(pollMs); } - })(); + })().then((handle) => { + // Recorded on the SHARED promise rather than in the first caller's `await` below: the other + // single-flight participants return `inFlight` directly and never reach that code, so putting it + // there would leave the memo down for whoever happened not to be first. + if (!handle && memoMs > 0) noHandleUntil = Date.now() + memoMs; + return handle; + }); try { return await inFlight; } finally { @@ -239,7 +349,8 @@ export async function ensureStudioRunning(deps: AutoLaunchDeps = {}): Promise { }); it('a later call can launch again after the first attempt settled', async () => { + // `memoMs: 0` because this case is about `inFlight` clearing, not about the negative memo that + // would otherwise swallow the second call — see the memo suite at the foot of this file. const launch = vi.fn(); - await ensureStudioRunning({ dataDir: dir, launch, launchable: () => true, timeoutMs: 0, sleep: noSleep }); - await ensureStudioRunning({ dataDir: dir, launch, launchable: () => true, timeoutMs: 0, sleep: noSleep }); + await ensureStudioRunning({ dataDir: dir, launch, launchable: () => true, timeoutMs: 0, memoMs: 0, sleep: noSleep }); + await ensureStudioRunning({ dataDir: dir, launch, launchable: () => true, timeoutMs: 0, memoMs: 0, sleep: noSleep }); expect(launch).toHaveBeenCalledTimes(2); }); }); @@ -266,7 +268,7 @@ describe('a launch that declines must not be polled for', () => { describe('defaultLaunch', () => { it('declines and spawns nothing when no substrate has been acquired', () => { const spawnFn = vi.fn(); - expect(defaultLaunch({ dataDir: dir, spawnFn })).toBe(false); + expect(defaultLaunch({ dataDir: dir, spawnFn }).started).toBe(false); expect(spawnFn).not.toHaveBeenCalled(); }); @@ -276,7 +278,7 @@ describe('defaultLaunch', () => { const on = vi.fn(); const spawnFn = vi.fn(() => ({ unref, on })); - expect(defaultLaunch({ dataDir: dir, spawnFn })).toBe(true); + expect(defaultLaunch({ dataDir: dir, spawnFn }).started).toBe(true); expect(spawnFn).toHaveBeenCalledTimes(1); const [command, args, options] = spawnFn.mock.calls[0] as unknown as [string, string[], Record]; @@ -301,7 +303,7 @@ describe('defaultLaunch', () => { const executable = plantSubstrateRecord(dir); rmSync(executable, { force: true }); const spawnFn = vi.fn(); - expect(defaultLaunch({ dataDir: dir, spawnFn })).toBe(false); + expect(defaultLaunch({ dataDir: dir, spawnFn }).started).toBe(false); expect(spawnFn).not.toHaveBeenCalled(); }); }); @@ -336,7 +338,7 @@ describe('a spawn that fails asynchronously must not kill the process', () => { const order: string[] = []; const child = fakeChild(order); - expect(defaultLaunch({ dataDir: dir, spawnFn: vi.fn(() => child) })).toBe(true); + expect(defaultLaunch({ dataDir: dir, spawnFn: vi.fn(() => child) }).started).toBe(true); // Not merely "a listener exists by the time the test looks" — it existed at the one moment // the launcher hands the child away and stops being able to attach anything. expect(order).toEqual(['unref:errorListeners=1']); @@ -375,3 +377,188 @@ describe('a spawn that fails asynchronously must not kill the process', () => { } }); }); + +/** + * THE DEAD SPAWN, which is the commoner half of the stall and the one the decline fix does not + * reach. + * + * The listener above keeps the process alive, which was #167's whole job, but it only LOGS — and by + * the time it fires, `defaultLaunch` has already returned "started". So `ensureStudioRunning` is + * inside the handle poll waiting on a process that is already dead, and it waits out the entire + * 30 s budget: 120 ticks at the shipped 250 ms cadence, once per challenged URL. + * + * The failure is already OBSERVED — nothing new has to be detected, only reported. The launcher's + * return widens from a bare boolean to an outcome carrying `failed()`, and the poll reads it each + * tick. + */ +describe('a spawn that died must not be polled for the full budget', () => { + /** A stand-in child that can be made to report its failure on a later tick, as `spawn` does. */ + function fakeChild(): EventEmitter & { unref(): void } { + const child = new EventEmitter() as EventEmitter & { unref(): void }; + child.unref = () => {}; + return child; + } + + it('breaks the poll on the tick after the error listener sees the failure', async () => { + plantSubstrateRecord(dir); + const child = fakeChild(); + const stderr = vi.spyOn(process.stderr, 'write').mockImplementation(() => true); + vi.useFakeTimers(); + try { + let ticks = 0; + const sleep = async (ms: number): Promise => { + ticks += 1; + // Emitted from inside the wait, not before it: an ENOENT/EACCES/EPERM spawn hands back a + // child and reports the failure on a later tick, so the poll is already running when it + // lands. Emitting it earlier would test a shape `spawn` never produces. + if (ticks === 1) child.emit('error', new Error('spawn EACCES')); + vi.advanceTimersByTime(ms); + }; + const h = await ensureStudioRunning({ + dataDir: dir, + launch: () => defaultLaunch({ dataDir: dir, spawnFn: vi.fn(() => child) }), + launchable: () => true, + // The SHIPPED budget, not a shrunken one: the stall this closes is only visible against + // 30 s / 250 ms, and a test that pre-shrank it could not tell the fix from the timeout. + timeoutMs: 30_000, + pollMs: 250, + sleep, + }); + expect(h).toBeNull(); + // One tick to let the failure land, then out. Unbroken this is 120. + expect(ticks).toBe(1); + } finally { + vi.useRealTimers(); + stderr.mockRestore(); + } + }); + + it('keeps polling a spawn that has NOT reported a failure', async () => { + // The paired positive arm. Without it, a `failed: () => true` hardwired into the launcher — or + // a poll that bails on the first empty read — satisfies the arm above forever. + plantSubstrateRecord(dir); + const child = fakeChild(); + let ticks = 0; + const sleep = async (): Promise => { if (++ticks === 4) publishHandle(); }; + const h = await ensureStudioRunning({ + dataDir: dir, + launch: () => defaultLaunch({ dataDir: dir, spawnFn: vi.fn(() => child) }), + launchable: () => true, + pollMs: 1, + sleep, + }); + expect(h?.endpoint).toBe(HANDLE.endpoint); + expect(ticks).toBe(4); + }); + + it('a declined launch carries no failure probe to read', async () => { + // The decline arm still short-circuits ahead of the poll, so `failed()` is never consulted on + // it. Pins that widening the return did not move the decline behind the new check. + const spawnFn = vi.fn(); + const outcome = defaultLaunch({ dataDir: dir, spawnFn }); + expect(outcome.started).toBe(false); + expect(outcome.failed()).toBe(false); + expect(spawnFn).not.toHaveBeenCalled(); + }); +}); + +/** + * THE NEGATIVE MEMO, which is the per-URL half of the same stall. + * + * `inFlight` is single-flight, not a cache: it clears in the `finally`, so it only collapses + * launches that OVERLAP. A crawl does not overlap — `src/fetch/router.ts` reaches the bridge rung + * once per page, sequentially, and `src/fetch/studio-bridge.ts` awaits `ensureStudioRunning` each + * time. Against a substrate that cannot start, 20 challenged pages therefore paid 20 separate + * budgets: ~10 minutes of sleeping and 20 dead spawn attempts for one broken install. + * + * So a launch that produced no handle is remembered for ~60 s. Short on purpose: the failure modes + * are things a human fixes in seconds (chmod +x, approve the Gatekeeper dialog, reinstall), and the + * memo must not outlive the fix. A handle appearing invalidates it immediately, which is the arm + * that keeps it from becoming a lockout. + */ +describe('a launch that produced no handle is remembered briefly', () => { + it('costs the second caller zero poll ticks inside the memo window', async () => { + vi.useFakeTimers(); + try { + let ticks = 0; + const sleep = async (ms: number): Promise => { + ticks += 1; + vi.advanceTimersByTime(ms); + }; + const launch = vi.fn(); + const args = { dataDir: dir, launch, launchable: () => true, timeoutMs: 30_000, pollMs: 250, sleep }; + + // The first challenged page pays the budget in full — that part is unchanged, and has to be: + // a wedged-but-live app really might publish on tick 119. + expect(await ensureStudioRunning(args)).toBeNull(); + expect(ticks).toBe(120); + + // The second one is what used to cost another 120. It must not even re-spawn. + const paid = ticks; + expect(await ensureStudioRunning(args)).toBeNull(); + expect(ticks - paid).toBe(0); + expect(launch).toHaveBeenCalledTimes(1); + } finally { + vi.useRealTimers(); + } + }); + + it('expires, so a machine that gets fixed is retried', async () => { + // The paired positive arm. Without it a permanent kill switch — or a bare `return null` at the + // top of the function — satisfies the arm above forever. + vi.useFakeTimers(); + try { + const sleep = async (ms: number): Promise => { vi.advanceTimersByTime(ms); }; + const launch = vi.fn(); + const args = { dataDir: dir, launch, launchable: () => true, timeoutMs: 0, memoMs: 60_000, sleep }; + + expect(await ensureStudioRunning(args)).toBeNull(); + expect(launch).toHaveBeenCalledTimes(1); + + // Still inside the window: memoized. + expect(await ensureStudioRunning(args)).toBeNull(); + expect(launch).toHaveBeenCalledTimes(1); + + vi.advanceTimersByTime(60_001); + expect(await ensureStudioRunning(args)).toBeNull(); + expect(launch).toHaveBeenCalledTimes(2); + } finally { + vi.useRealTimers(); + } + }); + + it('is invalidated by a handle appearing — a human starting the app mid-crawl recovers', async () => { + vi.useFakeTimers(); + try { + const sleep = async (ms: number): Promise => { vi.advanceTimersByTime(ms); }; + const launch = vi.fn(); + const args = { dataDir: dir, launch, launchable: () => true, timeoutMs: 0, sleep }; + + expect(await ensureStudioRunning(args)).toBeNull(); + expect(launch).toHaveBeenCalledTimes(1); + + // The human starts the app themselves, well inside the memo window. The handle read is ahead + // of the memo check, so this call is answered rather than declined. + publishHandle(); + expect((await ensureStudioRunning(args))?.endpoint).toBe(HANDLE.endpoint); + + // …and the memo is GONE, not merely bypassed. When that session ends the next caller launches + // instead of being declined by a memo the recovery should have cleared. + rmSync(join(dir, 'studio', 'current.json'), { force: true }); + expect(await ensureStudioRunning(args)).toBeNull(); + expect(launch).toHaveBeenCalledTimes(2); + } finally { + vi.useRealTimers(); + } + }); + + it('does not memoize a launchable that says no — there was no launch to remember', async () => { + // The memo is about launches that produced nothing, not about machines with no substrate. Those + // already decline in zero ticks at the gate, and folding them in would mean a substrate + // installed mid-session waited out a window for no reason. + const launch = vi.fn(); + expect(await ensureStudioRunning({ dataDir: dir, launch, launchable: () => false, sleep: noSleep })).toBeNull(); + expect(await ensureStudioRunning({ dataDir: dir, launch, launchable: () => true, timeoutMs: 0, sleep: noSleep })).toBeNull(); + expect(launch).toHaveBeenCalledTimes(1); + }); +});