Skip to content

Commit 0632cb7

Browse files
committed
fix(terminal): anchor command_output ask delay to execution start
Anchor the ask-delay timer to onShellExecutionStarted (falling back to the pre-runCommand timestamp) so shell-integration startup on cold terminals does not consume the grace period, and expand ask-policy tests to cover the agent-timeout cancel, re-anchor reschedule, ask error handling, and non-message responses to restore patch coverage.
1 parent e209c7c commit 0632cb7

2 files changed

Lines changed: 176 additions & 4 deletions

File tree

src/core/tools/ExecuteCommandTool.ts

Lines changed: 18 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -353,7 +353,10 @@ export async function executeCommandInTerminal(
353353
// output and exit normally never prompt the user. The ask only fires if the
354354
// command is still running once COMMAND_OUTPUT_ASK_DELAY_MS has elapsed
355355
// since execution started, preserving the interrupt/feedback path for
356-
// long-running commands.
356+
// long-running commands. The anchor is re-based to onShellExecutionStarted
357+
// (falling back to the pre-runCommand timestamp when that event never
358+
// fires) so shell-integration startup on cold terminals does not consume
359+
// the grace period.
357360
let commandStartedAt = 0
358361
let commandOutputAskTimer: NodeJS.Timeout | undefined
359362

@@ -452,9 +455,21 @@ export async function executeCommandInTerminal(
452455
console.error("[ExecuteCommandTool] Failed to flush final command_output:", error)
453456
})
454457
},
455-
onShellExecutionStarted: (pid: number | undefined) => {
458+
onShellExecutionStarted: (pid: number | undefined, process: RooTerminalProcess) => {
456459
const status: CommandExecutionStatus = { executionId, status: "started", pid, command }
457460
provider?.postMessageToWebview({ type: "commandExecutionStatus", text: JSON.stringify(status) })
461+
462+
// Re-anchor the ask delay to actual execution start so the shell
463+
// integration startup wait does not count against the grace period.
464+
commandStartedAt = Date.now()
465+
466+
// Output should not precede this event, but if it did, reschedule
467+
// the pending ask against the corrected anchor.
468+
if (commandOutputAskTimer) {
469+
clearTimeout(commandOutputAskTimer)
470+
commandOutputAskTimer = undefined
471+
scheduleCommandOutputAsk(process)
472+
}
458473
},
459474
onShellExecutionComplete: (details: ExitCodeDetails) => {
460475
const status: CommandExecutionStatus = { executionId, status: "exited", exitCode: details.exitCode }
@@ -481,6 +496,7 @@ export async function executeCommandInTerminal(
481496
workingDir = terminal.getCurrentWorkingDirectory()
482497
}
483498

499+
// Fallback anchor for providers that never fire onShellExecutionStarted.
484500
commandStartedAt = Date.now()
485501
const process = terminal.runCommand(command, callbacks)
486502
task.terminalProcess = process

src/core/tools/__tests__/executeCommandTool.spec.ts

Lines changed: 158 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -368,9 +368,10 @@ describe("executeCommandTool", () => {
368368
return state
369369
}
370370

371-
const handleCommand = (command: string) => {
371+
const handleCommand = (command: string, timeout?: number) => {
372372
mockToolUse.params.command = command
373-
mockToolUse.nativeArgs = { command }
373+
mockToolUse.params.timeout = timeout === undefined ? undefined : String(timeout)
374+
mockToolUse.nativeArgs = timeout === undefined ? { command } : { command, timeout }
374375

375376
return executeCommandTool.handle(mockCline as unknown as Task, mockToolUse, {
376377
askApproval: mockAskApproval as unknown as AskApproval,
@@ -389,6 +390,7 @@ describe("executeCommandTool", () => {
389390
const callbacks = terminal.callbacks!
390391
const proc = terminal.proc as unknown as RooTerminalProcess
391392

393+
callbacks.onShellExecutionStarted!(1234, proc)
392394
await callbacks.onLine("hello\n", proc)
393395
await callbacks.onCompleted!("hello\n", proc)
394396
callbacks.onShellExecutionComplete!({ exitCode: 0 }, proc)
@@ -418,6 +420,7 @@ describe("executeCommandTool", () => {
418420
const callbacks = terminal.callbacks!
419421
const proc = terminal.proc as unknown as RooTerminalProcess
420422

423+
callbacks.onShellExecutionStarted!(1234, proc)
421424
await callbacks.onLine("working...\n", proc)
422425

423426
// First output alone must not trigger the ask.
@@ -428,6 +431,10 @@ describe("executeCommandTool", () => {
428431
expect(mockCline.ask).toHaveBeenCalledWith("command_output", "")
429432
expect(terminal.proc.continue).toHaveBeenCalled()
430433

434+
// Further output after the ask must not schedule another ask.
435+
await callbacks.onLine("still working...\n", proc)
436+
expect(mockCline.ask).toHaveBeenCalledTimes(1)
437+
431438
// Let the command finish so the tool can resolve.
432439
await callbacks.onCompleted!("working...\n", proc)
433440
callbacks.onShellExecutionComplete!({ exitCode: 0 }, proc)
@@ -438,5 +445,154 @@ describe("executeCommandTool", () => {
438445

439446
expect(mockPushToolResult).toHaveBeenCalled()
440447
})
448+
449+
it("anchors the ask delay to execution start so shell integration startup does not consume it", async () => {
450+
vitest.useFakeTimers()
451+
const terminal = await setupControllableTerminal()
452+
453+
const handlePromise = handleCommand("echo hello")
454+
455+
await vitest.waitFor(() => expect(terminal.callbacks).toBeDefined())
456+
const callbacks = terminal.callbacks!
457+
const proc = terminal.proc as unknown as RooTerminalProcess
458+
459+
// Simulate a cold terminal spending most of the grace period waiting
460+
// for shell integration before the command actually starts.
461+
await vitest.advanceTimersByTimeAsync(executeCommandModule.COMMAND_OUTPUT_ASK_DELAY_MS - 2_000)
462+
callbacks.onShellExecutionStarted!(1234, proc)
463+
await callbacks.onLine("hello\n", proc)
464+
465+
// Past the pre-runCommand anchor deadline but well within the window
466+
// measured from execution start: still no ask.
467+
await vitest.advanceTimersByTimeAsync(2_500)
468+
expect(mockCline.ask).not.toHaveBeenCalled()
469+
470+
await callbacks.onCompleted!("hello\n", proc)
471+
callbacks.onShellExecutionComplete!({ exitCode: 0 }, proc)
472+
terminal.resolveProcess()
473+
await vitest.advanceTimersByTimeAsync(executeCommandModule.COMMAND_OUTPUT_ASK_DELAY_MS + 1_000)
474+
475+
await handlePromise
476+
477+
expect(mockCline.ask).not.toHaveBeenCalled()
478+
expect(mockPushToolResult).toHaveBeenCalled()
479+
})
480+
481+
it("re-anchors a pending ask when execution start is reported after early output", async () => {
482+
vitest.useFakeTimers()
483+
const terminal = await setupControllableTerminal()
484+
485+
const handlePromise = handleCommand("echo hello")
486+
487+
await vitest.waitFor(() => expect(terminal.callbacks).toBeDefined())
488+
const callbacks = terminal.callbacks!
489+
const proc = terminal.proc as unknown as RooTerminalProcess
490+
491+
// Output arrives before the execution-started event (defensive case).
492+
await callbacks.onLine("hello\n", proc)
493+
await vitest.advanceTimersByTimeAsync(executeCommandModule.COMMAND_OUTPUT_ASK_DELAY_MS - 2_000)
494+
callbacks.onShellExecutionStarted!(1234, proc)
495+
496+
// The pending ask was rescheduled against the new anchor, so the old
497+
// deadline passing must not fire it.
498+
await vitest.advanceTimersByTimeAsync(2_500)
499+
expect(mockCline.ask).not.toHaveBeenCalled()
500+
501+
await callbacks.onCompleted!("hello\n", proc)
502+
callbacks.onShellExecutionComplete!({ exitCode: 0 }, proc)
503+
terminal.resolveProcess()
504+
await vitest.advanceTimersByTimeAsync(executeCommandModule.COMMAND_OUTPUT_ASK_DELAY_MS + 1_000)
505+
506+
await handlePromise
507+
508+
expect(mockCline.ask).not.toHaveBeenCalled()
509+
})
510+
511+
it("cancels a pending ask when the agent timeout moves the command to the background", async () => {
512+
vitest.useFakeTimers()
513+
mockCline.supersedePendingAsk = vitest.fn()
514+
const terminal = await setupControllableTerminal()
515+
516+
const handlePromise = handleCommand("npm run dev", 2)
517+
518+
await vitest.waitFor(() => expect(terminal.callbacks).toBeDefined())
519+
const callbacks = terminal.callbacks!
520+
const proc = terminal.proc as unknown as RooTerminalProcess
521+
522+
callbacks.onShellExecutionStarted!(1234, proc)
523+
await callbacks.onLine("server starting...\n", proc)
524+
525+
// Agent timeout (2s) fires before the ask delay (5s).
526+
await vitest.advanceTimersByTimeAsync(2_000)
527+
expect(terminal.proc.continue).toHaveBeenCalled()
528+
expect(mockCline.supersedePendingAsk).toHaveBeenCalled()
529+
530+
// Output after the background transition must never schedule an ask.
531+
await callbacks.onLine("listening...\n", proc)
532+
await vitest.advanceTimersByTimeAsync(executeCommandModule.COMMAND_OUTPUT_ASK_DELAY_MS + 1_000)
533+
expect(mockCline.ask).not.toHaveBeenCalled()
534+
535+
await handlePromise
536+
537+
expect(mockPushToolResult).toHaveBeenCalled()
538+
expect(mockPushToolResult.mock.calls[0][0]).toContain("still running")
539+
})
540+
541+
it("swallows ask errors without failing the command", async () => {
542+
vitest.useFakeTimers()
543+
mockCline.ask.mockRejectedValue(new Error("Current ask promise was ignored"))
544+
const terminal = await setupControllableTerminal()
545+
546+
const handlePromise = handleCommand("sleep 60")
547+
548+
await vitest.waitFor(() => expect(terminal.callbacks).toBeDefined())
549+
const callbacks = terminal.callbacks!
550+
const proc = terminal.proc as unknown as RooTerminalProcess
551+
552+
callbacks.onShellExecutionStarted!(1234, proc)
553+
await callbacks.onLine("working...\n", proc)
554+
await vitest.advanceTimersByTimeAsync(executeCommandModule.COMMAND_OUTPUT_ASK_DELAY_MS)
555+
556+
expect(mockCline.ask).toHaveBeenCalledWith("command_output", "")
557+
expect(terminal.proc.continue).not.toHaveBeenCalled()
558+
559+
await callbacks.onCompleted!("working...\n", proc)
560+
callbacks.onShellExecutionComplete!({ exitCode: 0 }, proc)
561+
terminal.resolveProcess()
562+
await vitest.advanceTimersByTimeAsync(100)
563+
564+
await handlePromise
565+
566+
expect(mockPushToolResult).toHaveBeenCalled()
567+
expect(mockPushToolResult.mock.calls[0][0]).toContain("Exit code: 0")
568+
})
569+
570+
it("does not continue the process when the ask is answered without a message", async () => {
571+
vitest.useFakeTimers()
572+
mockCline.ask.mockResolvedValue({ response: "yesButtonClicked", text: undefined, images: undefined })
573+
const terminal = await setupControllableTerminal()
574+
575+
const handlePromise = handleCommand("sleep 60")
576+
577+
await vitest.waitFor(() => expect(terminal.callbacks).toBeDefined())
578+
const callbacks = terminal.callbacks!
579+
const proc = terminal.proc as unknown as RooTerminalProcess
580+
581+
callbacks.onShellExecutionStarted!(1234, proc)
582+
await callbacks.onLine("working...\n", proc)
583+
await vitest.advanceTimersByTimeAsync(executeCommandModule.COMMAND_OUTPUT_ASK_DELAY_MS)
584+
585+
expect(mockCline.ask).toHaveBeenCalledWith("command_output", "")
586+
expect(terminal.proc.continue).not.toHaveBeenCalled()
587+
588+
await callbacks.onCompleted!("working...\n", proc)
589+
callbacks.onShellExecutionComplete!({ exitCode: 0 }, proc)
590+
terminal.resolveProcess()
591+
await vitest.advanceTimersByTimeAsync(100)
592+
593+
await handlePromise
594+
595+
expect(mockPushToolResult).toHaveBeenCalled()
596+
})
441597
})
442598
})

0 commit comments

Comments
 (0)