From f4cebe14f5cc87f6d3748e11d40ada565d62474b Mon Sep 17 00:00:00 2001 From: Brennan Benson <79079362+brennanb2025@users.noreply.github.com> Date: Fri, 14 Aug 2026 12:21:35 -0700 Subject: [PATCH] fix(daemon): bound the caller's wait on final durable-history checkpoints (STA-4228) (#14497) * fix(daemon): bound the caller's wait on final durable-history checkpoints (STA-4228) shutdownWithHistoryLock threaded the caller's absolute deadline into ensureConnected and into the kill RPC, but awaited the final keep-history checkpoint between them with no bound at all. Worktree sleep supplies that deadline, so a stalled history write pinned the process-wide checkpoint tail and stranded Sleep Terminals until an app restart. Bound only the caller's wait. The checkpoint itself stays deadline-free: it remains the exclusive tail, runs to completion, and still commits, so nothing durable is cancelled or deferred. On expiry the caller stops awaiting, throws FinalCheckpointWaitExpiredError, and never falls through to the kill, so the PTY stays alive and the stop is reported unverified. * test(daemon): prove final checkpoint deadline outcomes --- src/main/daemon/daemon-pty-adapter.ts | 97 ++++++-- ...n-final-checkpoint-caller-deadline.test.ts | 222 ++++++++++++++++++ 2 files changed, 302 insertions(+), 17 deletions(-) create mode 100644 src/main/daemon/daemon-shutdown-final-checkpoint-caller-deadline.test.ts diff --git a/src/main/daemon/daemon-pty-adapter.ts b/src/main/daemon/daemon-pty-adapter.ts index 04982f9643c..d972f2aeb6e 100644 --- a/src/main/daemon/daemon-pty-adapter.ts +++ b/src/main/daemon/daemon-pty-adapter.ts @@ -179,6 +179,40 @@ function remainingRequestTimeoutMs(deadlineMs: number | undefined): number | und return deadlineMs === undefined ? undefined : Math.max(1, deadlineMs - Date.now()) } +// Why a distinct error: teardown callers must read this as "not proven stopped" and leave the PTY +// alive, not as a kill that failed. It never matches isPtyAlreadyGoneError, so `stopAndWait` reports +// the pty unverified and worktree sleep declines to commit it. +export class FinalCheckpointWaitExpiredError extends Error { + constructor(sessionId: string) { + super(`Final history checkpoint did not settle within the teardown deadline: ${sessionId}`) + this.name = 'FinalCheckpointWaitExpiredError' + } +} + +// Why only the caller's wait is bounded and never the work itself: cancelling durable work would +// silently drop what the user left on screen. This decides how long a caller blocks, nothing more — +// `work` keeps running behind an abandoned wait and still commits. False means the caller gave up. +// A rejection before the deadline still propagates, so a genuinely failed operation is not masked. +async function awaitWithinCallerDeadline( + work: Promise, + deadlineMs: number +): Promise { + // Why up front: once the race is abandoned nothing observes a later rejection here. + void work.catch(() => {}) + let timer: ReturnType | undefined + try { + return await Promise.race([ + work.then(() => true), + new Promise((resolve) => { + timer = setTimeout(() => resolve(false), Math.max(1, deadlineMs - Date.now())) + timer.unref?.() + }) + ]) + } finally { + clearTimeout(timer) + } +} + export class TerminalKilledError extends Error { constructor(sessionId: string) { super(`Session "${sessionId}" was explicitly killed`) @@ -1116,16 +1150,27 @@ export class DaemonPtyAdapter implements IPtyProvider { opts: { immediate?: boolean; keepHistory?: boolean; deadlineMs?: number } ): Promise { // Why: shutdown can be the first lazy-client operation after restart; connect - // before killing so a healthy daemon session is not orphaned (#7742). Connect - // and kill share the caller's one absolute deadline, so a wedged handshake - // cannot burn the whole teardown budget before the kill even starts. + // before killing so a healthy daemon session is not orphaned (#7742). Connect, + // the final-checkpoint wait, and kill all share the caller's one absolute + // deadline, so neither a wedged handshake nor a stalled history write can burn + // the whole teardown budget before the kill even starts. Only the waits are + // bounded — the checkpoint itself stays deadline-free and lossless (STA-4228). await this.ensureConnected(opts.deadlineMs) // Why: sleep/exact-stop kills the live PTY before the periodic checkpoint may run. // Force a final snapshot so wake can restore the pane users left. if (opts.keepHistory) { - await this.runExclusiveCheckpoint(async () => { - await this.checkpointSessions([id], { final: true, teardown: true }) - }) + const committed = await this.runExclusiveCheckpoint( + async () => { + await this.checkpointSessions([id], { final: true, teardown: true }) + }, + { callerDeadlineMs: opts.deadlineMs } + ) + // Why throw instead of killing anyway: the snapshot the caller asked us to prove is still + // being written. Killing here would race the wake-time restore source to disk, so report the + // pty unverified and leave it alive — worktree sleep declines to commit it and retries. + if (!committed) { + throw new FinalCheckpointWaitExpiredError(id) + } const wslDistro = this.wslDistrosBySessionId.get(id) const detection = await this.historyReader?.detectColdRestoreState(id, { wslDistro }) const detected = detection?.status === 'restored' ? detection.restoreInfo : null @@ -2071,25 +2116,43 @@ export class DaemonPtyAdapter implements IPtyProvider { this.stopCheckpointTimerIfIdle() } + /** False only when `callerDeadlineMs` expired first; the checkpoint itself keeps running. */ private async runExclusiveCheckpoint( operation: () => Promise, - options: { rescheduleDirty?: boolean } = {} - ): Promise { + options: { rescheduleDirty?: boolean; callerDeadlineMs?: number } = {} + ): Promise { this.stopCheckpointTimer() // Why: a promise tail keeps every waiter ordered; awaiting one active operation lets sibling waiters resume together. const previous = this.checkpointInFlight ?? Promise.resolve() const checkpoint = previous.catch(() => {}).then(operation) this.checkpointInFlight = checkpoint - try { - await checkpoint - } finally { - if (this.checkpointInFlight === checkpoint) { - this.checkpointInFlight = null - } - this.stopCheckpointTimer() - if (options.rescheduleDirty !== false) { - this.scheduleCheckpointTimer() + // Why the release rides the checkpoint instead of the caller's await: a caller that walks away + // at its deadline must leave this checkpoint as the tail, so the durable write still runs to + // completion, still commits, and the next waiter still queues behind it (STA-4228). + const settled = checkpoint.then( + () => this.releaseExclusiveCheckpoint(checkpoint, options.rescheduleDirty), + (err: unknown) => { + this.releaseExclusiveCheckpoint(checkpoint, options.rescheduleDirty) + throw err } + ) + if (options.callerDeadlineMs === undefined) { + await settled + return true + } + return await awaitWithinCallerDeadline(settled, options.callerDeadlineMs) + } + + private releaseExclusiveCheckpoint( + checkpoint: Promise, + rescheduleDirty: boolean | undefined + ): void { + if (this.checkpointInFlight === checkpoint) { + this.checkpointInFlight = null + } + this.stopCheckpointTimer() + if (rescheduleDirty !== false) { + this.scheduleCheckpointTimer() } } diff --git a/src/main/daemon/daemon-shutdown-final-checkpoint-caller-deadline.test.ts b/src/main/daemon/daemon-shutdown-final-checkpoint-caller-deadline.test.ts new file mode 100644 index 00000000000..679c124e2d6 --- /dev/null +++ b/src/main/daemon/daemon-shutdown-final-checkpoint-caller-deadline.test.ts @@ -0,0 +1,222 @@ +import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest' +import { mkdtempSync, rmSync } from 'node:fs' +import { tmpdir } from 'node:os' +import { join } from 'node:path' +import { DaemonPtyAdapter, FinalCheckpointWaitExpiredError } from './daemon-pty-adapter' +import { DaemonServer } from './daemon-server' +import { getDaemonSocketPath } from './daemon-spawner' +import type { DaemonFileLog } from './daemon-file-log' +import { HistoryReader } from './history-reader' +import type { HistoryCheckpointResult } from './terminal-history-manager-options' +import type { SubprocessHandle } from './session' +import type { TerminalSnapshot } from './types' + +// Worktree sleep threads an absolute deadline into stopAndWait; this stands in for it. +const CALLER_DEADLINE_MS = 300 +// Why well above the deadline it proves: a stop that only settles because the whole suite is slow +// would prove nothing, and a stop that never settles must fail this test rather than hang the run. +const STOP_BUDGET_MS = 8_000 + +function createMockSubprocess(): SubprocessHandle & { emitData: (data: string) => void } { + let onData: ((data: string) => void) | undefined + let onExit: ((code: number) => void) | undefined + return { + pid: 4243, + getForegroundProcess: vi.fn(() => null), + write: vi.fn(), + resize: vi.fn(), + kill: vi.fn(() => setTimeout(() => onExit?.(0), 1)), + forceKill: vi.fn(() => onExit?.(137)), + signal: vi.fn(), + onData(callback) { + onData = callback + }, + onExit(callback) { + onExit = callback + }, + dispose: vi.fn(), + emitData(data) { + onData?.(data) + } + } +} + +/** Resolves 'timed-out' instead of hanging, so a stranded stop fails the test rather than the run. */ +async function withinBudget(work: Promise, budgetMs: number): Promise { + let timer: ReturnType | undefined + const budget = new Promise<'timed-out'>((resolve) => { + timer = setTimeout(() => resolve('timed-out'), budgetMs) + }) + try { + return await Promise.race([work, budget]) + } finally { + clearTimeout(timer) + } +} + +async function rejectionOf(work: Promise): Promise { + try { + await work + } catch (error) { + return error + } + throw new Error('Expected work to reject') +} + +describe('STA-4228 keep-history stop bounds only the caller wait on the final checkpoint', () => { + let dir: string + let server: DaemonServer + let adapter: DaemonPtyAdapter + let subprocesses: ReturnType[] + + beforeEach(async () => { + dir = mkdtempSync(join(tmpdir(), 'orca-final-checkpoint-deadline-')) + subprocesses = [] + const log: DaemonFileLog = { log: () => {}, close: () => {} } + server = new DaemonServer({ + socketPath: getDaemonSocketPath(dir), + tokenPath: join(dir, 'test.token'), + log, + spawnSubprocess: () => { + const subprocess = createMockSubprocess() + subprocesses.push(subprocess) + return subprocess + } + }) + await server.start() + adapter = new DaemonPtyAdapter({ + socketPath: getDaemonSocketPath(dir), + tokenPath: join(dir, 'test.token'), + historyPath: join(dir, 'history') + }) + }) + + afterEach(async () => { + adapter?.dispose() + await server?.shutdown() + rmSync(dir, { recursive: true, force: true }) + }) + + /** Wedges one session's checkpoint at the history-write layer until explicitly released. */ + function stallCheckpointFor(stalledSessionId: string): { release: () => void } { + const manager = adapter.getHistoryManager() + expect(manager).not.toBeNull() + const original = manager!.checkpoint.bind(manager!) + let release = (): void => {} + const stalled = new Promise((resolve) => { + release = resolve + }) + vi.spyOn(manager!, 'checkpoint').mockImplementation( + async ( + sessionId: string, + snapshot: TerminalSnapshot, + opts?: { pendingOutputSeq?: number } + ): Promise => { + if (sessionId !== stalledSessionId) { + return await original(sessionId, snapshot, opts) + } + await stalled + return await original(sessionId, snapshot, opts) + } + ) + return { release } + } + + async function spawnWithOutput(sessionId: string, output: string): Promise { + const { id } = await adapter.spawn({ cols: 80, rows: 24, sessionId, cwd: '/tmp' }) + subprocesses.at(-1)!.emitData(output) + return id + } + + function stopKeepingHistory(id: string): Promise { + return adapter.shutdown(id, { + immediate: true, + keepHistory: true, + deadlineMs: Date.now() + CALLER_DEADLINE_MS + }) + } + + async function onDisk(sessionId: string): Promise { + const restore = await new HistoryReader(join(dir, 'history')).detectColdRestore(sessionId, { + ignoreCleanEnd: true + }) + return `${restore?.scrollbackAnsi ?? ''}${restore?.snapshotAnsi ?? ''}` + } + + it('lets a later keep-history stop settle while an earlier final checkpoint is wedged', async () => { + const wedgedId = await spawnWithOutput('wedged-session', 'WEDGED_OUTPUT\r\n') + const laterId = await spawnWithOutput('later-session', 'LATER_OUTPUT\r\n') + const stall = stallCheckpointFor(wedgedId) + + expect( + await withinBudget(rejectionOf(stopKeepingHistory(wedgedId)), STOP_BUDGET_MS) + ).toBeInstanceOf(FinalCheckpointWaitExpiredError) + // Why issued only now: this is the sleep-stranding case — a stop that starts while the wedged + // checkpoint still owns the exclusive tail, which before this fix waited on it forever. + expect( + await withinBudget(rejectionOf(stopKeepingHistory(laterId)), STOP_BUDGET_MS) + ).toBeInstanceOf(FinalCheckpointWaitExpiredError) + stall.release() + }, 30_000) + + it('leaves the unverified pty alive instead of falling through to the kill', async () => { + const wedgedId = await spawnWithOutput('alive-session', 'ALIVE_OUTPUT\r\n') + const stall = stallCheckpointFor(wedgedId) + + expect( + await withinBudget(rejectionOf(stopKeepingHistory(wedgedId)), STOP_BUDGET_MS) + ).toBeInstanceOf(FinalCheckpointWaitExpiredError) + + // Why liveness and not just bookkeeping: the whole point is that an unproven snapshot must not + // authorize the kill, so the daemon must still answer for this session. + expect(await adapter.probePtyLiveness(wedgedId)).toBe(true) + expect(adapter.hasPty(wedgedId)).toBe(true) + stall.release() + }, 30_000) + + it('still commits every abandoned final checkpoint once the wedged history write completes', async () => { + const wedgedId = await spawnWithOutput('committing-session', 'COMMITTING_OUTPUT\r\n') + const laterId = await spawnWithOutput('queued-session', 'QUEUED_OUTPUT\r\n') + const stall = stallCheckpointFor(wedgedId) + + expect( + await withinBudget(rejectionOf(stopKeepingHistory(wedgedId)), STOP_BUDGET_MS) + ).toBeInstanceOf(FinalCheckpointWaitExpiredError) + expect( + await withinBudget(rejectionOf(stopKeepingHistory(laterId)), STOP_BUDGET_MS) + ).toBeInstanceOf(FinalCheckpointWaitExpiredError) + + stall.release() + // Why this is the whole point of bounding the wait and not the work: both callers walked away, + // and both durable writes still land on disk — the abandoned one and the one queued behind it. + await vi.waitFor(async () => { + expect(await onDisk(wedgedId)).toContain('COMMITTING_OUTPUT') + expect(await onDisk(laterId)).toContain('QUEUED_OUTPUT') + }) + }, 30_000) + + it('resumes periodic durable writes after a rejected exclusive checkpoint', async () => { + const adapterClass = DaemonPtyAdapter as unknown as { CHECKPOINT_INTERVAL_MS: number } + const internals = adapter as unknown as { + runExclusiveCheckpoint(operation: () => Promise): Promise + } + const previousInterval = adapterClass.CHECKPOINT_INTERVAL_MS + const rejection = new Error('injected checkpoint rejection') + + try { + await expect( + internals.runExclusiveCheckpoint(async () => { + throw rejection + }) + ).rejects.toBe(rejection) + + adapterClass.CHECKPOINT_INTERVAL_MS = 10 + const id = await spawnWithOutput('post-rejection-session', 'POST_REJECTION_OUTPUT\r\n') + await vi.waitFor(async () => { + expect(await onDisk(id)).toContain('POST_REJECTION_OUTPUT') + }) + } finally { + adapterClass.CHECKPOINT_INTERVAL_MS = previousInterval + } + }) +})