From b28faacb188ca90fcea598dc5c421bf4f2cdea0d Mon Sep 17 00:00:00 2001 From: brennanb2025 Date: Thu, 9 Jul 2026 00:19:30 -0700 Subject: [PATCH] fix(agents): arm receipt window after paste; fix second-caller telemetry Round 1 review fixes for the receipt-based delivery verification: - Arm the 15s UserPromptSubmit receipt timeout only after the paste+Enter lands (new startTimer() on the watch), not at watch creation. The paste is gated behind a readiness wait that can run many seconds on a cold SSH boot, so the old timing could expire the window before the prompt was even submitted -> false receipt-timeout that withheld stage-1 side effects. Release the watch's IPC subscription if the paste throws. - pasteDirectWorkItemDraftWhenAgentReady now maps a receipt-timeout to error_class 'prompt_receipt_timeout' instead of folding it into 'unknown', matching the primary caller and keeping the new class accurate. - Strengthen the hookEventName guard test: emit a non-UserPromptSubmit event carrying hasExplicitPrompt:true (codex SessionStart can) so the guard is actually exercised; add a regression proving the timeout isn't armed until startTimer(); add second-caller telemetry tests. Co-authored-by: Orca --- .../lib/agent-launch-prompt-delivery.test.ts | 15 ++++- .../src/lib/agent-launch-prompt-delivery.ts | 30 ++++++--- .../lib/agent-prompt-submit-receipt.test.ts | 34 +++++++++- .../src/lib/agent-prompt-submit-receipt.ts | 26 ++++++-- .../src/lib/launch-agent-in-new-tab.test.ts | 6 +- .../lib/launch-work-item-direct-agent.test.ts | 62 ++++++++++++++++++- .../src/lib/launch-work-item-direct-agent.ts | 9 +-- 7 files changed, 153 insertions(+), 29 deletions(-) diff --git a/src/renderer/src/lib/agent-launch-prompt-delivery.test.ts b/src/renderer/src/lib/agent-launch-prompt-delivery.test.ts index 359c617128e..0eb33f76b05 100644 --- a/src/renderer/src/lib/agent-launch-prompt-delivery.test.ts +++ b/src/renderer/src/lib/agent-launch-prompt-delivery.test.ts @@ -6,7 +6,8 @@ const mocks = vi.hoisted(() => ({ markNativeChatLaunchPromptFailed: vi.fn(), isPromptReceiptEligible: vi.fn(), watchForPromptSubmitReceipt: vi.fn(), - receiptCancel: vi.fn() + receiptCancel: vi.fn(), + receiptStartTimer: vi.fn() })) vi.mock('@/lib/agent-paste-draft', () => ({ @@ -36,7 +37,8 @@ describe('deliverLaunchPromptToAgentTab', () => { mocks.isPromptReceiptEligible.mockResolvedValue(false) mocks.watchForPromptSubmitReceipt.mockReturnValue({ result: Promise.resolve(true), - cancel: mocks.receiptCancel + cancel: mocks.receiptCancel, + startTimer: mocks.receiptStartTimer }) }) @@ -183,6 +185,9 @@ describe('deliverLaunchPromptToAgentTab', () => { agent: 'codex', since: expect.any(Number) }) + // Why: the receipt window is armed only after the paste lands, so a slow + // readiness wait can't consume it before the prompt is submitted (#7466). + expect(mocks.receiptStartTimer).toHaveBeenCalledTimes(1) expect(mocks.markNativeChatLaunchPromptFailed).not.toHaveBeenCalled() }) @@ -190,7 +195,8 @@ describe('deliverLaunchPromptToAgentTab', () => { mocks.isPromptReceiptEligible.mockResolvedValue(true) mocks.watchForPromptSubmitReceipt.mockReturnValue({ result: Promise.resolve(false), - cancel: mocks.receiptCancel + cancel: mocks.receiptCancel, + startTimer: mocks.receiptStartTimer }) const onTimeout = vi.fn() @@ -224,6 +230,9 @@ describe('deliverLaunchPromptToAgentTab', () => { ).resolves.toBe(false) expect(mocks.receiptCancel).toHaveBeenCalledTimes(1) + // Why: a failed paste never submits a prompt, so the receipt window is + // released rather than armed. + expect(mocks.receiptStartTimer).not.toHaveBeenCalled() }) it('keeps the optimistic verdict for agents without installed managed hooks', async () => { diff --git a/src/renderer/src/lib/agent-launch-prompt-delivery.ts b/src/renderer/src/lib/agent-launch-prompt-delivery.ts index 44ddcb972e8..6dabda08b4c 100644 --- a/src/renderer/src/lib/agent-launch-prompt-delivery.ts +++ b/src/renderer/src/lib/agent-launch-prompt-delivery.ts @@ -57,15 +57,23 @@ export async function deliverLaunchPromptToAgentTab(args: { } } - const pasted = await pasteDraftWhenAgentReady({ - tabId, - content, - agent, - submit, - forcePaste, - timeoutMs, - onTimeout: onTimeout ? () => onTimeout('readiness-timeout') : undefined - }) + let pasted: boolean + try { + pasted = await pasteDraftWhenAgentReady({ + tabId, + content, + agent, + submit, + forcePaste, + timeoutMs, + onTimeout: onTimeout ? () => onTimeout('readiness-timeout') : undefined + }) + } catch (error) { + // Why: the receipt timeout is only armed after a successful paste, so an + // unexpected paste throw must still release the watch's IPC subscription. + receiptWatch?.cancel() + throw error + } if (!pasted && !deliversViaNativePrefill) { receiptWatch?.cancel() @@ -74,6 +82,10 @@ export async function deliverLaunchPromptToAgentTab(args: { } if (receiptWatch) { + // Why: arm the receipt window only now that the paste+Enter is in, so the + // full timeout covers the post-submit hook round-trip rather than the + // preceding readiness wait (which can run many seconds on a cold SSH boot). + receiptWatch.startTimer() const receipted = await receiptWatch.result if (!receipted) { onTimeout?.('receipt-timeout') diff --git a/src/renderer/src/lib/agent-prompt-submit-receipt.test.ts b/src/renderer/src/lib/agent-prompt-submit-receipt.test.ts index a581c8ac06d..950230aaf98 100644 --- a/src/renderer/src/lib/agent-prompt-submit-receipt.test.ts +++ b/src/renderer/src/lib/agent-prompt-submit-receipt.test.ts @@ -76,20 +76,25 @@ describe('agent-prompt-submit-receipt', () => { since: 1000, timeoutMs: 50 }) + watch.startTimer() emit({ tabId: 'tab-2', receivedAt: 2000 }) await vi.advanceTimersByTimeAsync(50) await expect(watch.result).resolves.toBe(false) }) - it('ignores non-submit hook events — codex SessionStart also maps to working', async () => { + it('ignores non-submit hook events even when they carry an explicit prompt', async () => { const watch = watchForPromptSubmitReceipt({ tabId: 'tab-1', agent: 'codex', since: 1000, timeoutMs: 50 }) - emit({ hookEventName: 'SessionStart', hasExplicitPrompt: undefined, receivedAt: 2000 }) - emit({ hookEventName: 'PreToolUse', hasExplicitPrompt: undefined, receivedAt: 2000 }) + watch.startTimer() + // Why: the codex normalizer can stamp hasExplicitPrompt on a SessionStart + // that carries a prompt (it maps to working too), so the hookEventName + // guard — not hasExplicitPrompt alone — is what rejects the boot event. + emit({ hookEventName: 'SessionStart', hasExplicitPrompt: true, receivedAt: 2000 }) + emit({ hookEventName: 'PreToolUse', hasExplicitPrompt: true, receivedAt: 2000 }) await vi.advanceTimersByTimeAsync(50) await expect(watch.result).resolves.toBe(false) }) @@ -101,6 +106,7 @@ describe('agent-prompt-submit-receipt', () => { since: 1000, timeoutMs: 50 }) + watch.startTimer() emit({ hasExplicitPrompt: undefined, receivedAt: 2000 }) await vi.advanceTimersByTimeAsync(50) await expect(watch.result).resolves.toBe(false) @@ -113,6 +119,7 @@ describe('agent-prompt-submit-receipt', () => { since: 10_000, timeoutMs: 50 }) + watch.startTimer() emit({ receivedAt: 1000 }) await vi.advanceTimersByTimeAsync(50) await expect(watch.result).resolves.toBe(false) @@ -125,6 +132,7 @@ describe('agent-prompt-submit-receipt', () => { since: 1000, timeoutMs: 50 }) + watch.startTimer() emit({ agentType: 'codex', receivedAt: 2000 }) await vi.advanceTimersByTimeAsync(50) await expect(watch.result).resolves.toBe(false) @@ -137,11 +145,31 @@ describe('agent-prompt-submit-receipt', () => { since: 1000, timeoutMs: 100 }) + watch.startTimer() await vi.advanceTimersByTimeAsync(100) await expect(watch.result).resolves.toBe(false) expect(unsubscribe).toHaveBeenCalledTimes(1) }) + it('does not arm the timeout until startTimer is called', async () => { + // Why: the window must cover the post-submit hook round-trip, not the + // readiness wait that precedes the paste — arming at creation would + // expire the window during a slow cold boot (#7466). + const watch = watchForPromptSubmitReceipt({ + tabId: 'tab-1', + agent: 'codex', + since: 1000, + timeoutMs: 50 + }) + await vi.advanceTimersByTimeAsync(1000) + const pending = Symbol('pending') + await expect(Promise.race([watch.result, Promise.resolve(pending)])).resolves.toBe(pending) + + watch.startTimer() + await vi.advanceTimersByTimeAsync(50) + await expect(watch.result).resolves.toBe(false) + }) + it('cancel resolves false immediately', async () => { const watch = watchForPromptSubmitReceipt({ tabId: 'tab-1', agent: 'codex', since: 1000 }) watch.cancel() diff --git a/src/renderer/src/lib/agent-prompt-submit-receipt.ts b/src/renderer/src/lib/agent-prompt-submit-receipt.ts index 431bb2f26e2..24254970f6d 100644 --- a/src/renderer/src/lib/agent-prompt-submit-receipt.ts +++ b/src/renderer/src/lib/agent-prompt-submit-receipt.ts @@ -58,14 +58,23 @@ export async function isPromptReceiptEligible(agent: TuiAgent | undefined): Prom export type PromptSubmitReceiptWatch = { /** Resolves true when a UserPromptSubmit receipt for the tab arrives; false on timeout/cancel. */ result: Promise + /** + * Arm the timeout countdown. Call AFTER the paste+Enter is issued so the full + * window covers the post-submit hook round-trip, not the readiness wait that + * precedes the paste (which can run many seconds on a cold SSH boot) — + * otherwise the window expires before the prompt is even submitted (issue + * #7466). Idempotent and a no-op once the watch has settled. + */ + startTimer: () => void cancel: () => void } /** * Watch the agent-status IPC stream for a UserPromptSubmit receipt bound to - * `tabId`. Start the watch BEFORE submitting so a fast receipt cannot slip - * past the subscription. Remote (SSH) launches arrive through the same - * channel via the agent-hook relay, so no transport split is needed. + * `tabId`. Subscribe BEFORE submitting so a fast receipt cannot slip past the + * subscription, then call `startTimer()` once the paste is in to arm the + * timeout. Remote (SSH) launches arrive through the same channel via the + * agent-hook relay, so no transport split is needed. */ export function watchForPromptSubmitReceipt(args: { tabId: string @@ -75,6 +84,7 @@ export function watchForPromptSubmitReceipt(args: { }): PromptSubmitReceiptWatch { const { tabId, agent, since, timeoutMs } = args let cancel: () => void = () => {} + let startTimer: () => void = () => {} const result = new Promise((resolve) => { let settled = false let unsubscribe: (() => void) | null = null @@ -92,6 +102,12 @@ export function watchForPromptSubmitReceipt(args: { resolve(value) } cancel = () => finish(false) + startTimer = () => { + if (settled || timer !== null) { + return + } + timer = window.setTimeout(() => finish(false), timeoutMs ?? PROMPT_RECEIPT_TIMEOUT_MS) + } unsubscribe = window.api.agentStatus.onSet((data: AgentStatusIpcPayload) => { if (data.tabId !== tabId) { @@ -108,8 +124,6 @@ export function watchForPromptSubmitReceipt(args: { } finish(true) }) - - timer = window.setTimeout(() => finish(false), timeoutMs ?? PROMPT_RECEIPT_TIMEOUT_MS) }) - return { result, cancel } + return { result, startTimer, cancel } } diff --git a/src/renderer/src/lib/launch-agent-in-new-tab.test.ts b/src/renderer/src/lib/launch-agent-in-new-tab.test.ts index a64b3d737c4..b189a0dc296 100644 --- a/src/renderer/src/lib/launch-agent-in-new-tab.test.ts +++ b/src/renderer/src/lib/launch-agent-in-new-tab.test.ts @@ -161,7 +161,8 @@ describe('launchAgentInNewTab', () => { mockIsPromptReceiptEligible.mockResolvedValue(false) mockWatchForPromptSubmitReceipt.mockReturnValue({ result: Promise.resolve(true), - cancel: vi.fn() + cancel: vi.fn(), + startTimer: vi.fn() }) }) @@ -702,7 +703,8 @@ describe('launchAgentInNewTab', () => { mockIsPromptReceiptEligible.mockResolvedValue(true) mockWatchForPromptSubmitReceipt.mockReturnValue({ result: Promise.resolve(false), - cancel: vi.fn() + cancel: vi.fn(), + startTimer: vi.fn() }) store.tabsByWorktree = { 'wt-1': [{ id: 'tab-1', ptyId: 'pty-1' } as never] } const { launchAgentInNewTab } = await import('./launch-agent-in-new-tab') diff --git a/src/renderer/src/lib/launch-work-item-direct-agent.test.ts b/src/renderer/src/lib/launch-work-item-direct-agent.test.ts index 29d373bf546..8149d14309a 100644 --- a/src/renderer/src/lib/launch-work-item-direct-agent.test.ts +++ b/src/renderer/src/lib/launch-work-item-direct-agent.test.ts @@ -1,14 +1,23 @@ -import { describe, expect, it, vi } from 'vitest' +import { beforeEach, describe, expect, it, vi } from 'vitest' + +const mocks = vi.hoisted(() => ({ deliverLaunchPromptToAgentTab: vi.fn() })) vi.mock('sonner', () => ({ toast: { message: vi.fn() } })) vi.mock('@/lib/agent-paste-draft', () => ({ pasteDraftWhenAgentReady: vi.fn() })) +vi.mock('@/lib/agent-launch-prompt-delivery', () => ({ + deliverLaunchPromptToAgentTab: mocks.deliverLaunchPromptToAgentTab +})) vi.mock('@/lib/telemetry', () => ({ track: vi.fn(), tuiAgentToAgentKind: (agent: string) => agent })) vi.mock('@/i18n/i18n', () => ({ translate: (_key: string, value: string) => value })) -import { buildDirectWorkItemStartupOpts } from './launch-work-item-direct-agent' +import { track } from '@/lib/telemetry' +import { + buildDirectWorkItemStartupOpts, + pasteDirectWorkItemDraftWhenAgentReady +} from './launch-work-item-direct-agent' import type { AgentStartupPlan } from './tui-agent-startup' describe('buildDirectWorkItemStartupOpts', () => { @@ -37,3 +46,52 @@ describe('buildDirectWorkItemStartupOpts', () => { }) }) }) + +describe('pasteDirectWorkItemDraftWhenAgentReady onTimeout telemetry', () => { + const plan: AgentStartupPlan = { + agent: 'codex', + launchCommand: "codex 'review linked issue'", + expectedProcess: 'codex', + followupPrompt: null, + launchConfig: { agentArgs: '', agentEnv: {} }, + startupCommandDelivery: 'shell-ready' + } + + beforeEach(() => { + vi.clearAllMocks() + }) + + async function runWithTimeoutReason( + reason: 'readiness-timeout' | 'receipt-timeout' + ): Promise { + mocks.deliverLaunchPromptToAgentTab.mockImplementation( + async (args: { onTimeout?: (reason?: 'readiness-timeout' | 'receipt-timeout') => void }) => { + args.onTimeout?.(reason) + return false + } + ) + await pasteDirectWorkItemDraftWhenAgentReady({ + primaryTabId: 'tab-1', + startupPlan: plan, + content: 'do the thing', + submit: true, + forcePaste: true + }) + } + + it('classifies a swallowed submit as prompt_receipt_timeout', async () => { + await runWithTimeoutReason('receipt-timeout') + expect(track).toHaveBeenCalledWith('agent_error', { + error_class: 'prompt_receipt_timeout', + agent_kind: 'codex' + }) + }) + + it('folds other startup timeouts to unknown', async () => { + await runWithTimeoutReason('readiness-timeout') + expect(track).toHaveBeenCalledWith('agent_error', { + error_class: 'unknown', + agent_kind: 'codex' + }) + }) +}) diff --git a/src/renderer/src/lib/launch-work-item-direct-agent.ts b/src/renderer/src/lib/launch-work-item-direct-agent.ts index 6e259f9a2e1..593afc5ae78 100644 --- a/src/renderer/src/lib/launch-work-item-direct-agent.ts +++ b/src/renderer/src/lib/launch-work-item-direct-agent.ts @@ -150,7 +150,7 @@ export async function pasteDirectWorkItemDraftWhenAgentReady(args: { agent: startupPlan.agent, submit, forcePaste, - onTimeout: () => { + onTimeout: (reason) => { const label = submit ? 'prompt' : 'work item context' toast.message( translate( @@ -159,10 +159,11 @@ export async function pasteDirectWorkItemDraftWhenAgentReady(args: { { value0: label } ) ) - // Why: process-startup timeout has no v1 enum slot; the `unknown` slice - // on the dashboard is the trigger to add one. + // Why: a swallowed submit is its own class (#7466); other startup + // timeouts still fold to `unknown`, whose dashboard slice is the trigger + // to add a dedicated enum value. track('agent_error', { - error_class: 'unknown', + error_class: reason === 'receipt-timeout' ? 'prompt_receipt_timeout' : 'unknown', agent_kind: tuiAgentToAgentKind(startupPlan.agent) }) }