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 + } + }) +})