From bd8ea09eb43bec63e2811039f083195b1fbeedb8 Mon Sep 17 00:00:00 2001 From: brynnclaw <261708852+brynnclaw@users.noreply.github.com> Date: Sat, 3 Oct 2026 22:11:21 +0200 Subject: [PATCH 1/2] fix(orchestration): report a wait-for-setup readiness timeout as a setup wait Under startupPolicy wait-for-setup the agent cannot become ready before the setup hook exits, so a readiness budget that runs out while setup is still running is the setup gate's timeout. worker-start now reports failedStage setup_wait with an error that says setup was still running after N ms and names --timeout-ms, instead of agent_readiness / timeout. Addresses #21512 --- .../worker/local-worker-start.ts | 45 +++++++++++++------ .../orchestration/worker/worker-setup-gate.ts | 15 +++++++ .../worker/workers-new-worktree.test.ts | 30 +++++++++++++ 3 files changed, 77 insertions(+), 13 deletions(-) diff --git a/src/main/runtime/rpc/methods/orchestration/worker/local-worker-start.ts b/src/main/runtime/rpc/methods/orchestration/worker/local-worker-start.ts index c6d7ef96f684..210af5c7c5a9 100644 --- a/src/main/runtime/rpc/methods/orchestration/worker/local-worker-start.ts +++ b/src/main/runtime/rpc/methods/orchestration/worker/local-worker-start.ts @@ -21,7 +21,8 @@ import type { WorkerStartInput } from './worker-start-schema' import { persistGatedSetupSpawnFailure, persistWorkerReadinessStage, - persistWorkerSetupWaitOutcome + persistWorkerSetupWaitOutcome, + setupStillRunningAtTimeout } from './worker-setup-gate' import { failWorkerStartWithReceipt } from './worker-start-receipt' import { parseTaskDeps } from './task-deps-argument' @@ -202,24 +203,42 @@ export async function startLocalWorker(args: { // A structured session is ready the moment its attach returns ok: there is no boot-to-idle // gap and no terminal title to read an idle edge from. Only the repo's wait-for-setup policy // still holds it back, and that gate has to be waited on explicitly here. - const wait = structuredSession - ? await awaitStructuredWorkerSetupGate({ - runtime, - setup: setupReceipt, - effects, - timeoutMs: params.timeoutMs ?? 60_000 - }) - : await waitForWorkerAgentReady(runtime, terminalHandle, { - agent, - reusesTerminal: Boolean(params.terminal), - timeoutMs: params.timeoutMs ?? 60_000 - }) + const readinessTimeoutMs = params.timeoutMs ?? 60_000 + const failIfSetupStillRunning = (timedOut: boolean): void => { + const setupTimeout = setupStillRunningAtTimeout(setupReceipt, timedOut, readinessTimeoutMs) + if (setupTimeout) { + failedStage = 'setup_wait' + throw setupTimeout + } + } + let wait: + | Awaited> + | Awaited> + try { + wait = structuredSession + ? await awaitStructuredWorkerSetupGate({ + runtime, + setup: setupReceipt, + effects, + timeoutMs: readinessTimeoutMs + }) + : await waitForWorkerAgentReady(runtime, terminalHandle, { + agent, + reusesTerminal: Boolean(params.terminal), + timeoutMs: readinessTimeoutMs + }) + } catch (error) { + // A terminal readiness wait rejects with 'timeout' rather than returning a status. + failIfSetupStillRunning(error instanceof Error && error.message === 'timeout') + throw error + } if (wait) { persistWorkerSetupWaitOutcome({ ...setupStage, wait }) if (!wait.satisfied) { if (setupReceipt.state === 'failed') { failedStage = 'setup_wait' } + failIfSetupStillRunning(wait.status === 'timeout') throw new Error( wait.blockedReason ? `Agent startup blocked: ${describeTerminalWaitBlockedReason(wait.blockedReason)}` diff --git a/src/main/runtime/rpc/methods/orchestration/worker/worker-setup-gate.ts b/src/main/runtime/rpc/methods/orchestration/worker/worker-setup-gate.ts index 52a704338676..eae4a3a926d9 100644 --- a/src/main/runtime/rpc/methods/orchestration/worker/worker-setup-gate.ts +++ b/src/main/runtime/rpc/methods/orchestration/worker/worker-setup-gate.ts @@ -67,3 +67,18 @@ export function persistWorkerSetupWaitOutcome( residualResources: residualWorkerEffects(args.effects) }) } + +/** Under wait-for-setup the agent cannot become ready before setup exits, so a readiness budget + * that runs out while setup is still running is the setup gate's timeout, not the agent's. */ +export function setupStillRunningAtTimeout( + setup: WorkerSetupReceipt, + timedOut: boolean, + timeoutMs: number +): Error | null { + if (!timedOut || setup.startupPolicy !== 'wait-for-setup' || setup.state !== 'running') { + return null + } + return new Error( + `Setup was still running after ${timeoutMs} ms (startup policy wait-for-setup), so the agent could not start. Retry with a larger --timeout-ms.` + ) +} diff --git a/src/main/runtime/rpc/methods/orchestration/worker/workers-new-worktree.test.ts b/src/main/runtime/rpc/methods/orchestration/worker/workers-new-worktree.test.ts index fc7c1f3b26cf..93ed3bde0624 100644 --- a/src/main/runtime/rpc/methods/orchestration/worker/workers-new-worktree.test.ts +++ b/src/main/runtime/rpc/methods/orchestration/worker/workers-new-worktree.test.ts @@ -455,6 +455,36 @@ describe('orchestration new-worktree workers', () => { expect(runtime.sendTerminalAgentPrompt).not.toHaveBeenCalled() }) + it('reports a readiness timeout while wait-for-setup is still running as a setup wait', async () => { + mockCreatedWorktree({ startupPolicy: 'wait-for-setup', state: 'running' }) + vi.mocked(runtime.waitForTerminal).mockRejectedValue(new Error('timeout')) + + const { result } = await startWorker({ timeoutMs: 1_000 }) + + expect(result).toMatchObject({ + state: 'failed', + failedStage: 'setup_wait', + setup: { startupPolicy: 'wait-for-setup', state: 'running' } + }) + const lastError = (result as { lastError: string }).lastError + expect(lastError).toContain('Setup was still running after 1000 ms') + expect(lastError).toContain('--timeout-ms') + expect(runtime.sendTerminalAgentPrompt).not.toHaveBeenCalled() + }) + + it('keeps a start-immediately readiness timeout at agent readiness', async () => { + mockCreatedWorktree({ startupPolicy: 'start-immediately', state: 'running' }) + vi.mocked(runtime.waitForTerminal).mockRejectedValue(new Error('timeout')) + + const { result } = await startWorker({ timeoutMs: 1_000 }) + + expect(result).toMatchObject({ + state: 'failed', + failedStage: 'agent_readiness', + lastError: 'timeout' + }) + }) + it('distinguishes no-effect failure, unknown acceptance, and durable residual effects', async () => { vi.spyOn(runtime, 'createManagedWorktree').mockRejectedValueOnce( new Error('repository validation failed before creation') From ef8ccb7228a7f2e3c29b78dd76022b6b5bfb5ada Mon Sep 17 00:00:00 2001 From: brynnclaw <261708852+brynnclaw@users.noreply.github.com> Date: Sun, 4 Oct 2026 05:55:42 +0200 Subject: [PATCH 2/2] fix(orchestration): ask the setup terminal what setup did at a wait-for-setup readiness timeout The setup receipt stays `running` on a terminal readiness timeout: only a wait that returns updates it, and a failed setup leaves the agent pane's shell alive, so readiness times out then too. Reporting "setup was still running" from that receipt mislabels a failed or finished setup. At the timeout, worker-start now probes the setup terminal (1 s, aborted afterwards) and reports what it saw: still running -> setup_wait with the --timeout-ms hint; exited non-zero -> setup_wait "Setup failed (exit N)" and setup.state failed; exited 0 -> agent_readiness with setup.state succeeded; no setup terminal -> unchanged. A structured worker whose own setup-completion race timed out reports setup_wait. Refs #21512 --- .../worker/local-worker-start.ts | 27 ++-- .../orchestration/worker/worker-setup-gate.ts | 68 +++++++++-- .../worker/workers-new-worktree.test.ts | 115 +++++++++++++++++- 3 files changed, 191 insertions(+), 19 deletions(-) diff --git a/src/main/runtime/rpc/methods/orchestration/worker/local-worker-start.ts b/src/main/runtime/rpc/methods/orchestration/worker/local-worker-start.ts index 210af5c7c5a9..82ff35bc1248 100644 --- a/src/main/runtime/rpc/methods/orchestration/worker/local-worker-start.ts +++ b/src/main/runtime/rpc/methods/orchestration/worker/local-worker-start.ts @@ -22,7 +22,8 @@ import { persistGatedSetupSpawnFailure, persistWorkerReadinessStage, persistWorkerSetupWaitOutcome, - setupStillRunningAtTimeout + setupErrorAtReadinessTimeout, + setupStillRunningError } from './worker-setup-gate' import { failWorkerStartWithReceipt } from './worker-start-receipt' import { parseTaskDeps } from './task-deps-argument' @@ -204,11 +205,19 @@ export async function startLocalWorker(args: { // gap and no terminal title to read an idle edge from. Only the repo's wait-for-setup policy // still holds it back, and that gate has to be waited on explicitly here. const readinessTimeoutMs = params.timeoutMs ?? 60_000 - const failIfSetupStillRunning = (timedOut: boolean): void => { - const setupTimeout = setupStillRunningAtTimeout(setupReceipt, timedOut, readinessTimeoutMs) - if (setupTimeout) { + // Under wait-for-setup a readiness timeout may be setup's, not the agent's. The structured + // gate's timeout is its own setup-completion race; a terminal one asks the setup terminal. + const failIfSetupBlockedAgent = async (): Promise => { + const setupError = structuredSession + ? setupStillRunningError(readinessTimeoutMs) + : await setupErrorAtReadinessTimeout({ + ...setupStage, + runtime, + timeoutMs: readinessTimeoutMs + }) + if (setupError) { failedStage = 'setup_wait' - throw setupTimeout + throw setupError } } let wait: @@ -229,7 +238,9 @@ export async function startLocalWorker(args: { }) } catch (error) { // A terminal readiness wait rejects with 'timeout' rather than returning a status. - failIfSetupStillRunning(error instanceof Error && error.message === 'timeout') + if (error instanceof Error && error.message === 'timeout') { + await failIfSetupBlockedAgent() + } throw error } if (wait) { @@ -238,7 +249,9 @@ export async function startLocalWorker(args: { if (setupReceipt.state === 'failed') { failedStage = 'setup_wait' } - failIfSetupStillRunning(wait.status === 'timeout') + if (wait.status === 'timeout') { + await failIfSetupBlockedAgent() + } throw new Error( wait.blockedReason ? `Agent startup blocked: ${describeTerminalWaitBlockedReason(wait.blockedReason)}` diff --git a/src/main/runtime/rpc/methods/orchestration/worker/worker-setup-gate.ts b/src/main/runtime/rpc/methods/orchestration/worker/worker-setup-gate.ts index eae4a3a926d9..173afc281434 100644 --- a/src/main/runtime/rpc/methods/orchestration/worker/worker-setup-gate.ts +++ b/src/main/runtime/rpc/methods/orchestration/worker/worker-setup-gate.ts @@ -1,3 +1,4 @@ +import type { OrcaRuntimeService } from '../../../../orca-runtime' import type { OrchestrationDb } from '../../../../orchestration/db' import { applyWaitForSetupOutcome, @@ -68,17 +69,66 @@ export function persistWorkerSetupWaitOutcome( }) } -/** Under wait-for-setup the agent cannot become ready before setup exits, so a readiness budget - * that runs out while setup is still running is the setup gate's timeout, not the agent's. */ -export function setupStillRunningAtTimeout( - setup: WorkerSetupReceipt, - timedOut: boolean, - timeoutMs: number -): Error | null { - if (!timedOut || setup.startupPolicy !== 'wait-for-setup' || setup.state !== 'running') { +/** How long a readiness timeout asks the setup terminal whether setup exited. An exited setup + * normally answers at once from its replayed completion marker; a running one uses the whole probe. */ +const SETUP_EXIT_PROBE_MS = 1_000 + +export function setupStillRunningError(timeoutMs: number): Error { + return new Error( + `Setup was still running after ${timeoutMs} ms (startup policy wait-for-setup), so the agent could not start. Retry with a larger --timeout-ms.` + ) +} + +/** + * Under wait-for-setup the agent cannot start before setup exits, so a terminal readiness timeout + * asks the setup terminal what setup did. The receipt cannot answer: it still says `running`, + * because only a readiness wait that returns updates it, and a failed setup leaves the pane's shell + * alive, so that wait times out too. + * + * Returns the setup error to report, or null to keep the agent-readiness timeout: setup exited 0, + * or there is no setup terminal to ask. An exit it observes is persisted as the setup outcome. + */ +export async function setupErrorAtReadinessTimeout( + args: WorkerSetupStageArgs & { + runtime: Pick + timeoutMs: number + } +): Promise { + if (args.setup.startupPolicy !== 'wait-for-setup' || args.setup.state !== 'running') { + return null + } + const setupTerminal = args.effects.find((effect) => effect.kind === 'setup')?.terminalId + if (!setupTerminal) { + return null + } + const abort = new AbortController() + let timer: ReturnType | undefined + let completion: { exitCode: number | null } | 'running' + try { + completion = await Promise.race([ + args.runtime.waitForSetupTerminalCompletion(setupTerminal, abort.signal), + new Promise<'running'>((resolve) => { + timer = setTimeout(() => resolve('running'), SETUP_EXIT_PROBE_MS) + }) + ]) + } catch { + // A setup terminal that is already gone gives no evidence either way. + return null + } finally { + clearTimeout(timer) + abort.abort() + } + if (completion === 'running') { + return setupStillRunningError(args.timeoutMs) + } + persistWorkerSetupWaitOutcome({ + ...args, + wait: { satisfied: completion.exitCode === 0, status: 'exited' } + }) + if (completion.exitCode === 0) { return null } return new Error( - `Setup was still running after ${timeoutMs} ms (startup policy wait-for-setup), so the agent could not start. Retry with a larger --timeout-ms.` + `Setup failed (exit ${completion.exitCode ?? 'unknown'}), so the agent could not start (startup policy wait-for-setup).` ) } diff --git a/src/main/runtime/rpc/methods/orchestration/worker/workers-new-worktree.test.ts b/src/main/runtime/rpc/methods/orchestration/worker/workers-new-worktree.test.ts index 93ed3bde0624..3ab538c7763a 100644 --- a/src/main/runtime/rpc/methods/orchestration/worker/workers-new-worktree.test.ts +++ b/src/main/runtime/rpc/methods/orchestration/worker/workers-new-worktree.test.ts @@ -8,6 +8,12 @@ import { OrchestrationDb } from '../../../../orchestration/db' import { RpcDispatcher } from '../../../dispatcher' import type { RpcRequest } from '../../../core' import { ORCHESTRATION_METHODS } from '../../orchestration' +import { placeWorkerAgent } from './worker-start-agent-placement' + +vi.mock(import('./worker-start-agent-placement'), async (importOriginal) => { + const actual = await importOriginal() + return { ...actual, placeWorkerAgent: vi.fn(actual.placeWorkerAgent) } +}) describe('orchestration new-worktree workers', () => { type CreateWorktreeResult = Awaited> @@ -132,6 +138,15 @@ describe('orchestration new-worktree workers', () => { } } + function mockGatedSetupReadinessTimeout(state: 'running' | 'skipped') { + mockCreatedWorktree({ + startupPolicy: 'wait-for-setup', + state, + setupTerminalHandle: 'term_setup' + }) + vi.mocked(runtime.waitForTerminal).mockRejectedValue(new Error('timeout')) + } + it('creates an independent top-level worktree and reuses its agent terminal', async () => { mockCreatedWorktree() @@ -456,8 +471,7 @@ describe('orchestration new-worktree workers', () => { }) it('reports a readiness timeout while wait-for-setup is still running as a setup wait', async () => { - mockCreatedWorktree({ startupPolicy: 'wait-for-setup', state: 'running' }) - vi.mocked(runtime.waitForTerminal).mockRejectedValue(new Error('timeout')) + mockGatedSetupReadinessTimeout('running') const { result } = await startWorker({ timeoutMs: 1_000 }) @@ -469,11 +483,106 @@ describe('orchestration new-worktree workers', () => { const lastError = (result as { lastError: string }).lastError expect(lastError).toContain('Setup was still running after 1000 ms') expect(lastError).toContain('--timeout-ms') + expect(runtime.waitForSetupTerminalCompletion).toHaveBeenCalledWith( + 'term_setup', + expect.any(AbortSignal) + ) + expect(runtime.sendTerminalAgentPrompt).not.toHaveBeenCalled() + }) + + it('reports a wait-for-setup readiness timeout after setup failed as a setup failure', async () => { + // The gate skips the agent and the pane's shell stays alive, so readiness can only time out. + mockGatedSetupReadinessTimeout('running') + vi.mocked(runtime.waitForSetupTerminalCompletion).mockResolvedValue({ exitCode: 3 }) + + const { result } = await startWorker({ timeoutMs: 1_000 }) + + expect(result).toMatchObject({ + state: 'failed', + failedStage: 'setup_wait', + setup: { startupPolicy: 'wait-for-setup', state: 'failed' }, + effects: expect.arrayContaining([expect.objectContaining({ kind: 'setup', state: 'failed' })]) + }) + const lastError = (result as { lastError: string }).lastError + expect(lastError).toContain('Setup failed (exit 3)') + expect(lastError).not.toContain('still running') expect(runtime.sendTerminalAgentPrompt).not.toHaveBeenCalled() }) + it('keeps a wait-for-setup readiness timeout after setup succeeded at agent readiness', async () => { + mockGatedSetupReadinessTimeout('running') + vi.mocked(runtime.waitForSetupTerminalCompletion).mockResolvedValue({ exitCode: 0 }) + + const { result } = await startWorker({ timeoutMs: 1_000 }) + + expect(result).toMatchObject({ + state: 'failed', + failedStage: 'agent_readiness', + lastError: 'timeout', + setup: { startupPolicy: 'wait-for-setup', state: 'succeeded' } + }) + }) + + it('keeps a wait-for-setup readiness timeout with no running setup at agent readiness', async () => { + mockGatedSetupReadinessTimeout('skipped') + + const { result } = await startWorker({ timeoutMs: 1_000 }) + + expect(result).toMatchObject({ + state: 'failed', + failedStage: 'agent_readiness', + lastError: 'timeout', + setup: { state: 'skipped' } + }) + expect(runtime.waitForSetupTerminalCompletion).not.toHaveBeenCalled() + }) + + it('reports a structured worker whose setup gate timed out as a setup wait', async () => { + vi.mocked(placeWorkerAgent).mockImplementationOnce(async (args) => { + args.effects.push({ + kind: 'setup', + action: 'run', + startupPolicy: 'wait-for-setup', + state: 'running', + terminalId: 'term_setup' + }) + return { + mode: args.mode, + worktree: { id: 'repo::created', repoId: 'repo' }, + terminalHandle: 'structured_worker_1', + structuredSession: { + identity: { sessionId: 'session_1', handle: 'structured_worker_1' } + } as never, + setupReceipt: { + requested: 'run', + effective: 'run', + source: 'orchestration_default', + hookFound: true, + startupPolicy: 'wait-for-setup', + state: 'running' + } + } + }) + + const { result } = await startWorker({ timeoutMs: 50 }) + + expect(result).toMatchObject({ + state: 'failed', + failedStage: 'setup_wait', + setup: { startupPolicy: 'wait-for-setup', state: 'running' } + }) + expect((result as { lastError: string }).lastError).toContain( + 'Setup was still running after 50 ms' + ) + expect(runtime.waitForTerminal).not.toHaveBeenCalled() + }) + it('keeps a start-immediately readiness timeout at agent readiness', async () => { - mockCreatedWorktree({ startupPolicy: 'start-immediately', state: 'running' }) + mockCreatedWorktree({ + startupPolicy: 'start-immediately', + state: 'running', + setupTerminalHandle: 'term_setup' + }) vi.mocked(runtime.waitForTerminal).mockRejectedValue(new Error('timeout')) const { result } = await startWorker({ timeoutMs: 1_000 })