From 1c766876f09e669bebef577d1ff97124b9d98d85 Mon Sep 17 00:00:00 2001 From: Neil <4138956+nwparker@users.noreply.github.com> Date: Fri, 4 Sep 2026 16:19:02 -0700 Subject: [PATCH] fix: submit agent startup at the prompt without polling --- ...nt-startup-prompt-latency.node-pty.test.ts | 123 ++++++++++++++++++ .../daemon/daemon-bash-shell-ready-rcfile.ts | 10 +- src/main/daemon/daemon-pty-adapter.test.ts | 9 ++ src/main/daemon/daemon-pty-session-spawn.ts | 26 +++- src/main/daemon/daemon-pty-spawn-request.ts | 4 + src/main/daemon/post-ready-flush-gate.test.ts | 44 +------ src/main/daemon/post-ready-flush-gate.ts | 55 ++------ .../pty-subprocess/shell-launch-plan.ts | 17 ++- .../daemon/session-shell-ready-barrier.ts | 5 +- src/main/daemon/shell-ready.ts | 5 + 10 files changed, 200 insertions(+), 98 deletions(-) create mode 100644 src/main/daemon/agent-startup-prompt-latency.node-pty.test.ts diff --git a/src/main/daemon/agent-startup-prompt-latency.node-pty.test.ts b/src/main/daemon/agent-startup-prompt-latency.node-pty.test.ts new file mode 100644 index 00000000000..cfa01fed8e5 --- /dev/null +++ b/src/main/daemon/agent-startup-prompt-latency.node-pty.test.ts @@ -0,0 +1,123 @@ +import { appendFileSync, existsSync, mkdtempSync, rmSync, writeFileSync } from 'node:fs' +import { tmpdir } from 'node:os' +import { join } from 'node:path' +import { afterEach, describe, expect, it, vi } from 'vitest' +import { createPtySubprocess } from './pty-subprocess' +import { Session } from './session' + +const SHELLS = process.platform === 'win32' ? [] : ['/bin/bash', '/bin/zsh'].filter(existsSync) +const COMMAND = "printf 'AGENT_%s\\n' STARTED" + +async function launch( + shell: string, + slow: boolean, + legacy = false +): Promise<{ output: string; ms: number }> { + const root = mkdtempSync(join(tmpdir(), 'orca-startup-latency-')) + const bash = shell.endsWith('bash') + const pause = slow ? 'sleep 0.6\n' : '' + const prompt = slow ? "PS1='$(sleep 0.3)prompt> '\n" : "PS1='prompt> '\n" + writeFileSync( + join(root, bash ? '.bash_profile' : '.zshrc'), + `${pause}${bash ? '' : 'setopt PROMPT_SUBST\n'}${prompt}` + ) + vi.stubEnv('HOME', root) + vi.stubEnv('ZDOTDIR', root) + vi.stubEnv('ORCA_ORIG_ZDOTDIR', root) + let session: Session | undefined + let timer: ReturnType | undefined + let legacyTimer: ReturnType | undefined + const readinessEvents: string[] = [] + const started = performance.now() + try { + const subprocess = await createPtySubprocess({ + sessionId: 'startup-latency', + cols: 120, + rows: 30, + cwd: root, + shellOverride: shell, + command: COMMAND, + env: { HOME: root, SHELL: shell, TERM: 'xterm-256color' } + }) + session = new Session({ + sessionId: 'startup-latency', + cols: 120, + rows: 30, + subprocess, + shellReadySupported: !legacy, + reportReadinessEvent: (event) => readinessEvents.push(event) + }) + const active = session + return await new Promise((resolve, reject) => { + let output = '' + timer = setTimeout( + () => reject(new Error(`Startup timed out: ${JSON.stringify(output)}`)), + 5000 + ) + active.attachClient({ + onExit: () => {}, + onData: (data) => { + output += data + if (output.includes('AGENT_STARTED')) { + resolve({ output, ms: performance.now() - started }) + } + } + }) + if (legacy) { + legacyTimer = setTimeout(() => active.write(`${COMMAND}\n`), 300) + } else { + active.write(`${COMMAND}\n`) + } + }) + } finally { + clearTimeout(timer) + clearTimeout(legacyTimer) + if (session) { + await session.forceKillAndWaitForExit(3000) + session.dispose() + } + vi.unstubAllEnvs() + rmSync(root, { recursive: true, force: true }) + expect(readinessEvents).toEqual([]) + } +} + +describe('agent startup at the rendered shell prompt', () => { + afterEach(() => vi.unstubAllEnvs()) + it.each(SHELLS)( + '%s displays the command once after slow startup and prompt expansion', + async (shell) => { + const before = await launch(shell, true, true) + expect(before.output.split(COMMAND)).toHaveLength(3) + const result = await launch(shell, true) + expect(result.output).not.toContain('orca-shell-ready') + expect(result.output.split(COMMAND)).toHaveLength(2) + expect(result.output.indexOf('prompt> ')).toBeLessThan(result.output.indexOf(COMMAND)) + } + ) + + it.skipIf(!process.env.ORCA_STARTUP_BENCH || SHELLS.length === 0)( + 'compares legacy input timing with prompt delivery', + async () => { + for (const shell of SHELLS) { + for (const slow of [false, true]) { + const legacy: number[] = [] + const current: number[] = [] + for (let i = 0; i < 5; i++) { + legacy.push((await launch(shell, slow, true)).ms) + const result = await launch(shell, slow) + expect(result.output).not.toContain('orca-shell-ready') + expect(result.output.split(COMMAND)).toHaveLength(2) + current.push(result.ms) + } + const result = JSON.stringify({ shell, slow, legacy, current }) + if (process.env.ORCA_STARTUP_BENCH_OUTPUT) { + appendFileSync(process.env.ORCA_STARTUP_BENCH_OUTPUT, `${result}\n`) + } + console.log(result) + } + } + }, + 60_000 + ) +}) diff --git a/src/main/daemon/daemon-bash-shell-ready-rcfile.ts b/src/main/daemon/daemon-bash-shell-ready-rcfile.ts index 142c0c131d9..f7834dba9d7 100644 --- a/src/main/daemon/daemon-bash-shell-ready-rcfile.ts +++ b/src/main/daemon/daemon-bash-shell-ready-rcfile.ts @@ -2,7 +2,6 @@ import { getPosixOmpShellWrapper } from '../pty/omp-shell-wrapper' import { getPosixCodexShellLaunchPreflight } from '../pty/codex-shell-launch-preflight' import { BASH_PROMPT_COMMAND_COMPOSITION_BLOCK } from '../bash-prompt-command-composition' import { BASH_FEATURE_CHANNEL_BLOCK, SHELL_STARTUP_IDENTITY_MARKER_BLOCK } from '../shell-templates' -import { SHELL_READY_MARKER } from './daemon-shell-ready-marker' export function getDaemonBashShellReadyRcfileContent(): string { return `# Orca daemon bash shell-ready wrapper @@ -56,10 +55,6 @@ __orca_osc133_precmd() { unset __orca_in_command fi printf "\\033]133;A\\007" - # Why: emit the shell-ready marker here (not a trailing PROMPT_COMMAND entry) - # so a framework that must be last in PROMPT_COMMAND — bash-preexec — is not - # displaced by one of Orca's own hooks. - [[ -n "$__orca_ready_marker" ]] && printf "${SHELL_READY_MARKER}" return "$exit_code" } __orca_osc133_preexec() { @@ -117,6 +112,11 @@ __orca_osc133_epilogue() { unset __orca_in_prompt_command __orca_adopt_outer_debug_trap trap '__orca_osc133_preexec' DEBUG + # Readline renders PS1 after entering raw mode; prompt hooks still run in cooked mode. + if [[ -n "$__orca_ready_marker" ]]; then + PS1="\${PS1-}"'\\[\\e]777;orca-shell-ready\\a\\]' + __orca_ready_marker="" + fi } ${BASH_PROMPT_COMMAND_COMPOSITION_BLOCK} __orca_prepend_prompt_command "__orca_osc133_precmd" diff --git a/src/main/daemon/daemon-pty-adapter.test.ts b/src/main/daemon/daemon-pty-adapter.test.ts index 46819e6fed1..d0c0198af65 100644 --- a/src/main/daemon/daemon-pty-adapter.test.ts +++ b/src/main/daemon/daemon-pty-adapter.test.ts @@ -344,6 +344,15 @@ describe('DaemonPtyAdapter (IPtyProvider)', () => { } }) + itOnPosix('preserves the existing fast-start timing for fish', async () => { + await adapter.spawn({ cols: 80, rows: 24, command: 'codex', env: { SHELL: '/usr/bin/fish' } }) + await waitFor(() => vi.mocked(lastSubprocess.write).mock.calls.length > 0) + expect(lastSubprocess.write).toHaveBeenCalledExactlyOnceWith('codex\n') + expect(lastSpawnOpts).not.toEqual( + expect.objectContaining({ startupCommandDelivery: 'shell-ready' }) + ) + }) + itOnPosix.each([ { command: 'codex' }, { command: 'codex', startupCommandDelivery: 'fast' as const }, diff --git a/src/main/daemon/daemon-pty-session-spawn.ts b/src/main/daemon/daemon-pty-session-spawn.ts index 5799e817ac9..00f19777878 100644 --- a/src/main/daemon/daemon-pty-session-spawn.ts +++ b/src/main/daemon/daemon-pty-session-spawn.ts @@ -1,3 +1,6 @@ +import { recognizeAgentProcessFromCommandLine } from '../../shared/agent-process-recognition' +import { shouldUseShellReadyStartupDelivery } from '../../shared/codex-startup-delivery' +import { CODEX_SHELL_READY_TIMEOUT_MS } from './session-shell-ready-barrier' import type { HistoryRecoveryContext, PendingDaemonSpawnOperation @@ -9,7 +12,11 @@ import { DaemonPtySpawnResult } from './daemon-pty-spawn-result' import type { DaemonPtySpawnContext } from './daemon-pty-spawn-request' import type { ColdRestoreInfo } from './history-reader' import { mintPtySessionId } from './pty-session-id' -import { supportsPtyStartupBarrier } from './shell-ready' +import { + supportsPtyStartupBarrier, + shellReadyMarkerComesFromLineEditor, + resolvePtyShellPath +} from './shell-ready' import { getRecoveredHistorySeedSegments } from './terminal-history-seed-segments' import { AGENT_SESSION_CLAIM_DAEMON_PROTOCOL_VERSION, type CreateOrAttachResult } from './types' import { normalizeWslColdRestoreCwd } from './wsl-cold-restore-cwd' @@ -210,9 +217,23 @@ export abstract class DaemonPtySessionSpawn extends DaemonPtySpawnResult { let effectiveRows = restoreInfo?.rows ?? opts.rows const shellReadySupported = opts.command ? supportsPtyStartupBarrier(opts.env ?? {}) : false + const immediateMarker = + process.platform !== 'win32' && + shellReadyMarkerComesFromLineEditor(opts.shellOverride || resolvePtyShellPath(opts.env ?? {})) + const shellReadyTimeoutMs = + shellReadySupported && + !immediateMarker && + recognizeAgentProcessFromCommandLine(opts.command)?.agent === 'codex' && + !shouldUseShellReadyStartupDelivery({ + command: opts.command, + startupCommandDelivery: opts.startupCommandDelivery + }) + ? CODEX_SHELL_READY_TIMEOUT_MS + : undefined const context: DaemonPtySpawnContext = { // Older daemons also need the existing hint to enable their ready marker. - opts: opts.command ? { ...opts, startupCommandDelivery: 'shell-ready' } : opts, + opts: + opts.command && immediateMarker ? { ...opts, startupCommandDelivery: 'shell-ready' } : opts, operation, historyRecovery, requestedSessionId, @@ -226,6 +247,7 @@ export abstract class DaemonPtySessionSpawn extends DaemonPtySpawnResult { effectiveCols, effectiveRows, shellReadySupported, + shellReadyTimeoutMs, historySeedSegments: restoreInfo ? getRecoveredHistorySeedSegments(restoreInfo) : null, detectColdRestore } diff --git a/src/main/daemon/daemon-pty-spawn-request.ts b/src/main/daemon/daemon-pty-spawn-request.ts index 61bf9b4eb85..7de9b21926a 100644 --- a/src/main/daemon/daemon-pty-spawn-request.ts +++ b/src/main/daemon/daemon-pty-spawn-request.ts @@ -33,6 +33,7 @@ export type DaemonPtySpawnContext = { effectiveCols: number effectiveRows: number shellReadySupported: boolean + shellReadyTimeoutMs: number | undefined historySeedSegments: readonly string[] | null detectColdRestore(options?: { ignoreCleanEnd?: boolean }): Promise } @@ -122,6 +123,9 @@ export abstract class DaemonPtySpawnRequest extends DaemonPtyRuntimeState { ? undefined : opts.terminalWindowsPowerShellImplementation, shellReadySupported: context.attachOnly ? false : context.shellReadySupported, + ...(!context.attachOnly && context.shellReadyTimeoutMs !== undefined + ? { shellReadyTimeoutMs: context.shellReadyTimeoutMs } + : {}), ...(historySeed ? { historySeed } : {}), ...(historySeedTransferId ? { historySeedTransferId } : {}), ...(this.supportsStartupIngress && !context.attachOnly && opts.startupIngress diff --git a/src/main/daemon/post-ready-flush-gate.test.ts b/src/main/daemon/post-ready-flush-gate.test.ts index 7152e4be464..06ff64db99f 100644 --- a/src/main/daemon/post-ready-flush-gate.test.ts +++ b/src/main/daemon/post-ready-flush-gate.test.ts @@ -20,50 +20,12 @@ describe('PostReadyFlushGate', () => { vi.useRealTimers() }) - it('waits while a slow prompt still has cooked echo enabled', async () => { - const probe = vi.fn().mockResolvedValue('other') - gate = new PostReadyFlushGate(onFlush, probe) - gate.arm(true) - await vi.advanceTimersByTimeAsync(1000) - expect(onFlush).not.toHaveBeenCalled() - expect(gate.isPending).toBe(true) - probe.mockResolvedValue('line-editor') - await vi.advanceTimersByTimeAsync(250) - expect(onFlush).toHaveBeenCalledTimes(1) - expect(gate.isPending).toBe(false) - }) - - it('drops an in-flight probe result after teardown', async () => { - let resolveProbe!: (state: 'line-editor') => void - gate = new PostReadyFlushGate( - onFlush, - () => - new Promise((resolve) => { - resolveProbe = resolve - }) - ) - gate.arm(true) - await vi.advanceTimersByTimeAsync(POST_READY_FLUSH_DELAY_MS) - gate.clear() - resolveProbe('line-editor') - await vi.advanceTimersByTimeAsync(1000) - expect(onFlush).not.toHaveBeenCalled() - expect(gate.isPending).toBe(false) - }) - - it.each(['unknown', 'unavailable'])('retains the fallback when probing is %s', async (state) => { - gate = new PostReadyFlushGate(onFlush, vi.fn().mockResolvedValue(state)) + it('flushes synchronously when the marker comes from the line editor', () => { + gate = new PostReadyFlushGate(onFlush, true) gate.arm() - await vi.advanceTimersByTimeAsync(POST_READY_FLUSH_FALLBACK_MS) - expect(onFlush).toHaveBeenCalledTimes(1) - }) - - it('bounds waiting when a shell never enters its line editor', async () => { - gate = new PostReadyFlushGate(onFlush, vi.fn().mockResolvedValue('other')) - gate.arm(true) - await vi.advanceTimersByTimeAsync(15_500) expect(onFlush).toHaveBeenCalledTimes(1) expect(gate.isPending).toBe(false) + expect(vi.getTimerCount()).toBe(0) }) it('does not flush immediately when armed', () => { diff --git a/src/main/daemon/post-ready-flush-gate.ts b/src/main/daemon/post-ready-flush-gate.ts index 315dbf77809..f7f7a2f1869 100644 --- a/src/main/daemon/post-ready-flush-gate.ts +++ b/src/main/daemon/post-ready-flush-gate.ts @@ -1,5 +1,5 @@ -import type { PtySlaveLineEditorProbe } from '../../shared/pty-slave-line-discipline-echo' - +// Bash's prompt and zsh's line-init marker are ready for input immediately. +// Other shells retain the existing settling delay. export const POST_READY_FLUSH_DELAY_MS = 30 export const POST_READY_FLUSH_FALLBACK_MS = 200 @@ -8,58 +8,25 @@ export class PostReadyFlushGate { private postDataTimer: ReturnType | null = null private fallbackTimer: ReturnType | null = null - private generation = 0 - private probePending = false - private probeDeadline = 0 - constructor( private readonly onFlush: () => void, - private readonly lineEditorProbe?: PtySlaveLineEditorProbe + private readonly markerIsLineEditorReady = false ) {} - private async flushWhenLineEditorReady(): Promise { - const generation = this.generation - this.probePending = true - const state = await this.lineEditorProbe?.().catch(() => 'unknown') - if (generation !== this.generation) { - return - } - this.probePending = false - // Slow prompt hooks can leave cooked echo enabled long after the ready marker. - if (state === 'other' && Date.now() < this.probeDeadline) { - this.postDataTimer = setTimeout(() => { - this.postDataTimer = null - void this.flushWhenLineEditorReady() - }, 250) - return - } - this.onFlush() - } - - private flush(): void { - if (this.lineEditorProbe) { - void this.flushWhenLineEditorReady() - } else { - this.onFlush() - } - } - /** True between arm() and the actual flush firing. Callers should treat * input as still-queued during this window to preserve ordering. */ get isPending(): boolean { - return ( - this.probePending || - this.awaitingPromptDraw || - this.postDataTimer !== null || - this.fallbackTimer !== null - ) + return this.awaitingPromptDraw || this.postDataTimer !== null || this.fallbackTimer !== null } /** Arm the gate after observing the shell-ready marker. Starts the * wall-clock fallback unless the marker scan already observed post-marker * bytes, in which case the short post-data settle path is enough. */ arm(postMarkerBytesObserved = false): void { - this.probeDeadline = Date.now() + 15_000 + if (this.markerIsLineEditorReady) { + this.onFlush() + return + } this.awaitingPromptDraw = true if (postMarkerBytesObserved) { this.notifyData() @@ -68,7 +35,7 @@ export class PostReadyFlushGate { this.fallbackTimer = setTimeout(() => { this.fallbackTimer = null this.awaitingPromptDraw = false - this.flush() + this.onFlush() }, POST_READY_FLUSH_FALLBACK_MS) } @@ -87,15 +54,13 @@ export class PostReadyFlushGate { if (this.postDataTimer === null) { this.postDataTimer = setTimeout(() => { this.postDataTimer = null - this.flush() + this.onFlush() }, POST_READY_FLUSH_DELAY_MS) } } /** Cancel any pending flush. Call on session teardown. */ clear(): void { - this.generation += 1 - this.probePending = false this.awaitingPromptDraw = false if (this.postDataTimer) { clearTimeout(this.postDataTimer) diff --git a/src/main/daemon/pty-subprocess/shell-launch-plan.ts b/src/main/daemon/pty-subprocess/shell-launch-plan.ts index 2f7baaba665..12e049d9f72 100644 --- a/src/main/daemon/pty-subprocess/shell-launch-plan.ts +++ b/src/main/daemon/pty-subprocess/shell-launch-plan.ts @@ -1,3 +1,4 @@ +import { shouldUseShellReadyStartupDelivery } from '../../../shared/codex-startup-delivery' import { win32 as pathWin32 } from 'node:path' import { isWindowsGitBashShellPath, resolveWindowsGitBashShellPath } from '../../git-bash' import { isPwshAvailable } from '../../pwsh' @@ -34,7 +35,11 @@ import { } from '../../../shared/agent-process-recognition' import { ORCA_HERMES_STARTUP_QUERY_ENV } from '../../../shared/hermes-startup-query' import { WINDOWS_GIT_BASH_SHELL } from '../../../shared/windows-terminal-shell' -import { getShellLaunchConfig, resolvePtyShellPath } from '../shell-ready' +import { + getShellLaunchConfig, + resolvePtyShellPath, + shellReadyMarkerComesFromLineEditor +} from '../shell-ready' import { resolveWslSessionContext } from '../wsl-session-context' import { finalizeDaemonPtyEnvironment, rescrubDaemonPtyEnvironment } from './spawn-environment' import type { PtySubprocessOptions } from '../pty-subprocess' @@ -188,8 +193,14 @@ export function createPtyShellLaunchPlan( `[daemon/pty] Preferred shell "${preferredShellPath}" is unavailable, fell back to "${shellPath}"` ) } - // PTY input must wait for the line editor, including plain Codex launches. - const waitsForShellReady = Boolean(opts.command) + const waitsForShellReady = + Boolean(opts.command) && + (startupAgentRecognition?.agent !== 'codex' || + shellReadyMarkerComesFromLineEditor(shellPath) || + shouldUseShellReadyStartupDelivery({ + command: opts.command, + startupCommandDelivery: opts.startupCommandDelivery + })) delete env.ORCA_SHELL_FEATURES const shellLaunch = getShellLaunchConfig( shellPath, diff --git a/src/main/daemon/session-shell-ready-barrier.ts b/src/main/daemon/session-shell-ready-barrier.ts index 55847519e6a..538fd57a49a 100644 --- a/src/main/daemon/session-shell-ready-barrier.ts +++ b/src/main/daemon/session-shell-ready-barrier.ts @@ -1,4 +1,4 @@ -import { createPtySlaveLineEditorProbe } from '../../shared/pty-slave-line-discipline-echo' +import { shellReadyMarkerComesFromLineEditor } from './shell-ready' import { installDeviceAttributesResponder, STARTUP_DA1_RESPONSE @@ -20,6 +20,7 @@ import { basename } from 'node:path' import type { ShellReadyState } from './types' const SHELL_READY_TIMEOUT_MS = 15_000 +export const CODEX_SHELL_READY_TIMEOUT_MS = 300 export type SessionShellReadyBarrierDeps = { sessionId: string @@ -70,7 +71,7 @@ export class SessionShellReadyBarrier { this.postReadyFlushGate = new PostReadyFlushGate( () => this.flushPreReadyQueue(), - createPtySlaveLineEditorProbe(deps.subprocess.slavePath) + shellReadyMarkerComesFromLineEditor(deps.subprocess.shellPath ?? '') ) } diff --git a/src/main/daemon/shell-ready.ts b/src/main/daemon/shell-ready.ts index 9dc60b7c980..d51f6efb80a 100644 --- a/src/main/daemon/shell-ready.ts +++ b/src/main/daemon/shell-ready.ts @@ -101,6 +101,11 @@ export function resolvePtyShellPath(env: Record): string { return env.SHELL || process.env.SHELL || '/bin/zsh' } +export function shellReadyMarkerComesFromLineEditor(shellPath: string): boolean { + const shellName = pathWin32.basename(basename(shellPath)).toLowerCase() + return shellName === 'bash' || shellName === 'zsh' +} + export function shellPathSupportsPtyStartupBarrier(shellPath: string): boolean { const shellName = pathWin32.basename(basename(shellPath)).toLowerCase() // Why fish: markerless, its startup command is written before fish's reader owns