diff --git a/mobile/src/session/MobileNativeChatOverlay.tsx b/mobile/src/session/MobileNativeChatOverlay.tsx index 357a089466e..303d2343c38 100644 --- a/mobile/src/session/MobileNativeChatOverlay.tsx +++ b/mobile/src/session/MobileNativeChatOverlay.tsx @@ -72,6 +72,8 @@ export function MobileNativeChatOverlay({ agent={controller.nativeChatAgent} agentWorking={controller.nativeChatAgentWorking} structuredActivityUi={controller.nativeChatStructured} + workingStartedAt={controller.nativeChatWorkingStartedAt} + settledTurns={controller.nativeChatSettledTurns} streaming={streaming} onStop={controller.handleNativeChatStop} ask={controller.nativeChatAsk} diff --git a/mobile/src/session/MobileNativeChatView.tsx b/mobile/src/session/MobileNativeChatView.tsx index 70a67787de0..27dccb88459 100644 --- a/mobile/src/session/MobileNativeChatView.tsx +++ b/mobile/src/session/MobileNativeChatView.tsx @@ -13,6 +13,7 @@ import { GestureDetector, GestureHandlerRootView } from 'react-native-gesture-ha import { ArrowDown, ChevronsDownUp, ChevronsUpDown, Square } from 'lucide-react-native' import type { AskAnswerSelection, AskPrompt } from '../../../src/shared/native-chat-ask' import type { NativeChatMessage } from '../../../src/shared/native-chat-types' +import type { NativeChatSettledTurn } from '../../../src/shared/native-chat-turn-status' import { colors } from '../theme/mobile-theme' import { styles } from './mobile-native-chat-view-styles' import { @@ -22,6 +23,7 @@ import { } from './mobile-native-chat-render-data' import { useMobileNativeChatPinchGesture } from './use-mobile-native-chat-pinch-gesture' import { useMobileNativeChatTurnDisclosure } from './use-mobile-native-chat-turn-disclosure' +import { useSettledMobileNativeChatInputLock } from './use-mobile-native-chat-input-lease' import { MobileNativeChatTurnStatus } from './MobileNativeChatTurnStatus' import { MobileAgentWorkingIndicator } from './MobileAgentWorkingIndicator' import type { PendingNativeChatImage } from './mobile-native-chat-image-attachment' @@ -33,8 +35,6 @@ import type { MobileNativeChatSessionOptionPickersProps } from './MobileNativeCh import { MobileNativeChatMessage } from './MobileNativeChatMessage' import type { MobileNativeChatStatus } from './use-mobile-native-chat-session' -const INPUT_LOCK_SETTLE_MS = 600 - /** Why the composer input is locked: the transport is disconnected, or the * terminal subscription has not acknowledged its input lease yet. */ export type MobileNativeChatInputLockReason = 'disconnected' | 'waiting' @@ -52,6 +52,9 @@ type Props = { /** Structured lane: per-turn "Working for N" status plus live tool progress, * replacing the bridge lane's static three-dot working row (desktop parity). */ structuredActivityUi?: boolean + /** Structured lane: host-recorded turn timing feeding the per-turn status rows. */ + workingStartedAt?: number | null + settledTurns?: ReadonlyMap | null /** Interrupt the agent mid-turn (shown as a Stop button on the working bar). */ onStop?: () => void /** Live partial assistant text to show as an in-progress bubble, already gated @@ -130,6 +133,8 @@ export function MobileNativeChatView({ agent, agentWorking, structuredActivityUi = false, + workingStartedAt, + settledTurns, onStop, streaming, hasMore, @@ -262,6 +267,8 @@ export function MobileNativeChatView({ messages: data, enabled: structuredActivityUi, isWorking: agentWorking === true, + workingStartedAt, + settledTurns, scopeKey: sendSurfaceId }) @@ -285,18 +292,7 @@ export function MobileNativeChatView({ const emptyState = mobileNativeChatEmptyState(status, agent ?? null, error) const showLoading = status === 'loading' && messages.length === 0 - // A dead PTY emits subscribed→end; settle both edges so its false lease cannot flash the composer enabled. - const rawLockReason = inputLockReason ?? null - const rawLockHeld = rawLockReason !== null - const [lockHeld, setLockHeld] = useState(false) - useEffect(() => { - if (rawLockHeld === lockHeld) { - return - } - const timer = setTimeout(() => setLockHeld(rawLockHeld), INPUT_LOCK_SETTLE_MS) - return () => clearTimeout(timer) - }, [lockHeld, rawLockHeld]) - const lockReason = lockHeld ? (rawLockReason ?? 'waiting') : null + const lockReason = useSettledMobileNativeChatInputLock(inputLockReason) return ( diff --git a/mobile/src/session/mobile-native-chat-controller-contract.ts b/mobile/src/session/mobile-native-chat-controller-contract.ts index 53187e0d6db..5645706a437 100644 --- a/mobile/src/session/mobile-native-chat-controller-contract.ts +++ b/mobile/src/session/mobile-native-chat-controller-contract.ts @@ -6,6 +6,7 @@ import type { } from '../../../src/shared/native-chat-ask' import type { detectAgentPermission } from './mobile-native-chat-permission' import type { parseAgentQuestion } from './mobile-native-chat-question' +import type { NativeChatSettledTurn } from '../../../src/shared/native-chat-turn-status' import type { MobileNativeChatSendOutcome } from './mobile-native-chat-send' import type { MobileNativeChatPendingMessage } from './use-mobile-native-chat-drafts' import type { useMobileNativeChatSession } from './use-mobile-native-chat-session' @@ -28,6 +29,9 @@ export type MobileNativeChatController = { /** Structured lane: drives the per-turn status row and live tool progress. */ nativeChatStructured: boolean nativeChatAgentWorking: boolean + /** Structured lane: host-recorded turn timing for the per-turn status rows. */ + nativeChatWorkingStartedAt: number | null + nativeChatSettledTurns: ReadonlyMap | null nativeChatStreamingText?: string /** Agent mid-turn, regardless of whether chat is the visible view. */ nativeChatStreamLive: boolean diff --git a/mobile/src/session/use-mobile-native-chat-controller.ts b/mobile/src/session/use-mobile-native-chat-controller.ts index 729cec302c1..c5b7504e51b 100644 --- a/mobile/src/session/use-mobile-native-chat-controller.ts +++ b/mobile/src/session/use-mobile-native-chat-controller.ts @@ -299,6 +299,8 @@ export function useMobileNativeChatController(args: { /** Structured lane: drives the per-turn status row and live tool progress. */ nativeChatStructured: activeChatStructured, nativeChatAgentWorking, + nativeChatWorkingStartedAt: activeChatStructured ? structuredNativeChat.workingStartedAt : null, + nativeChatSettledTurns: activeChatStructured ? structuredNativeChat.settledTurns : null, nativeChatStreamingText, nativeChatStreamLive, nativeChatStreamScopeKey: streamScopeKey, diff --git a/mobile/src/session/use-mobile-native-chat-input-lease.test.ts b/mobile/src/session/use-mobile-native-chat-input-lease.test.ts index 7491f74500f..6e4d12a2bcc 100644 --- a/mobile/src/session/use-mobile-native-chat-input-lease.test.ts +++ b/mobile/src/session/use-mobile-native-chat-input-lease.test.ts @@ -1,7 +1,10 @@ import { createElement } from 'react' import { act, create, type ReactTestRenderer } from 'react-test-renderer' -import { afterEach, describe, expect, it } from 'vitest' -import { useMobileNativeChatInputLease } from './use-mobile-native-chat-input-lease' +import { afterEach, describe, expect, it, vi } from 'vitest' +import { + useMobileNativeChatInputLease, + useSettledMobileNativeChatInputLock +} from './use-mobile-native-chat-input-lease' type Lease = ReturnType @@ -61,3 +64,40 @@ describe('useMobileNativeChatInputLease', () => { expect(lease?.clear()).toBe(true) }) }) + +describe('useSettledMobileNativeChatInputLock', () => { + let renderer: ReactTestRenderer | null = null + let settled: ReturnType | undefined + + afterEach(() => { + act(() => renderer?.unmount()) + renderer = null + vi.useRealTimers() + }) + + function Harness({ reason }: { reason: 'waiting' | 'disconnected' | null }): null { + settled = useSettledMobileNativeChatInputLock(reason) + return null + } + + it('holds each edge until the lease has stopped flapping', () => { + vi.useFakeTimers() + act(() => { + renderer = create(createElement(Harness, { reason: 'waiting' })) + }) + expect(settled).toBeNull() + act(() => vi.advanceTimersByTime(600)) + expect(settled).toBe('waiting') + + // A brief unlock that reverts inside the settle window never reaches the composer. + act(() => renderer?.update(createElement(Harness, { reason: null }))) + act(() => vi.advanceTimersByTime(300)) + act(() => renderer?.update(createElement(Harness, { reason: 'disconnected' }))) + act(() => vi.advanceTimersByTime(600)) + expect(settled).toBe('disconnected') + + act(() => renderer?.update(createElement(Harness, { reason: null }))) + act(() => vi.advanceTimersByTime(600)) + expect(settled).toBeNull() + }) +}) diff --git a/mobile/src/session/use-mobile-native-chat-input-lease.ts b/mobile/src/session/use-mobile-native-chat-input-lease.ts index fddf9274573..f1489faa9cd 100644 --- a/mobile/src/session/use-mobile-native-chat-input-lease.ts +++ b/mobile/src/session/use-mobile-native-chat-input-lease.ts @@ -72,3 +72,23 @@ export function useMobileNativeChatInputLease(args: { clear } } + +const INPUT_LOCK_SETTLE_MS = 600 + +/** A dead PTY emits subscribed→end; settle both edges so its false lease cannot + * flash the composer enabled. */ +export function useSettledMobileNativeChatInputLock( + reason: MobileNativeChatInputLockReason | null | undefined +): MobileNativeChatInputLockReason | null { + const rawLockReason = reason ?? null + const rawLockHeld = rawLockReason !== null + const [lockHeld, setLockHeld] = useState(false) + useEffect(() => { + if (rawLockHeld === lockHeld) { + return + } + const timer = setTimeout(() => setLockHeld(rawLockHeld), INPUT_LOCK_SETTLE_MS) + return () => clearTimeout(timer) + }, [lockHeld, rawLockHeld]) + return lockHeld ? (rawLockReason ?? 'waiting') : null +} diff --git a/mobile/src/session/use-mobile-native-chat-turn-disclosure.test.tsx b/mobile/src/session/use-mobile-native-chat-turn-disclosure.test.tsx index 8467684ce16..8fef2433662 100644 --- a/mobile/src/session/use-mobile-native-chat-turn-disclosure.test.tsx +++ b/mobile/src/session/use-mobile-native-chat-turn-disclosure.test.tsx @@ -2,6 +2,7 @@ import { createElement } from 'react' import { act, create, type ReactTestRenderer } from 'react-test-renderer' import { afterEach, describe, expect, it, vi } from 'vitest' import type { NativeChatMessage } from '../../../src/shared/native-chat-types' +import type { NativeChatSettledTurn } from '../../../src/shared/native-chat-turn-status' import { useMobileNativeChatTurnDisclosure } from './use-mobile-native-chat-turn-disclosure' function userMessage(id: string): NativeChatMessage { @@ -18,17 +19,20 @@ function Harness({ messages, enabled, isWorking = true, + settledTurns, scopeKey = 'host\0worktree\0tab-a' }: { messages: readonly NativeChatMessage[] enabled: boolean isWorking?: boolean + settledTurns?: ReadonlyMap scopeKey?: string }): React.JSX.Element { const disclosure = useMobileNativeChatTurnDisclosure({ messages, enabled, isWorking, + settledTurns, scopeKey }) return createElement('result', { disclosure }) @@ -116,6 +120,30 @@ describe('useMobileNativeChatTurnDisclosure', () => { } }) + it('shows the host-recorded duration over the locally observed one', () => { + vi.useFakeTimers() + try { + vi.setSystemTime(1_000) + const messages = [userMessage('u1')] + act(() => { + renderer = create(createElement(Harness, { messages, enabled: true })) + }) + // Locally this turn ran 5s; the host says 3m 17s and the host wins. + vi.setSystemTime(6_000) + const settledTurns = new Map([['u1', { startedAt: 500, workedSeconds: 197 }]]) + act(() => { + renderer?.update( + createElement(Harness, { messages, enabled: true, isWorking: false, settledTurns }) + ) + }) + const row = renderer!.root.findByType('result').props.disclosure.resolveRow(0, messages[0]) + expect(row.turnStatus).toEqual({ startedAt: 500, thinking: false, workedSeconds: 197 }) + expect(row.turnKey).toBe('u1') + } finally { + vi.useRealTimers() + } + }) + it('keeps at most the latest 128 turns expanded', () => { vi.useFakeTimers() try { diff --git a/mobile/src/session/use-mobile-native-chat-turn-disclosure.ts b/mobile/src/session/use-mobile-native-chat-turn-disclosure.ts index 46b58f29cba..a1cc5c14201 100644 --- a/mobile/src/session/use-mobile-native-chat-turn-disclosure.ts +++ b/mobile/src/session/use-mobile-native-chat-turn-disclosure.ts @@ -1,5 +1,6 @@ import { useCallback, useMemo, useState } from 'react' import type { NativeChatMessage } from '../../../src/shared/native-chat-types' +import type { NativeChatSettledTurn } from '../../../src/shared/native-chat-turn-status' import { MOBILE_UNANCHORED_TURN_KEY, useMobileNativeChatTurnStatus, @@ -25,11 +26,16 @@ export function useMobileNativeChatTurnDisclosure({ messages, enabled, isWorking, + workingStartedAt, + settledTurns, scopeKey }: { messages: readonly NativeChatMessage[] enabled: boolean isWorking: boolean + workingStartedAt?: number | null + /** Host-recorded durations; they outrank whatever this client observed. */ + settledTurns?: ReadonlyMap | null /** Host/worktree/tab identity for timing and disclosure isolation. */ scopeKey: string }): { @@ -43,6 +49,8 @@ export function useMobileNativeChatTurnDisclosure({ messages, enabled, isWorking, + workingStartedAt, + settledTurns, scopeKey }) const [expandedTurns, setExpandedTurns] = useState<{ diff --git a/mobile/src/session/use-mobile-native-chat-turn-status.ts b/mobile/src/session/use-mobile-native-chat-turn-status.ts index 13afbe70c09..eb3cf42b403 100644 --- a/mobile/src/session/use-mobile-native-chat-turn-status.ts +++ b/mobile/src/session/use-mobile-native-chat-turn-status.ts @@ -4,6 +4,7 @@ import { nativeChatTurnHasResponse, reduceNativeChatTurnTiming, selectNativeChatTurnStatuses, + type NativeChatSettledTurn, type NativeChatTurnStatus, type NativeChatTurnTimingByTurn } from '../../../src/shared/native-chat-turn-status' @@ -25,12 +26,15 @@ export function useMobileNativeChatTurnStatus({ enabled, isWorking, workingStartedAt, + settledTurns, scopeKey }: { messages: readonly NativeChatMessage[] enabled: boolean isWorking: boolean workingStartedAt?: number | null + /** Host-recorded durations; they outrank whatever this client observed. */ + settledTurns?: ReadonlyMap | null /** Host/worktree/tab identity. Timings never carry across chat surfaces. */ scopeKey: string }): { @@ -91,15 +95,24 @@ export function useMobileNativeChatTurnStatus({ // turn re-renders ~20x/s. Without this, every settled turn's row gets fresh // props each tick and the memoized message rows all re-render. const turnIsWorking = enabled && isWorking + const settledByTurn = enabled ? (settledTurns ?? undefined) : undefined const statuses = useMemo( () => selectNativeChatTurnStatuses(timingByTurn, { activeTurnKey, isWorking: turnIsWorking, workingStartedAt, - hasCurrentTurnResponse + hasCurrentTurnResponse, + settledByTurn }), - [timingByTurn, activeTurnKey, turnIsWorking, workingStartedAt, hasCurrentTurnResponse] + [ + timingByTurn, + activeTurnKey, + turnIsWorking, + workingStartedAt, + hasCurrentTurnResponse, + settledByTurn + ] ) return { ...statuses, activeTurnKey } } diff --git a/mobile/src/session/use-mobile-structured-agent-session.ts b/mobile/src/session/use-mobile-structured-agent-session.ts index 271f9143671..f4f4a4eb348 100644 --- a/mobile/src/session/use-mobile-structured-agent-session.ts +++ b/mobile/src/session/use-mobile-structured-agent-session.ts @@ -31,25 +31,27 @@ import type { MobileNativeChatSession } from './use-mobile-native-chat-session' import { useMobileStructuredAgentState } from './use-mobile-structured-agent-state' import { useMobileStructuredPromptResponses } from './use-mobile-structured-prompt-responses' import { useMobileStructuredAgentOptions } from './use-mobile-structured-agent-options' +import { useMobileStructuredAgentTurnTiming } from './use-mobile-structured-agent-turn-timing' type StructuredMobileAttachment = StructuredAgentSessionAttachment & { id?: string } -type StructuredMobileSession = ReturnType & { - session: MobileNativeChatSession - isWorking: boolean - turnId: string | null - sendWithOutcome: ( - text: string, - images?: string[], - deadline?: number, - attachments?: readonly StructuredMobileAttachment[] - ) => Promise - cancel: () => void - permission: MobileChatPermission | null - question: MobileChatQuestion | null - respondPermission: (optionId: string) => Promise - respondQuestion: (answer: string) => Promise -} +type StructuredMobileSession = ReturnType & + ReturnType & { + session: MobileNativeChatSession + isWorking: boolean + turnId: string | null + sendWithOutcome: ( + text: string, + images?: string[], + deadline?: number, + attachments?: readonly StructuredMobileAttachment[] + ) => Promise + cancel: () => void + permission: MobileChatPermission | null + question: MobileChatQuestion | null + respondPermission: (optionId: string) => Promise + respondQuestion: (answer: string) => Promise + } export function useMobileStructuredAgentSession(args: { client: RpcClient | null @@ -269,6 +271,8 @@ export function useMobileStructuredAgentSession(args: { () => projectStructuredAgentSessionMessages(state.items, [], state.submissions), [state.items, state.submissions] ) + const turnId = activeStructuredAgentSessionTurnId(state.items) + const turnTiming = useMobileStructuredAgentTurnTiming(state.items, turnId) const status = state.status === 'idle' ? 'idle' : state.status const approvalPrompt = useMemo( () => state.items.find(pendingStructuredApproval) ?? null, @@ -291,8 +295,9 @@ export function useMobileStructuredAgentSession(args: { loadingEarlier: loadingOlder, loadEarlier }, - isWorking: activeStructuredAgentSessionTurnId(state.items) !== null, - turnId: activeStructuredAgentSessionTurnId(state.items), + isWorking: turnId !== null, + turnId, + ...turnTiming, sendWithOutcome, cancel, permission: projectStructuredPermission(approvalPrompt), diff --git a/mobile/src/session/use-mobile-structured-agent-session.turn-timing.test.tsx b/mobile/src/session/use-mobile-structured-agent-session.turn-timing.test.tsx new file mode 100644 index 00000000000..fab91d39442 --- /dev/null +++ b/mobile/src/session/use-mobile-structured-agent-session.turn-timing.test.tsx @@ -0,0 +1,151 @@ +import { createElement } from 'react' +import { act, create, type ReactTestRenderer } from 'react-test-renderer' +import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest' +import type { AgentJournalRenderItem } from '../../../src/shared/agent-session-journal-types' +import type { AgentSessionSubscribeEvent } from '../../../src/shared/agent-session-wire' +import type { RpcClient } from '../transport/rpc-client' +import { useMobileStructuredAgentSession } from './use-mobile-structured-agent-session' + +function ok(result: unknown) { + return { ok: true, result, _meta: { runtimeId: 'runtime-1' } } +} + +function snapshotEvent(items: AgentJournalRenderItem[]): AgentSessionSubscribeEvent { + return { + type: 'snapshot', + sessionId: 'session-1', + fence: 3, + page: { + sessionId: 'session-1', + epoch: 'epoch-1', + fence: 3, + direction: 'tail', + items, + removedItemIds: [], + submissions: [], + window: { + oldest: null, + newest: null, + nextCursor: { epoch: 'epoch-1', sequence: 0 } + }, + liveCursor: { epoch: 'epoch-1', sequence: 0 }, + hasOlder: false, + hasNewer: false + } + } +} + +function user(itemId: string, sequence: number, observedAt: number): AgentJournalRenderItem { + return { + itemId, + revision: 0, + sequence, + observedAt, + body: { kind: 'message', role: 'user', blocks: [{ type: 'text', text: itemId }] } + } +} + +async function sendRequest(method: string) { + if (method === 'agentSession.options') { + return ok({ + models: [ + { + id: 'gpt-fast', + label: 'GPT Fast', + isDefault: true, + defaultEffort: 'low', + efforts: [{ value: 'low', label: 'Low' }] + } + ], + current: { model: 'gpt-fast', effort: 'low' } + }) + } + return ok({}) +} + +describe('useMobileStructuredAgentSession turn timing', () => { + let renderer: ReactTestRenderer | null = null + let hook: ReturnType | null = null + let listener: ((value: unknown) => void) | null = null + const subscribe = vi.fn((_method: string, _params: unknown, onData: (value: unknown) => void) => { + listener = onData + return vi.fn() + }) + const client = { sendRequest: vi.fn(sendRequest), subscribe } as unknown as RpcClient + + function Harness(): null { + hook = useMobileStructuredAgentSession({ + client, + sessionId: 'session-1', + sourceIdentity: 'host-a\0workspace-a', + enabled: true, + connected: true, + agent: 'codex', + onSendError: vi.fn() + } as never) + return null + } + + beforeEach(() => { + listener = null + vi.useFakeTimers({ shouldAdvanceTime: true }) + }) + + afterEach(() => { + act(() => renderer?.unmount()) + renderer = null + hook = null + vi.useRealTimers() + }) + + it('exposes host-settled durations and a skew-free live anchor', async () => { + vi.setSystemTime(50_000) + act(() => { + renderer = create(createElement(Harness)) + }) + await vi.waitFor(() => expect(listener).toEqual(expect.any(Function))) + act(() => + listener?.( + snapshotEvent([ + user('u1', 1, 9_000_000), + { + itemId: 'l1', + revision: 1, + sequence: 2, + observedAt: 9_000_100, + body: { + kind: 'status', + text: 'Done', + turnLifecycle: { + turnId: 't1', + state: 'completed', + startedAt: 9_000_000, + completedAt: 9_004_000 + } + } + }, + user('u2', 3, 9_010_000), + { + itemId: 'l2', + revision: 1, + sequence: 4, + observedAt: 9_010_300, + body: { + kind: 'status', + text: 'Working', + turnLifecycle: { turnId: 't2', state: 'running', startedAt: 9_010_000 } + } + } + ]) + ) + ) + expect(hook?.isWorking).toBe(true) + const anchor = hook!.workingStartedAt + // Client clock (50s) is nowhere near the host's (9,010s): only the 300ms append lag moves it. + expect(anchor).toBe(Date.now() - 300) + expect([...hook!.settledTurns]).toEqual([['u1', { startedAt: 9_000_000, workedSeconds: 4 }]]) + vi.setSystemTime(Date.now() + 30_000) + act(() => renderer?.update(createElement(Harness))) + expect(hook?.workingStartedAt).toBe(anchor) + }) +}) diff --git a/mobile/src/session/use-mobile-structured-agent-turn-timing.test.tsx b/mobile/src/session/use-mobile-structured-agent-turn-timing.test.tsx new file mode 100644 index 00000000000..f79d922a877 --- /dev/null +++ b/mobile/src/session/use-mobile-structured-agent-turn-timing.test.tsx @@ -0,0 +1,113 @@ +import { createElement } from 'react' +import { act, create, type ReactTestRenderer } from 'react-test-renderer' +import { afterEach, describe, expect, it, vi } from 'vitest' +import type { AgentJournalRenderItem } from '../../../src/shared/agent-session-journal-types' +import { useMobileStructuredAgentTurnTiming } from './use-mobile-structured-agent-turn-timing' + +// Host clock sits an hour ahead of the client's so any leak of a host timestamp +// into the local anchor shows up as a huge offset. +const HOST_START = 3_600_000_000 +const CLIENT_NOW = 12_345_000 + +function user(itemId: string, sequence: number): AgentJournalRenderItem { + return { + itemId, + revision: 0, + sequence, + observedAt: HOST_START + sequence, + body: { kind: 'message', role: 'user', blocks: [{ type: 'text', text: itemId }] } + } +} + +function lifecycle( + turnId: string, + sequence: number, + turnLifecycle: Omit< + NonNullable['turnLifecycle']>, + 'turnId' + >, + observedAt: number +): AgentJournalRenderItem { + return { + itemId: `lifecycle-${turnId}`, + revision: 1, + sequence, + observedAt, + body: { kind: 'status', text: 'Working', turnLifecycle: { turnId, ...turnLifecycle } } + } +} + +type Timing = ReturnType + +describe('useMobileStructuredAgentTurnTiming', () => { + let renderer: ReactTestRenderer | null = null + let timing: Timing | null = null + + function Harness({ + items, + turnId + }: { + items: readonly AgentJournalRenderItem[] + turnId: string | null + }): null { + timing = useMobileStructuredAgentTurnTiming(items, turnId) + return null + } + + afterEach(() => { + act(() => renderer?.unmount()) + renderer = null + timing = null + vi.useRealTimers() + }) + + it('hands settled host durations through keyed by user message', () => { + const items = [ + user('u1', 1), + lifecycle( + 't1', + 2, + { state: 'interrupted', startedAt: HOST_START, completedAt: HOST_START + 61_000 }, + HOST_START + 5 + ) + ] + act(() => { + renderer = create(createElement(Harness, { items, turnId: null })) + }) + expect(timing?.workingStartedAt).toBeNull() + expect([...timing!.settledTurns]).toEqual([ + ['u1', { startedAt: HOST_START, workedSeconds: 61 }] + ]) + }) + + it('anchors the live counter on the local clock, once per turn, free of host skew', () => { + vi.useFakeTimers() + vi.setSystemTime(CLIENT_NOW) + const running = [ + user('u1', 1), + lifecycle('t1', 2, { state: 'running', startedAt: HOST_START }, HOST_START + 2_500) + ] + act(() => { + renderer = create(createElement(Harness, { items: running, turnId: 't1' })) + }) + expect(timing?.workingStartedAt).toBe(CLIENT_NOW - 2_500) + + vi.setSystemTime(CLIENT_NOW + 30_000) + act(() => renderer?.update(createElement(Harness, { items: [...running], turnId: 't1' }))) + expect(timing?.workingStartedAt).toBe(CLIENT_NOW - 2_500) + + act(() => renderer?.update(createElement(Harness, { items: running, turnId: null }))) + expect(timing?.workingStartedAt).toBeNull() + }) + + it('leaves the anchor null when an older host records no start', () => { + vi.useFakeTimers() + vi.setSystemTime(CLIENT_NOW) + const items = [user('u1', 1), lifecycle('t1', 2, { state: 'running' }, HOST_START)] + act(() => { + renderer = create(createElement(Harness, { items, turnId: 't1' })) + }) + expect(timing?.workingStartedAt).toBeNull() + expect(timing?.settledTurns.size).toBe(0) + }) +}) diff --git a/mobile/src/session/use-mobile-structured-agent-turn-timing.ts b/mobile/src/session/use-mobile-structured-agent-turn-timing.ts new file mode 100644 index 00000000000..611b7db592d --- /dev/null +++ b/mobile/src/session/use-mobile-structured-agent-turn-timing.ts @@ -0,0 +1,45 @@ +import { useMemo, useState } from 'react' +import type { AgentJournalRenderItem } from '../../../src/shared/agent-session-journal-types' +import type { NativeChatSettledTurn } from '../../../src/shared/native-chat-turn-status' +import { + selectStructuredAgentRunningTurnTiming, + selectStructuredAgentSettledTurns, + structuredAgentTurnLocalStartedAt +} from '../../../src/shared/structured-agent-session-turn-timing' + +type TurnAnchor = { turnId: string; startedAt: number | null } + +/** The live turn's local-clock anchor. Null when its row carries no host start + * (older hosts), so local observation applies. */ +function anchorRunningTurn(items: readonly AgentJournalRenderItem[], turnId: string): TurnAnchor { + const timing = selectStructuredAgentRunningTurnTiming(items, turnId) + return { + turnId, + startedAt: timing ? structuredAgentTurnLocalStartedAt(timing, Date.now()) : null + } +} + +/** Host-recorded turn timing for the structured lane: settled durations straight + * off the journal, and a skew-free start for the live counter stamped once per + * turn so re-renders never move it. */ +export function useMobileStructuredAgentTurnTiming( + items: readonly AgentJournalRenderItem[], + turnId: string | null +): { settledTurns: ReadonlyMap; workingStartedAt: number | null } { + const settledTurns = useMemo(() => selectStructuredAgentSettledTurns(items), [items]) + const [anchor, setAnchor] = useState(null) + // Stamp during render (React's derive-from-props pattern) so the first paint of + // a new turn already counts from the right instant. + if (turnId === null) { + if (anchor !== null) { + setAnchor(null) + } + return { settledTurns, workingStartedAt: null } + } + if (anchor?.turnId !== turnId) { + const next = anchorRunningTurn(items, turnId) + setAnchor(next) + return { settledTurns, workingStartedAt: next.startedAt } + } + return { settledTurns, workingStartedAt: anchor.startedAt } +} diff --git a/src/main/claude/claude-structured-journal-translation-turn-timing.test.ts b/src/main/claude/claude-structured-journal-translation-turn-timing.test.ts new file mode 100644 index 00000000000..20262ebbdcd --- /dev/null +++ b/src/main/claude/claude-structured-journal-translation-turn-timing.test.ts @@ -0,0 +1,226 @@ +import { afterEach, describe, expect, it, vi } from 'vitest' +import type { + AgentJournalItemBody, + AgentJournalItemIdentity +} from '../../shared/agent-session-journal-types' +import type { + StructuredAgentSessionAppendOptions, + StructuredAgentSessionEventSink +} from '../native-chat/agent-session-wire/structured-agent-session-event-sink' +import { createClaudeJournalTranslator } from './claude-structured-journal-translation' +import type { ClaudeStructuredSessionEvent } from './claude-structured-session-state' +import { acquired, fakeClaude } from './claude-structured-session-test-support' + +type Append = { + identity: AgentJournalItemIdentity + body: AgentJournalItemBody + options: StructuredAgentSessionAppendOptions | undefined +} + +function sinkState() { + const items: Append[] = [] + const tombstones: AgentJournalItemIdentity[] = [] + const sink: StructuredAgentSessionEventSink = { + appendItem: (identity, body, options) => items.push({ identity, body, options }), + appendTombstone: (identity) => tombstones.push(identity), + publish: vi.fn() + } + const lifecycle = () => + items.flatMap((item) => + item.body.kind === 'status' && item.body.turnLifecycle + ? [{ ...item.body.turnLifecycle, options: item.options }] + : [] + ) + return { sink, items, tombstones, lifecycle } +} + +function userTurn(uuid: string, observedAt?: number): ClaudeStructuredSessionEvent { + return { + type: 'message', + sessionId: 'orca-session', + startsTurn: true, + ...(observedAt === undefined ? {} : { observedAt }), + message: { + type: 'user', + uuid, + session_id: 'claude-session', + parent_tool_use_id: null, + message: { role: 'user', content: [{ type: 'text', text: 'go' }] } + } + } +} + +function result(observedAt?: number): ClaudeStructuredSessionEvent { + return { + type: 'message', + sessionId: 'orca-session', + ...(observedAt === undefined ? {} : { observedAt }), + message: { + type: 'result', + subtype: 'success', + uuid: 'result-1', + session_id: 'claude-session', + is_error: false, + result: 'done' + } + } +} + +describe('Claude structured turn timing', () => { + afterEach(() => { + vi.useRealTimers() + }) + + it('stamps the running row with the host start time as both startedAt and row ts', () => { + const state = sinkState() + const translator = createClaudeJournalTranslator({ sink: state.sink }) + + translator.handle(userTurn('user-1', 1_000)) + + expect(state.lifecycle()).toEqual([ + { turnId: 'user-1', state: 'running', startedAt: 1_000, options: { observedAt: 1_000 } } + ]) + }) + + it('revises the running row to completed with the result receipt time', () => { + const state = sinkState() + const translator = createClaudeJournalTranslator({ sink: state.sink }) + + translator.handle(userTurn('user-1', 1_000)) + translator.handle(result(4_500)) + + expect(state.tombstones).toEqual([]) + expect(state.lifecycle().at(-1)).toEqual({ + turnId: 'user-1', + state: 'completed', + startedAt: 1_000, + completedAt: 4_500, + options: {} + }) + expect(state.items.at(-1)?.identity).toEqual(state.items[0]?.identity) + }) + + it('revises the running row to interrupted when the result reports a user abort', () => { + const state = sinkState() + const translator = createClaudeJournalTranslator({ sink: state.sink }) + + translator.handle(userTurn('user-1', 1_000)) + const aborted = result(4_500) + if (aborted.type === 'message') { + aborted.message = { + ...aborted.message, + subtype: 'error_during_execution', + is_error: true, + terminal_reason: 'aborted_streaming' + } + } + translator.handle(aborted) + + expect(state.tombstones).toEqual([]) + expect(state.lifecycle().at(-1)).toMatchObject({ + turnId: 'user-1', + state: 'interrupted', + startedAt: 1_000, + completedAt: 4_500 + }) + }) + + it('revises an open turn to interrupted when the session ends without a result', () => { + const state = sinkState() + const translator = createClaudeJournalTranslator({ sink: state.sink }) + + translator.handle(userTurn('user-1', 1_000)) + translator.handle({ + type: 'ended', + sessionId: 'orca-session', + reason: 'child exited', + observedAt: 2_250 + }) + + expect(state.tombstones).toEqual([]) + expect(state.lifecycle().at(-1)).toMatchObject({ + turnId: 'user-1', + state: 'interrupted', + startedAt: 1_000, + completedAt: 2_250 + }) + }) + + it('interrupts the open turn at the receipt time of the turn that replaces it', () => { + const state = sinkState() + const translator = createClaudeJournalTranslator({ sink: state.sink }) + + translator.handle(userTurn('user-1', 1_000)) + translator.handle(userTurn('user-2', 3_000)) + + expect(state.lifecycle().map(({ options: _options, ...row }) => row)).toEqual([ + { turnId: 'user-1', state: 'running', startedAt: 1_000 }, + { turnId: 'user-1', state: 'interrupted', startedAt: 1_000, completedAt: 3_000 }, + { turnId: 'user-2', state: 'running', startedAt: 3_000 } + ]) + }) + + it('falls back to the host clock when an event carries no receipt time', () => { + vi.useFakeTimers({ now: 50_000 }) + const state = sinkState() + const translator = createClaudeJournalTranslator({ sink: state.sink }) + + translator.handle(userTurn('user-1')) + vi.setSystemTime(56_000) + translator.handle(result()) + + expect(state.lifecycle().at(-1)).toMatchObject({ + state: 'completed', + startedAt: 50_000, + completedAt: 56_000 + }) + }) + + it('acquisition stamps turn boundaries from the host clock, never the frame timestamp', async () => { + const claude = fakeClaude({ replayUuid: null }) + const events: ClaudeStructuredSessionEvent[] = [] + const adapter = await acquired(claude, {}, events) + const dispatch = adapter.dispatch({ + sessionId: 'session-1', + clientMessageId: 'client-1', + body: { kind: 'message', role: 'user', blocks: [{ type: 'text', text: 'ship it' }] }, + fence: 7 + }) + await Promise.resolve() + const connection = claude.connections[0]! + connection.handlers.onMessage?.({ + ...connection.sent[0], + uuid: 'turn-1', + timestamp: '2001-01-01T00:00:00.000Z' + }) + await dispatch + connection.handlers.onMessage?.({ + type: 'assistant', + uuid: 'assistant-1', + session_id: connection.sent[0]?.session_id, + timestamp: '2001-01-01T00:00:01.000Z', + message: { role: 'assistant', content: [{ type: 'text', text: 'ok' }] } + }) + connection.handlers.onMessage?.({ + type: 'result', + subtype: 'success', + uuid: 'result-1', + session_id: connection.sent[0]?.session_id, + timestamp: '2001-01-01T00:00:02.000Z', + is_error: false, + result: 'ok' + }) + + const messages = events.filter( + (event) => event.type === 'message' && event.message.type !== 'system' + ) + expect(messages).toEqual([ + expect.objectContaining({ startsTurn: true, observedAt: 1_700_000_000_500 }), + expect.not.objectContaining({ observedAt: expect.anything() }), + expect.objectContaining({ + message: expect.objectContaining({ type: 'result' }), + observedAt: 1_700_000_000_500 + }) + ]) + }) +}) diff --git a/src/main/claude/claude-structured-journal-translation.test.ts b/src/main/claude/claude-structured-journal-translation.test.ts index 951872f0c69..7a8c6e1acc6 100644 --- a/src/main/claude/claude-structured-journal-translation.test.ts +++ b/src/main/claude/claude-structured-journal-translation.test.ts @@ -33,6 +33,17 @@ function sinkState() { return { sink, items, tombstones } } +/** `[recordId, state]` of every lifecycle append, in journal order. */ +function lifecycleAppends( + items: { identity: AgentJournalItemIdentity; body: AgentJournalItemBody }[] +) { + return items.flatMap((item) => + item.identity.provider === 'legacy' && item.body.kind === 'status' && item.body.turnLifecycle + ? [[item.identity.recordId, item.body.turnLifecycle.state]] + : [] + ) +} + function message( type: 'assistant' | 'user', uuid: string, @@ -346,11 +357,13 @@ describe('Claude structured journal translation', () => { expect( state.items.some((item) => item.body.kind === 'status' && !item.body.turnLifecycle) ).toBe(false) - expect( - state.tombstones.flatMap((identity) => - identity.provider === 'legacy' ? [identity.recordId] : [] - ) - ).toEqual(['turn-lifecycle:user-replay-1', 'turn-lifecycle:user-interrupt']) + expect(state.tombstones).toEqual([]) + expect(lifecycleAppends(state.items)).toEqual([ + ['turn-lifecycle:user-replay-1', 'running'], + ['turn-lifecycle:user-replay-1', 'completed'], + ['turn-lifecycle:user-interrupt', 'running'], + ['turn-lifecycle:user-interrupt', 'interrupted'] + ]) }) it('does not reopen a completed turn when the SDK replays its user row after restart', () => { @@ -371,11 +384,9 @@ describe('Claude structured journal translation', () => { liveTranslator.handle({ ...replay, startsTurn: true }) liveTranslator.handle(resultFrame('success', { is_error: false, result: '' })) - expect(live.tombstones).toContainEqual({ - provider: 'legacy', - agent: 'claude', - sessionId: 'claude-session', - recordId: 'turn-lifecycle:picker-command-1' + expect(live.items.at(-1)).toMatchObject({ + identity: { provider: 'legacy', recordId: 'turn-lifecycle:picker-command-1' }, + body: { turnLifecycle: { turnId: 'picker-command-1', state: 'completed' } } }) liveTranslator.dispose() @@ -419,11 +430,7 @@ describe('Claude structured journal translation', () => { text: 'API Error: 529 upstream overloaded' }) // The turn still settles: the error is an extra row, not a stuck lifecycle. - expect( - state.tombstones.flatMap((identity) => - identity.provider === 'legacy' ? [identity.recordId] : [] - ) - ).toEqual(['turn-lifecycle:user-1']) + expect(lifecycleAppends(state.items).at(-1)).toEqual(['turn-lifecycle:user-1', 'completed']) }) it('drops the stream state of turns that ended without their final frame', () => { @@ -551,11 +558,8 @@ describe('Claude structured journal translation', () => { sessionId: 'orca-session', message: { type: 'result', session_id: 'claude-session', uuid: 'result-1' } }) - expect(state.tombstones.at(-1)).toMatchObject({ - provider: 'legacy', - agent: 'claude', - recordId: 'turn-lifecycle:user-1' - }) + expect(state.tombstones).toEqual([]) + expect(lifecycleAppends(state.items).at(-1)).toEqual(['turn-lifecycle:user-1', 'completed']) }) it('bounds persisted thinking text to the shared journal payload limit', () => { @@ -584,7 +588,7 @@ describe('Claude structured journal translation', () => { expect(state.items.at(-1)?.body).toEqual({ kind: 'status', text: 'Claude is working…', - turnLifecycle: { turnId: 'user-image', state: 'running' } + turnLifecycle: { turnId: 'user-image', state: 'running', startedAt: expect.any(Number) } }) }) diff --git a/src/main/claude/claude-structured-journal-translation.ts b/src/main/claude/claude-structured-journal-translation.ts index 759c2926763..95ac176123b 100644 --- a/src/main/claude/claude-structured-journal-translation.ts +++ b/src/main/claude/claude-structured-journal-translation.ts @@ -39,6 +39,12 @@ import { import { ClaudeSubagentRoster } from './claude-subagent-roster' import { createClaudeStreamedBlockRegistry } from './claude-streamed-block-identity' import { createClaudeStreamedTextCheckpoints } from './claude-streamed-text-checkpoints' +import { + claudeTurnEndForResult, + claudeTurnLifecycleItem, + type ClaudeCurrentTurn, + type ClaudeTurnEnd +} from './claude-turn-lifecycle-item' export type ClaudeJournalTranslatorDeps = { sink: StructuredAgentSessionEventSink @@ -71,23 +77,14 @@ export function createClaudeSessionJournalTranslator( : null } -function lifecycleIdentity(sessionId: string, turnId: string): AgentJournalItemIdentity { - return { - provider: 'legacy', - agent: 'claude', - sessionId, - recordId: `turn-lifecycle:${turnId}` - } -} - export function createClaudeJournalTranslator( deps: ClaudeJournalTranslatorDeps ): ClaudeJournalTranslator { const tools = new Map() const promptItems = new Map() const streamedBlocks = createClaudeStreamedBlockRegistry() - let currentTurn: { sessionId: string; turnId: string } | null = null - const groupKeyOf = (turn: { sessionId: string; turnId: string } | null): string | null => + let currentTurn: ClaudeCurrentTurn | null = null + const groupKeyOf = (turn: ClaudeCurrentTurn | null): string | null => turn ? `${turn.sessionId}:${turn.turnId}` : null const providerFallback = createClaudeProviderFrameFallback( deps.sink, @@ -106,21 +103,11 @@ export function createClaudeJournalTranslator( } }) - const publishLifecycle = (sessionId: string, turnId: string, running: boolean): void => { - const identity = lifecycleIdentity(sessionId, turnId) - if (running) { - deps.sink.appendItem(identity, { - kind: 'status', - text: 'Claude is working…', - turnLifecycle: { turnId, state: 'running' } - }) - } else { - deps.sink.appendTombstone(identity) - } + const publishLifecycle = (turn: ClaudeCurrentTurn, end?: ClaudeTurnEnd): void => { + const item = claudeTurnLifecycleItem(turn, end) + deps.sink.appendItem(item.identity, item.body, item.options) // Preserve first-work evidence when completion arrives before the journal drains. - deps.sink.publish({ - coalescingKey: running ? `turn-start:${sessionId}:${turnId}` : 'publish' - }) + deps.sink.publish({ coalescingKey: item.publishCoalescingKey }) } const publishActivity = (kind: string, payload: unknown): void => { @@ -142,7 +129,11 @@ export function createClaudeJournalTranslator( return true } - const handleMessage = (message: Record, startsTurn: boolean): boolean => { + const handleMessage = ( + message: Record, + startsTurn: boolean, + observedAt: number + ): boolean => { const envelope = readClaudeMessageEnvelope(message) if (!envelope) { return false @@ -205,10 +196,10 @@ export function createClaudeJournalTranslator( // A new turn starting is the only end the previous one gets when its // result never arrives; settling it later would sweep THIS turn. subagents.settleTurn(groupKeyOf(currentTurn)) - publishLifecycle(currentTurn.sessionId, currentTurn.turnId, false) + publishLifecycle(currentTurn, { state: 'interrupted', completedAt: observedAt }) } - currentTurn = { sessionId: envelope.sessionId, turnId: envelope.uuid } - publishLifecycle(envelope.sessionId, envelope.uuid, true) + currentTurn = { sessionId: envelope.sessionId, turnId: envelope.uuid, startedAt: observedAt } + publishLifecycle(currentTurn) deps.sink.setActivity?.(null) } if (changed) { @@ -248,7 +239,11 @@ export function createClaudeJournalTranslator( // No event will ever settle a child once the provider is gone. subagents.settleSession() if (currentTurn) { - publishLifecycle(currentTurn.sessionId, currentTurn.turnId, false) + // The host saw the child end, so the turn's end is observed, not lost. + publishLifecycle(currentTurn, { + state: 'interrupted', + completedAt: event.observedAt ?? Date.now() + }) currentTurn = null } deps.sink.setActivity?.(null) @@ -271,7 +266,10 @@ export function createClaudeJournalTranslator( // reported as working will never be settled by an event. subagents.settleTurn(groupKeyOf(currentTurn)) if (currentTurn) { - publishLifecycle(currentTurn.sessionId, currentTurn.turnId, false) + publishLifecycle( + currentTurn, + claudeTurnEndForResult(event.message, event.observedAt ?? Date.now()) + ) currentTurn = null } deps.sink.setActivity?.(null) @@ -291,7 +289,9 @@ export function createClaudeJournalTranslator( // fallback below still drops the raw frame instead of printing an opcode. subagents.observeSystemFrame(event.message) const kind = claudeProviderFrameKind(event.message) - if (!handleMessage(event.message, event.startsTurn === true)) { + if ( + !handleMessage(event.message, event.startsTurn === true, event.observedAt ?? Date.now()) + ) { providerFallback.append(kind, event.message) } publishActivity(kind, event.message) diff --git a/src/main/claude/claude-structured-session-acquisition.ts b/src/main/claude/claude-structured-session-acquisition.ts index 20ddde819b9..57bad1f1873 100644 --- a/src/main/claude/claude-structured-session-acquisition.ts +++ b/src/main/claude/claude-structured-session-acquisition.ts @@ -121,12 +121,16 @@ export async function acquireClaudeSession({ deps.onDispatchSettledLate?.({ sessionId, ...settlement }) ) : false + // Turn endpoints are stamped on the host clock, never the frame's own timestamp. + const observedAt = + startsTurn || message.type === 'result' ? { observedAt: deps.now?.() ?? Date.now() } : {} callbacks.deliver(attempt, sessionId, () => callbacks.emit(liveSession, input.events, { type: 'message', sessionId, message, - ...(startsTurn ? { startsTurn: true } : {}) + ...(startsTurn ? { startsTurn: true } : {}), + ...observedAt }) ) } diff --git a/src/main/claude/claude-structured-session-adapter.ts b/src/main/claude/claude-structured-session-adapter.ts index bcae132f695..e2256b6210c 100644 --- a/src/main/claude/claude-structured-session-adapter.ts +++ b/src/main/claude/claude-structured-session-adapter.ts @@ -154,7 +154,8 @@ export class ClaudeStructuredSessionAdapter implements StructuredAgentSessionAda reason: exit.error.message, cause: 'unexpected-exit', fence: exit.session.fence, - acquisitionGeneration: exit.session.acquisitionGeneration + acquisitionGeneration: exit.session.acquisitionGeneration, + observedAt: this.deps.now?.() ?? Date.now() } try { this.emit(exit.session, ended) diff --git a/src/main/claude/claude-structured-session-close.ts b/src/main/claude/claude-structured-session-close.ts index de07439919d..eac681ff291 100644 --- a/src/main/claude/claude-structured-session-close.ts +++ b/src/main/claude/claude-structured-session-close.ts @@ -109,7 +109,8 @@ async function finalizeClaudePublishedSession( const ended = { type: 'ended', sessionId: input.sessionId, - reason: 'claude session closed' + reason: 'claude session closed', + observedAt: Date.now() } as const let callbackError: unknown let callbackThrew = false diff --git a/src/main/claude/claude-structured-session-recovery.test.ts b/src/main/claude/claude-structured-session-recovery.test.ts index 5bfe56cf156..bd8f8cb40b2 100644 --- a/src/main/claude/claude-structured-session-recovery.test.ts +++ b/src/main/claude/claude-structured-session-recovery.test.ts @@ -598,7 +598,8 @@ describe('ClaudeStructuredSessionAdapter transcript-derived recovery', () => { reason: 'crashed before replacement', cause: 'unexpected-exit', fence: 7, - acquisitionGeneration: firstAcquisition.acquisitionGeneration + acquisitionGeneration: firstAcquisition.acquisitionGeneration, + observedAt: 1_700_000_000_500 } ]) expect(replacement.link).toMatchObject({ diff --git a/src/main/claude/claude-structured-session-state.ts b/src/main/claude/claude-structured-session-state.ts index ea539065920..ab259f62097 100644 --- a/src/main/claude/claude-structured-session-state.ts +++ b/src/main/claude/claude-structured-session-state.ts @@ -31,6 +31,8 @@ export type ClaudeStructuredSessionEvent = message: Record /** Present only when this replay acknowledged Orca's in-flight dispatch. */ startsTurn?: true + /** Host clock at receipt; stamped on turn boundaries only. */ + observedAt?: number } | { type: 'provider-frame'; sessionId: string; kind: string; payload: unknown } | { type: 'prompt'; sessionId: string; prompt: ClaudePendingPrompt } @@ -53,6 +55,8 @@ export type ClaudeStructuredSessionEvent = fence?: number acquisitionGeneration?: string settlementRetryRequired?: boolean + /** Host clock when the end was observed. */ + observedAt?: number } export type ClaudeStructuredSessionAdapterDeps = { diff --git a/src/main/claude/claude-turn-lifecycle-item.ts b/src/main/claude/claude-turn-lifecycle-item.ts new file mode 100644 index 00000000000..8b0e0678edf --- /dev/null +++ b/src/main/claude/claude-turn-lifecycle-item.ts @@ -0,0 +1,62 @@ +import type { + AgentJournalItemIdentity, + AgentJournalStatusItem +} from '../../shared/agent-session-journal-types' +import type { StructuredAgentSessionAppendOptions } from '../native-chat/agent-session-wire/structured-agent-session-event-sink' +import { claudeText } from './claude-structured-item-translation' + +export type ClaudeCurrentTurn = { sessionId: string; turnId: string; startedAt: number } + +export type ClaudeTurnEnd = { state: 'completed' | 'interrupted'; completedAt: number } + +/** A result the SDK reports as aborted is the user's stop, not the model's end. */ +export function claudeTurnEndForResult( + message: Record, + completedAt: number +): ClaudeTurnEnd { + const reason = message.is_error === true ? claudeText(message.terminal_reason) : null + return { + state: + reason === 'aborted_streaming' || reason === 'aborted_tools' ? 'interrupted' : 'completed', + completedAt + } +} + +export function claudeTurnLifecycleIdentity( + sessionId: string, + turnId: string +): AgentJournalItemIdentity { + return { + provider: 'legacy', + agent: 'claude', + sessionId, + recordId: `turn-lifecycle:${turnId}` + } +} + +/** The lifecycle row is revised to its terminal state, never tombstoned, so the + * turn's host-clock endpoints outlive the turn. */ +export function claudeTurnLifecycleItem( + turn: ClaudeCurrentTurn, + end?: ClaudeTurnEnd +): { + identity: AgentJournalItemIdentity + body: AgentJournalStatusItem + options: StructuredAgentSessionAppendOptions + publishCoalescingKey: string +} { + const { sessionId, turnId, startedAt } = turn + return { + identity: claudeTurnLifecycleIdentity(sessionId, turnId), + body: { + kind: 'status', + text: 'Claude is working…', + turnLifecycle: end + ? { turnId, state: end.state, startedAt, completedAt: end.completedAt } + : { turnId, state: 'running', startedAt } + }, + // The running row's ts is the turn start itself, so clients read no append lag. + options: end ? {} : { observedAt: startedAt }, + publishCoalescingKey: end ? 'publish' : `turn-start:${sessionId}:${turnId}` + } +} diff --git a/src/main/codex/codex-structured-journal-contracts.ts b/src/main/codex/codex-structured-journal-contracts.ts index acd04a4cf30..ba52f667289 100644 --- a/src/main/codex/codex-structured-journal-contracts.ts +++ b/src/main/codex/codex-structured-journal-contracts.ts @@ -4,6 +4,9 @@ import type { CodexStructuredSessionEvent } from './codex-structured-session-ada export type CodexJournalTranslatorDeps = { sink: StructuredAgentSessionEventSink + /** Keys restored lifecycle rows to the live identity; without it history restore skips them. */ + sessionId?: string + now?: () => number bindPromptItemId?: (journalItemId: string, threadId: string, promptKey: string) => void primaryThreadId?: () => string | null coalesceMs?: number diff --git a/src/main/codex/codex-structured-journal-settlement.ts b/src/main/codex/codex-structured-journal-settlement.ts index 2b8eb627d4f..cfed3a64bed 100644 --- a/src/main/codex/codex-structured-journal-settlement.ts +++ b/src/main/codex/codex-structured-journal-settlement.ts @@ -1,6 +1,7 @@ import type { AgentJournalItemBody, - AgentJournalItemIdentity + AgentJournalItemIdentity, + AgentJournalTurnLifecycle } from '../../shared/agent-session-journal-types' import { partitionJournalLifecycleMutations } from '../native-chat/agent-session-journal/journal-lifecycle-batch-partition' import type { JournalLifecycleMutationInput } from '../native-chat/agent-session-journal/journal-row-builders' @@ -20,6 +21,10 @@ import { } from './codex-structured-item-translation' import type { CodexStructuredItemStreams } from './codex-structured-item-streams' import type { CodexStructuredSessionEvent } from './codex-structured-session-adapter' +import { + codexTurnLifecycleBody, + codexTurnLifecycleIdentity +} from './codex-structured-journal-translation-turns' export type CodexActiveJournalItem = { threadId: string @@ -44,6 +49,8 @@ export function settleCodexJournalSession(input: { currentTurnIds: ReadonlyMap> primaryThreadId: string | null ordinals: CodexTurnOrdinals + /** Terminal lifecycle for a turn the provider left running when it ended. */ + settledTurnLifecycle: (threadId: string, turnId: string) => AgentJournalTurnLifecycle }): StructuredAgentSessionSinkAdmission { const mutations: JournalLifecycleMutationInput[] = [] const turnOrdinalsToForget: { threadId: string; turnId: string }[] = [] @@ -83,13 +90,9 @@ export function settleCodexJournalSession(input: { } for (const turnId of turnIds) { mutations.push({ - kind: 'tombstone', - identity: { - provider: 'legacy', - agent: 'codex', - sessionId: input.event.sessionId, - recordId: `turn-lifecycle:${turnId}` - } + kind: 'item', + identity: codexTurnLifecycleIdentity(input.event.sessionId, turnId), + body: codexTurnLifecycleBody(input.settledTurnLifecycle(threadId, turnId)) }) turnOrdinalsToForget.push({ threadId, turnId }) } @@ -108,6 +111,8 @@ export function settleCodexJournalTurn(input: { sessionId: string threadId: string turnId: string + /** Null off the primary thread: only the primary turn owns a lifecycle row. */ + turnLifecycle: AgentJournalTurnLifecycle | null sink: StructuredAgentSessionEventSink streams: CodexStructuredItemStreams activeItems: Map @@ -128,15 +133,17 @@ export function settleCodexJournalTurn(input: { } activeItemsToForget.push({ key, threadId: active.threadId, itemId: active.item.id }) } - mutations.push({ - kind: 'tombstone', - identity: { - provider: 'legacy', - agent: 'codex', - sessionId: input.sessionId, - recordId: `turn-lifecycle:${input.turnId}` - } - }) + // Revised, never tombstoned: the terminal row keeps the turn's duration durable. + if (input.turnLifecycle) { + mutations.push({ + kind: 'item', + identity: codexTurnLifecycleIdentity(input.sessionId, input.turnId), + body: codexTurnLifecycleBody(input.turnLifecycle) + }) + } + if (mutations.length === 0) { + return ADMITTED + } const admission = appendLifecycleMutations( input.sink, `turn-completed:${input.sessionId}:${input.threadId}:${input.turnId}`, diff --git a/src/main/codex/codex-structured-journal-translation-restore.ts b/src/main/codex/codex-structured-journal-translation-restore.ts index 155cba0c6a7..15d01345d8a 100644 --- a/src/main/codex/codex-structured-journal-translation-restore.ts +++ b/src/main/codex/codex-structured-journal-translation-restore.ts @@ -1,9 +1,12 @@ +import type { AgentJournalTurnLifecycle } from '../../shared/agent-session-journal-types' import type { CodexTurnOrdinals } from './codex-structured-item-translation' import { readCodexJournalRecord, readCodexJournalString } from './codex-structured-journal-translation-values' import type { CodexJournalTranslationAdmission } from './codex-structured-journal-translation' +import { codexTurnLifecycleState } from './codex-structured-journal-translation-turns' +import { readCodexTurnStatus } from './codex-structured-thread-facts' /** Old providers may return the complete thread from resume. Keep that fallback * bounded before admitting any rows to the asynchronous sink. */ @@ -20,6 +23,10 @@ export function restoreCodexJournalThread(input: { method: string params: unknown }) => CodexJournalTranslationAdmission + /** Absent when the caller has no session identity to key lifecycle rows by. */ + restoreTurnLifecycle?: ( + turnLifecycle: AgentJournalTurnLifecycle + ) => CodexJournalTranslationAdmission flush: () => void }): CodexJournalTranslationAdmission { const turns = Array.isArray(input.thread.turns) ? input.thread.turns : [] @@ -30,8 +37,14 @@ export function restoreCodexJournalThread(input: { ? (Array.isArray(turn.items) ? turn.items : []).map((item) => ({ turnId, item })) : [] }) + const lifecycles = input.restoreTurnLifecycle + ? turns.flatMap((rawTurn) => historicalTurnLifecycle(readCodexJournalRecord(rawTurn)) ?? []) + : [] const encodedBytes = Buffer.byteLength(JSON.stringify(items), 'utf8') - if (items.length > CODEX_RESTORE_MAX_OPERATIONS || encodedBytes > CODEX_RESTORE_MAX_BYTES) { + if ( + items.length + lifecycles.length > CODEX_RESTORE_MAX_OPERATIONS || + encodedBytes > CODEX_RESTORE_MAX_BYTES + ) { return { accepted: false, reason: 'backpressure' } } for (const rawTurn of turns) { @@ -53,7 +66,36 @@ export function restoreCodexJournalThread(input: { } input.currentTurnIds.delete(input.threadId) input.ordinals.forgetTurn(input.threadId, turnId) + const lifecycle = input.restoreTurnLifecycle ? historicalTurnLifecycle(turn) : null + if (lifecycle) { + const admission = input.restoreTurnLifecycle?.(lifecycle) ?? { accepted: true } + if (!admission.accepted) { + return admission + } + } } input.flush() return { accepted: true } } + +/** Codex reports both endpoints in unix seconds; a turn missing either has no durable duration. */ +function historicalTurnLifecycle(turn: Record): AgentJournalTurnLifecycle | null { + const turnId = readCodexJournalString(turn, 'id') + const startedAt = turn.startedAt + const completedAt = turn.completedAt + if ( + !turnId || + typeof startedAt !== 'number' || + typeof completedAt !== 'number' || + !Number.isFinite(startedAt) || + !Number.isFinite(completedAt) + ) { + return null + } + return { + turnId, + state: codexTurnLifecycleState(readCodexTurnStatus(turn)), + startedAt: startedAt * 1000, + completedAt: completedAt * 1000 + } +} diff --git a/src/main/codex/codex-structured-journal-translation-settlement.test.ts b/src/main/codex/codex-structured-journal-translation-settlement.test.ts index 1f2bc480a22..0d83ea6c439 100644 --- a/src/main/codex/codex-structured-journal-translation-settlement.test.ts +++ b/src/main/codex/codex-structured-journal-translation-settlement.test.ts @@ -220,10 +220,14 @@ describe('codex journal translation', () => { expect(bodies).toEqual([ expect.objectContaining({ kind: 'status', - turnLifecycle: { turnId: TURN_ID, state: 'running' } + turnLifecycle: expect.objectContaining({ turnId: TURN_ID, state: 'running' }) }), expect.objectContaining({ kind: 'tool-call', state: 'running' }), - expect.objectContaining({ kind: 'tool-call', state: 'failed' }) + expect.objectContaining({ kind: 'tool-call', state: 'failed' }), + expect.objectContaining({ + kind: 'status', + turnLifecycle: expect.objectContaining({ turnId: TURN_ID, state: 'completed' }) + }) ]) expect(publishes).toHaveLength(2) }) @@ -265,7 +269,7 @@ describe('codex journal translation', () => { expect(bodies).toEqual([ expect.objectContaining({ kind: 'status', - turnLifecycle: { turnId: TURN_ID, state: 'running' } + turnLifecycle: expect.objectContaining({ turnId: TURN_ID, state: 'running' }) }), expect.objectContaining({ kind: 'approval', @@ -275,7 +279,11 @@ describe('codex journal translation', () => { kind: 'approval', resolution: expect.objectContaining({ state: 'cancelled' }) }), - { kind: 'status', text: 'Provider exited: lost child' } + { kind: 'status', text: 'Provider exited: lost child' }, + expect.objectContaining({ + kind: 'status', + turnLifecycle: expect.objectContaining({ turnId: TURN_ID, state: 'interrupted' }) + }) ]) expect(publishes).toHaveLength(2) }) @@ -349,7 +357,12 @@ describe('codex journal translation', () => { expect.objectContaining({ body: { kind: 'status', text: 'Provider exited: lost child' } }), - expect.objectContaining({ kind: 'tombstone' }) + expect.objectContaining({ + kind: 'item', + body: expect.objectContaining({ + turnLifecycle: expect.objectContaining({ turnId: TURN_ID, state: 'interrupted' }) + }) + }) ]) ) }) @@ -422,7 +435,10 @@ describe('codex journal translation', () => { kind: 'item', body: { kind: 'status', text: 'Provider exited: lost child' } }) - expect(flattened.at(-1)).toMatchObject({ kind: 'tombstone' }) + expect(flattened.at(-1)).toMatchObject({ + kind: 'item', + body: { kind: 'status', turnLifecycle: { state: 'interrupted' } } + }) expectLifecycleBatchBounds(batches) }) @@ -542,15 +558,25 @@ describe('codex journal translation', () => { output: expect.objectContaining({ head: 'partial' }) }) }), - expect.objectContaining({ - kind: 'tombstone', + { + kind: 'item', identity: { provider: 'legacy', agent: 'codex', sessionId: SESSION_ID, recordId: `turn-lifecycle:${TURN_ID}` + }, + body: { + kind: 'status', + text: 'Codex is working…', + turnLifecycle: { + turnId: TURN_ID, + state: 'completed', + startedAt: expect.any(Number), + completedAt: expect.any(Number) + } } - }) + } ] } ]) diff --git a/src/main/codex/codex-structured-journal-translation-streams.test.ts b/src/main/codex/codex-structured-journal-translation-streams.test.ts index ea01f88e4c9..8a924a9d78a 100644 --- a/src/main/codex/codex-structured-journal-translation-streams.test.ts +++ b/src/main/codex/codex-structured-journal-translation-streams.test.ts @@ -486,7 +486,8 @@ describe('codex journal translation', () => { expect(translator.handle(notification('turn/completed', { turn: { id: TURN_ID } }))).toEqual({ accepted: true }) - expect(tap.tombstones).toContain('legacy:codex:session-1:turn-lifecycle%3Aturn-1') + // Lifecycle rows are revised in place, never tombstoned. + expect(tap.tombstones).toEqual([]) // The two maps share one bounded bucket budget; this assertion documents // the contract for future changes even though the maps are private. expect(MAX_CODEX_GENERIC_BOOKKEEPING_ENTRIES).toBeGreaterThanOrEqual( diff --git a/src/main/codex/codex-structured-journal-translation-turn-boundaries.ts b/src/main/codex/codex-structured-journal-translation-turn-boundaries.ts new file mode 100644 index 00000000000..7bb9276f81c --- /dev/null +++ b/src/main/codex/codex-structured-journal-translation-turn-boundaries.ts @@ -0,0 +1,119 @@ +import type { AgentJournalTurnLifecycle } from '../../shared/agent-session-journal-types' +import type { StructuredAgentSessionEventSink } from '../native-chat/agent-session-wire/structured-agent-session-event-sink' +import { + CODEX_JOURNAL_ADMITTED, + type CodexJournalTranslationAdmission +} from './codex-structured-journal-contracts' +import type { CodexJournalItems } from './codex-structured-journal-items' +import { settleCodexJournalTurn } from './codex-structured-journal-settlement' +import type { CodexJournalActiveTurns } from './codex-structured-journal-translation-turn-state' +import { + codexTurnLifecycleState, + publishCodexTurnLifecycle +} from './codex-structured-journal-translation-turns' +import { readCodexTurnId, readCodexTurnStatus } from './codex-structured-thread-facts' + +type TurnBoundaryEvent = { + sessionId: string + threadId: string + params: unknown + observedAt?: number +} + +/** Opens and settles the durable lifecycle row for each primary-thread turn. */ +export class CodexJournalTurnBoundaries { + constructor( + private readonly deps: { + sink: StructuredAgentSessionEventSink + primaryThreadId: () => string | null + activeTurns: CodexJournalActiveTurns + items: Pick + flushSuppression: () => CodexJournalTranslationAdmission + resetActivity: (threadId: string) => void + now?: () => number + } + ) {} + + start(event: TurnBoundaryEvent): CodexJournalTranslationAdmission { + const turnId = readCodexTurnId(event.params) + if (!turnId) { + return CODEX_JOURNAL_ADMITTED + } + if (!this.deps.activeTurns.canRemember(event.threadId, turnId)) { + return { accepted: false, reason: 'backpressure' } + } + const startedAt = this.receiptTime(event) + const admission = publishCodexTurnLifecycle({ + sink: this.deps.sink, + primaryThreadId: this.deps.primaryThreadId(), + sessionId: event.sessionId, + threadId: event.threadId, + turnId, + state: 'running', + startedAt + }) + if (admission.accepted) { + this.deps.activeTurns.remember(event.threadId, turnId, startedAt) + this.deps.resetActivity(event.threadId) + } + return admission + } + + complete(event: TurnBoundaryEvent): CodexJournalTranslationAdmission { + const suppressionAdmission = this.deps.flushSuppression() + if (!suppressionAdmission.accepted) { + return suppressionAdmission + } + const turnId = readCodexTurnId(event.params) ?? this.deps.activeTurns.current(event.threadId) + if (!turnId) { + return CODEX_JOURNAL_ADMITTED + } + // The roster is deliberately NOT swept here. `spawn_agent` children outlive + // the turn that spawned them and go on reporting into the same group, so a + // turn boundary is no evidence contact was lost. Only `settleSession` may + // write `unverifiable`. + const admission = settleCodexJournalTurn({ + sink: this.deps.sink, + sessionId: event.sessionId, + threadId: event.threadId, + turnId, + turnLifecycle: + event.threadId === this.deps.primaryThreadId() + ? this.settled( + event.threadId, + turnId, + codexTurnLifecycleState(readCodexTurnStatus(event.params)), + this.receiptTime(event) + ) + : null, + streams: this.deps.items.streams, + activeItems: this.deps.items.activeItems + }) + if (admission.accepted) { + this.deps.items.ordinals.forgetTurn(event.threadId, turnId) + this.deps.activeTurns.forget(event.threadId, turnId) + this.deps.resetActivity(event.threadId) + } + return admission + } + + /** Terminal lifecycle for a remembered turn; `startedAt` is absent when the start was never seen. */ + settled( + threadId: string, + turnId: string, + state: 'completed' | 'interrupted', + completedAt: number + ): AgentJournalTurnLifecycle { + const startedAt = this.deps.activeTurns.startedAt(threadId, turnId) + return { + turnId, + state, + ...(startedAt !== undefined ? { startedAt } : {}), + completedAt + } + } + + private receiptTime(event: TurnBoundaryEvent): number { + return event.observedAt ?? this.deps.now?.() ?? Date.now() + } +} diff --git a/src/main/codex/codex-structured-journal-translation-turn-lifecycle.test.ts b/src/main/codex/codex-structured-journal-translation-turn-lifecycle.test.ts new file mode 100644 index 00000000000..4cc569b964d --- /dev/null +++ b/src/main/codex/codex-structured-journal-translation-turn-lifecycle.test.ts @@ -0,0 +1,315 @@ +import { mkdtemp, rm } from 'node:fs/promises' +import { tmpdir } from 'node:os' +import { join } from 'node:path' +import { afterEach, beforeEach, describe, expect, it } from 'vitest' +import type { + AgentJournalItemBody, + AgentJournalItemIdentity +} from '../../shared/agent-session-journal-types' +import { agentJournalItemKey } from '../../shared/agent-session-journal-item-key' +import { projectStructuredAgentSessionStatus } from '../../shared/structured-agent-session-projection' +import { createTrackedJournalOpener } from '../native-chat/agent-session-journal/journal-store-test-open' +import { + createDeferredStructuredAgentSessionEventSink, + type StructuredAgentSessionEventSink +} from '../native-chat/agent-session-wire/structured-agent-session-event-sink' +import { createCodexJournalTranslator } from './codex-structured-journal-translation' +import type { CodexStructuredSessionEvent } from './codex-structured-session-adapter' + +const SESSION_ID = 'session-1' +const THREAD_ID = 'thread-abc' +const TURN_ID = 'turn-1' +const LIFECYCLE_KEY = 'legacy:codex:session-1:turn-lifecycle%3Aturn-1' + +type Row = { key: string; body: AgentJournalItemBody } + +function recorder() { + const rows: Row[] = [] + const tombstones: string[] = [] + const sink: StructuredAgentSessionEventSink = { + appendItem: (identity: AgentJournalItemIdentity, body) => + rows.push({ key: agentJournalItemKey(identity), body }), + appendTombstone: (identity) => tombstones.push(agentJournalItemKey(identity)), + publish: () => {} + } + return { sink, rows, tombstones } +} + +/** Latest body per identity, in first-seen order: what the journal reducer keeps. */ +function reduced(rows: readonly Row[]): Row[] { + const latest = new Map() + for (const row of rows) { + latest.set(row.key, row) + } + return [...latest.values()] +} + +function notification( + method: string, + params: unknown, + observedAt?: number +): CodexStructuredSessionEvent { + return { + type: 'notification', + sessionId: SESSION_ID, + threadId: THREAD_ID, + method, + params, + ...(observedAt !== undefined ? { observedAt } : {}) + } +} + +function translatorFor(tap: ReturnType, now?: () => number) { + return createCodexJournalTranslator({ + sink: tap.sink, + sessionId: SESSION_ID, + primaryThreadId: () => THREAD_ID, + ...(now ? { now } : {}) + }) +} + +const journals = createTrackedJournalOpener() +let root: string + +beforeEach(async () => { + root = await mkdtemp(join(tmpdir(), 'orca-codex-turn-lifecycle-')) +}) + +afterEach(async () => { + await journals.closeAll() + await rm(root, { recursive: true, force: true }) +}) + +describe('codex turn lifecycle rows', () => { + it('opens the running row with the host receipt time and pins the row time to it', async () => { + const journal = await journals.open({ + identity: { + sessionId: SESSION_ID, + workspaceId: 'workspace-1', + hostId: 'local', + agent: 'codex', + providerHandle: { kind: 'codex', threadId: THREAD_ID } + }, + now: () => 9_000, + journalDir: join(root, SESSION_ID) + }) + const deferred = createDeferredStructuredAgentSessionEventSink() + const translator = createCodexJournalTranslator({ + sink: deferred.sink, + sessionId: SESSION_ID, + primaryThreadId: () => THREAD_ID + }) + deferred.bind({ journal, fence: 1, publish: () => {} }) + + translator.handle(notification('turn/started', { turn: { id: TURN_ID } }, 1_000)) + await expect(deferred.drained()).resolves.toEqual({ ok: true }) + + expect(journal.snapshot().items).toEqual([ + expect.objectContaining({ + observedAt: 1_000, + body: { + kind: 'status', + text: 'Codex is working…', + turnLifecycle: { turnId: TURN_ID, state: 'running', startedAt: 1_000 } + } + }) + ]) + deferred.close() + }) + + it('revises the running row to completed, carrying the start time forward', () => { + const tap = recorder() + const translator = translatorFor(tap) + + translator.handle(notification('turn/started', { turn: { id: TURN_ID } }, 1_000)) + translator.handle( + notification('turn/completed', { turn: { id: TURN_ID, status: 'completed' } }, 4_500) + ) + + expect(tap.tombstones).toEqual([]) + expect(tap.rows).toEqual([ + { + key: LIFECYCLE_KEY, + body: { + kind: 'status', + text: 'Codex is working…', + turnLifecycle: { turnId: TURN_ID, state: 'running', startedAt: 1_000 } + } + }, + { + key: LIFECYCLE_KEY, + body: { + kind: 'status', + text: 'Codex is working…', + turnLifecycle: { + turnId: TURN_ID, + state: 'completed', + startedAt: 1_000, + completedAt: 4_500 + } + } + } + ]) + expect( + projectStructuredAgentSessionStatus( + reduced(tap.rows).map((row, sequence) => ({ + itemId: row.key, + revision: 1, + sequence: sequence + 1, + observedAt: sequence + 1, + body: row.body + })) + ) + ).toBe('idle') + }) + + it.each(['interrupted', 'failed', 'cancelled'])( + 'maps a %s turn status to an interrupted lifecycle', + (status) => { + const tap = recorder() + const translator = translatorFor(tap) + + translator.handle(notification('turn/started', { turn: { id: TURN_ID } }, 1_000)) + translator.handle(notification('turn/completed', { turn: { id: TURN_ID, status } }, 2_000)) + + expect(tap.rows.at(-1)?.body).toMatchObject({ + turnLifecycle: { state: 'interrupted', startedAt: 1_000, completedAt: 2_000 } + }) + } + ) + + it('stamps the host clock when a boundary arrives without a receipt time', () => { + const tap = recorder() + let clock = 10_000 + const translator = translatorFor(tap, () => (clock += 250)) + + translator.handle(notification('turn/started', { turn: { id: TURN_ID } })) + translator.handle(notification('turn/completed', { turn: { id: TURN_ID } })) + + expect(tap.rows.map((row) => row.body)).toMatchObject([ + { turnLifecycle: { state: 'running', startedAt: 10_250 } }, + { turnLifecycle: { state: 'completed', startedAt: 10_250, completedAt: 10_500 } } + ]) + }) + + it('writes only the end time when the start was never observed', () => { + const tap = recorder() + const translator = translatorFor(tap) + + translator.handle(notification('turn/completed', { turn: { id: TURN_ID } }, 3_000)) + + expect(tap.rows).toEqual([ + { + key: LIFECYCLE_KEY, + body: { + kind: 'status', + text: 'Codex is working…', + turnLifecycle: { turnId: TURN_ID, state: 'completed', completedAt: 3_000 } + } + } + ]) + }) + + it('revises every open turn to interrupted when the provider ends', () => { + const tap = recorder() + const translator = translatorFor(tap, () => 7_000) + + translator.handle(notification('turn/started', { turn: { id: 'turn-a' } }, 1_000)) + translator.handle(notification('turn/started', { turn: { id: 'turn-b' } }, 2_000)) + translator.handle({ type: 'ended', sessionId: SESSION_ID, reason: 'app-server exited' }) + + expect(tap.tombstones).toEqual([]) + expect(reduced(tap.rows).map((row) => row.body)).toMatchObject([ + { + turnLifecycle: { + turnId: 'turn-a', + state: 'interrupted', + startedAt: 1_000, + completedAt: 7_000 + } + }, + { + turnLifecycle: { + turnId: 'turn-b', + state: 'interrupted', + startedAt: 2_000, + completedAt: 7_000 + } + }, + { text: 'Provider exited: app-server exited' } + ]) + }) + + it('restores terminal rows for historical turns with both endpoints, in milliseconds', () => { + const tap = recorder() + const translator = translatorFor(tap) + + expect( + translator.restoreThread(THREAD_ID, { + turns: [ + { + id: 'turn-done', + status: 'completed', + startedAt: 1_700_000_000, + completedAt: 1_700_000_042, + items: [{ type: 'agentMessage', id: 'agent-done', text: 'done' }] + }, + { + id: 'turn-cut', + status: 'interrupted', + startedAt: 1_700_000_100, + completedAt: 1_700_000_101, + items: [] + }, + { id: 'turn-open', status: 'inProgress', startedAt: 1_700_000_200, items: [] }, + { id: 'turn-untimed', status: 'completed', items: [] } + ] + }) + ).toEqual({ accepted: true }) + + expect(tap.rows).toEqual([ + expect.objectContaining({ body: expect.objectContaining({ kind: 'message' }) }), + { + key: 'legacy:codex:session-1:turn-lifecycle%3Aturn-done', + body: { + kind: 'status', + text: 'Codex is working…', + turnLifecycle: { + turnId: 'turn-done', + state: 'completed', + startedAt: 1_700_000_000_000, + completedAt: 1_700_000_042_000 + } + } + }, + { + key: 'legacy:codex:session-1:turn-lifecycle%3Aturn-cut', + body: { + kind: 'status', + text: 'Codex is working…', + turnLifecycle: { + turnId: 'turn-cut', + state: 'interrupted', + startedAt: 1_700_000_100_000, + completedAt: 1_700_000_101_000 + } + } + } + ]) + expect(tap.tombstones).toEqual([]) + }) + + it('restores no lifecycle rows without a session identity to key them by', () => { + const tap = recorder() + const translator = createCodexJournalTranslator({ + sink: tap.sink, + primaryThreadId: () => THREAD_ID + }) + + translator.restoreThread(THREAD_ID, { + turns: [{ id: 'turn-done', status: 'completed', startedAt: 1, completedAt: 2, items: [] }] + }) + + expect(tap.rows).toEqual([]) + }) +}) diff --git a/src/main/codex/codex-structured-journal-translation-turn-state.test.ts b/src/main/codex/codex-structured-journal-translation-turn-state.test.ts index 303c0426f49..b1c11433e55 100644 --- a/src/main/codex/codex-structured-journal-translation-turn-state.test.ts +++ b/src/main/codex/codex-structured-journal-translation-turn-state.test.ts @@ -40,4 +40,16 @@ describe('CodexJournalActiveTurns', () => { expect(active.size).toBe(0) expect(active.bytes).toBe(0) }) + + it('remembers each turn start time until the turn is forgotten', () => { + const active = new CodexJournalActiveTurns() + + expect(active.remember('thread', 'turn-1', 1_000)).toBe(true) + expect(active.remember('thread', 'turn-1', 2_000)).toBe(true) + expect(active.startedAt('thread', 'turn-1')).toBe(1_000) + expect(active.startedAt('thread', 'turn-missing')).toBeUndefined() + + active.forget('thread', 'turn-1') + expect(active.startedAt('thread', 'turn-1')).toBeUndefined() + }) }) diff --git a/src/main/codex/codex-structured-journal-translation-turn-state.ts b/src/main/codex/codex-structured-journal-translation-turn-state.ts index 9a05b96fdd5..feca169ae99 100644 --- a/src/main/codex/codex-structured-journal-translation-turn-state.ts +++ b/src/main/codex/codex-structured-journal-translation-turn-state.ts @@ -5,6 +5,8 @@ export class CodexJournalActiveTurns { /** Bounds active turn keys retained across provider threads. */ static readonly MAX_ENTRIES = MAX_CODEX_ACTIVE_TURNS readonly byThread = new Map>() + /** Host turn-start receipt per remembered turn; the terminal row carries it forward. */ + private readonly startedAtByTurn = new Map() private activeCount = 0 private retainedBytes = 0 @@ -16,6 +18,10 @@ export class CodexJournalActiveTurns { return this.retainedBytes } + private turnKey(threadId: string, turnId: string): string { + return `${encodeURIComponent(threadId)}:${encodeURIComponent(turnId)}` + } + private entryBytes(threadId: string, turnId: string): number { return Buffer.byteLength(threadId, 'utf8') + Buffer.byteLength(turnId, 'utf8') } @@ -33,7 +39,11 @@ export class CodexJournalActiveTurns { return [...(this.byThread.get(threadId) ?? [])].at(-1) ?? null } - remember(threadId: string, turnId: string): boolean { + startedAt(threadId: string, turnId: string): number | undefined { + return this.startedAtByTurn.get(this.turnKey(threadId, turnId)) + } + + remember(threadId: string, turnId: string, startedAt?: number): boolean { const active = this.byThread.get(threadId) if (active?.has(turnId)) { return true @@ -41,6 +51,9 @@ export class CodexJournalActiveTurns { if (!this.canRemember(threadId, turnId)) { return false } + if (startedAt !== undefined) { + this.startedAtByTurn.set(this.turnKey(threadId, turnId), startedAt) + } if (active) { active.add(turnId) } else { @@ -52,6 +65,7 @@ export class CodexJournalActiveTurns { } forget(threadId: string, turnId: string): void { + this.startedAtByTurn.delete(this.turnKey(threadId, turnId)) const active = this.byThread.get(threadId) if (active?.delete(turnId)) { this.activeCount -= 1 @@ -64,6 +78,7 @@ export class CodexJournalActiveTurns { clear(): void { this.byThread.clear() + this.startedAtByTurn.clear() this.activeCount = 0 this.retainedBytes = 0 } diff --git a/src/main/codex/codex-structured-journal-translation-turns.ts b/src/main/codex/codex-structured-journal-translation-turns.ts index 7313946a53e..1f20eefe5bf 100644 --- a/src/main/codex/codex-structured-journal-translation-turns.ts +++ b/src/main/codex/codex-structured-journal-translation-turns.ts @@ -1,3 +1,9 @@ +import type { + AgentJournalItemIdentity, + AgentJournalStatusItem, + AgentJournalTurnLifecycle, + AgentJournalTurnLifecycleState +} from '../../shared/agent-session-journal-types' import type { StructuredAgentSessionEventSink, StructuredAgentSessionSinkAdmission @@ -5,56 +11,65 @@ import type { const ADMITTED: StructuredAgentSessionSinkAdmission = { accepted: true } +export function codexTurnLifecycleIdentity( + sessionId: string, + turnId: string +): AgentJournalItemIdentity { + return { + provider: 'legacy', + agent: 'codex', + sessionId, + recordId: `turn-lifecycle:${turnId}` + } +} + +export function codexTurnLifecycleBody( + turnLifecycle: AgentJournalTurnLifecycle +): AgentJournalStatusItem { + return { kind: 'status', text: 'Codex is working…', turnLifecycle } +} + +/** `turn/completed` is Codex's only turn-end notification; a missing status is a clean finish. */ +export function codexTurnLifecycleState( + status: string | null +): Extract { + return status === null || status === 'completed' ? 'completed' : 'interrupted' +} + export function publishCodexTurnLifecycle(input: { sink: StructuredAgentSessionEventSink primaryThreadId: string | null sessionId: string threadId: string turnId: string - state: 'running' | 'completed' + state: AgentJournalTurnLifecycleState + startedAt?: number + completedAt?: number }): StructuredAgentSessionSinkAdmission { if (input.primaryThreadId !== input.threadId) { return ADMITTED } - const identity = { - provider: 'legacy' as const, - agent: 'codex' as const, - sessionId: input.sessionId, - recordId: `turn-lifecycle:${input.turnId}` + const identity = codexTurnLifecycleIdentity(input.sessionId, input.turnId) + const body = codexTurnLifecycleBody({ + turnId: input.turnId, + state: input.state, + ...(input.startedAt !== undefined ? { startedAt: input.startedAt } : {}), + ...(input.completedAt !== undefined ? { completedAt: input.completedAt } : {}) + }) + // The running row's `ts` is the host's turn-start receipt so clients can anchor a live counter. + const appendOptions = { + lifecycle: true, + ...(input.state === 'running' && input.startedAt !== undefined + ? { observedAt: input.startedAt } + : {}) } - if (input.state === 'completed') { - if (input.sink.tryAppendTombstone) { - const admission = input.sink.tryAppendTombstone(identity, { lifecycle: true }) - if (!admission.accepted) { - return admission - } - } else { - input.sink.appendTombstone(identity, { lifecycle: true }) - } - } else { - const admission = input.sink.tryAppendItem - ? input.sink.tryAppendItem( - identity, - { - kind: 'status', - text: 'Codex is working…', - turnLifecycle: { turnId: input.turnId, state: input.state } - }, - { lifecycle: true } - ) - : (input.sink.appendItem( - identity, - { - kind: 'status', - text: 'Codex is working…', - turnLifecycle: { turnId: input.turnId, state: input.state } - }, - { lifecycle: true } - ), - ADMITTED) + if (input.sink.tryAppendItem) { + const admission = input.sink.tryAppendItem(identity, body, appendOptions) if (!admission.accepted) { return admission } + } else { + input.sink.appendItem(identity, body, appendOptions) } // Preserve first-work evidence when completion arrives before the journal drains. const publishOptions = { diff --git a/src/main/codex/codex-structured-journal-translation.test.ts b/src/main/codex/codex-structured-journal-translation.test.ts index 0a791afa77e..2723a10f2fe 100644 --- a/src/main/codex/codex-structured-journal-translation.test.ts +++ b/src/main/codex/codex-structured-journal-translation.test.ts @@ -49,6 +49,15 @@ function recorder() { } } +/** Latest body per identity, in first-seen order: what the journal reducer keeps. */ +function reduced(rows: readonly Row[]): Row[] { + const latest = new Map() + for (const row of rows) { + latest.set(row.key, row) + } + return [...latest.values()] +} + /** Fires the coalescing window on demand instead of on wall time. */ function manualWindow() { const pending: (() => void)[] = [] @@ -226,11 +235,24 @@ describe('codex journal translation', () => { body: { kind: 'status', text: 'Codex is working…', - turnLifecycle: { turnId: TURN_ID, state: 'running' } + turnLifecycle: { turnId: TURN_ID, state: 'running', startedAt: expect.any(Number) } + } + }, + { + key: 'legacy:codex:session-1:turn-lifecycle%3Aturn-1', + body: { + kind: 'status', + text: 'Codex is working…', + turnLifecycle: { + turnId: TURN_ID, + state: 'completed', + startedAt: expect.any(Number), + completedAt: expect.any(Number) + } } } ]) - expect(tap.tombstones).toEqual(['legacy:codex:session-1:turn-lifecycle%3Aturn-1']) + expect(tap.tombstones).toEqual([]) }) it('closes every active turn when the provider session ends after a later turn starts', () => { @@ -244,29 +266,34 @@ describe('codex journal translation', () => { translator.handle(notification('turn/started', { turn: { id: 'turn-later' } })) translator.handle({ type: 'ended', sessionId: SESSION_ID, reason: 'app-server exited' }) - expect(tap.rows.filter((row) => row.body.kind === 'status')).toHaveLength(3) + expect(tap.rows.filter((row) => row.body.kind === 'status')).toHaveLength(5) expect(tap.rows.map((row) => row.body)).toEqual([ - expect.objectContaining({ turnLifecycle: { turnId: 'turn-stale', state: 'running' } }), - expect.objectContaining({ turnLifecycle: { turnId: 'turn-later', state: 'running' } }), - expect.objectContaining({ text: 'Provider exited: app-server exited' }) + expect.objectContaining({ + turnLifecycle: expect.objectContaining({ turnId: 'turn-stale', state: 'running' }) + }), + expect.objectContaining({ + turnLifecycle: expect.objectContaining({ turnId: 'turn-later', state: 'running' }) + }), + expect.objectContaining({ text: 'Provider exited: app-server exited' }), + expect.objectContaining({ + turnLifecycle: expect.objectContaining({ turnId: 'turn-stale', state: 'interrupted' }) + }), + expect.objectContaining({ + turnLifecycle: expect.objectContaining({ turnId: 'turn-later', state: 'interrupted' }) + }) ]) - expect(tap.tombstones).toEqual([ - 'legacy:codex:session-1:turn-lifecycle%3Aturn-stale', - 'legacy:codex:session-1:turn-lifecycle%3Aturn-later' - ]) - // The tombstones remove both running rows from the reduced journal; no - // lifecycle identity remains live after a session end. + expect(tap.tombstones).toEqual([]) + // Both running rows are revised to interrupted, so no lifecycle identity + // remains live after a session end. expect( projectStructuredAgentSessionStatus( - tap.rows - .filter((row) => !tap.tombstones.includes(row.key)) - .map((row, sequence) => ({ - itemId: row.key, - revision: 1, - sequence: sequence + 1, - observedAt: sequence + 1, - body: row.body - })) + reduced(tap.rows).map((row, sequence) => ({ + itemId: row.key, + revision: 1, + sequence: sequence + 1, + observedAt: sequence + 1, + body: row.body + })) ) ).toBe('idle') }) @@ -283,21 +310,24 @@ describe('codex journal translation', () => { translator.handle(notification('turn/completed', { turn: { id: 'turn-stale' } })) translator.handle(notification('turn/completed', { turn: { id: 'turn-later' } })) - expect(tap.tombstones).toEqual([ - 'legacy:codex:session-1:turn-lifecycle%3Aturn-stale', - 'legacy:codex:session-1:turn-lifecycle%3Aturn-later' + expect(tap.tombstones).toEqual([]) + expect(reduced(tap.rows).map((row) => row.body)).toEqual([ + expect.objectContaining({ + turnLifecycle: expect.objectContaining({ turnId: 'turn-stale', state: 'completed' }) + }), + expect.objectContaining({ + turnLifecycle: expect.objectContaining({ turnId: 'turn-later', state: 'completed' }) + }) ]) expect( projectStructuredAgentSessionStatus( - tap.rows - .filter((row) => !tap.tombstones.includes(row.key)) - .map((row, sequence) => ({ - itemId: row.key, - revision: 1, - sequence: sequence + 1, - observedAt: sequence + 1, - body: row.body - })) + reduced(tap.rows).map((row, sequence) => ({ + itemId: row.key, + revision: 1, + sequence: sequence + 1, + observedAt: sequence + 1, + body: row.body + })) ) ).toBe('idle') }) @@ -431,7 +461,7 @@ describe('codex journal translation', () => { expect(window.idle()).toBe(true) }) - it('settles tools, prompts, exit status, and turn tombstone in one ordered batch', () => { + it('settles tools, prompts, exit status, and turn lifecycle in one ordered batch', () => { const tap = recorder() const batches: { settlementId: string; mutations: unknown[] }[] = [] tap.sink.appendLifecycleBatch = (settlementId, mutations) => { @@ -488,7 +518,12 @@ describe('codex journal translation', () => { kind: 'item', body: { kind: 'status', text: 'Provider exited: lost child' } }), - expect.objectContaining({ kind: 'tombstone' }) + expect.objectContaining({ + kind: 'item', + body: expect.objectContaining({ + turnLifecycle: expect.objectContaining({ turnId: TURN_ID, state: 'interrupted' }) + }) + }) ]) }) @@ -683,7 +718,7 @@ describe('codex journal translation', () => { expect(bodies).toEqual([ expect.objectContaining({ kind: 'status', - turnLifecycle: { turnId: TURN_ID, state: 'running' } + turnLifecycle: expect.objectContaining({ turnId: TURN_ID, state: 'running' }) }) ]) expect(publishes).toHaveLength(1) diff --git a/src/main/codex/codex-structured-journal-translation.ts b/src/main/codex/codex-structured-journal-translation.ts index 00b90d7ffc8..a35097a3825 100644 --- a/src/main/codex/codex-structured-journal-translation.ts +++ b/src/main/codex/codex-structured-journal-translation.ts @@ -15,12 +15,10 @@ import { type CodexJournalTranslator, type CodexJournalTranslatorDeps } from './codex-structured-journal-contracts' -import { - settleCodexJournalSession, - settleCodexJournalTurn -} from './codex-structured-journal-settlement' +import { settleCodexJournalSession } from './codex-structured-journal-settlement' import { settleCodexOversizedNotificationFrame } from './codex-structured-journal-translation-frames' import { restoreCodexJournalThread } from './codex-structured-journal-translation-restore' +import { CodexJournalTurnBoundaries } from './codex-structured-journal-translation-turn-boundaries' import { CodexJournalActiveTurns } from './codex-structured-journal-translation-turn-state' import { publishCodexTurnLifecycle } from './codex-structured-journal-translation-turns' import { readCodexTurnId } from './codex-structured-thread-facts' @@ -69,6 +67,21 @@ export function createCodexJournalTranslator( const flushStreams = (): CodexJournalTranslationAdmission => items.streams.flush() ? CODEX_JOURNAL_ADMITTED : { accepted: false, reason: 'backpressure' } let readActivity = createCodexProviderActivityReader() + const resetActivity = (threadId: string): void => { + if (threadId === (deps.primaryThreadId?.() ?? null)) { + readActivity = createCodexProviderActivityReader() + deps.sink.setActivity?.(null) + } + } + const turnBoundaries = new CodexJournalTurnBoundaries({ + sink: deps.sink, + primaryThreadId: () => deps.primaryThreadId?.() ?? null, + activeTurns, + items, + flushSuppression: () => genericFrames.flush(), + resetActivity, + ...(deps.now ? { now: deps.now } : {}) + }) const publishActivity = ( event: Extract, admission: CodexJournalTranslationAdmission @@ -107,6 +120,18 @@ export function createCodexJournalTranslator( ? translated.admission : { accepted: false, reason: 'untranslated' } }, + ...(deps.sessionId !== undefined + ? { + restoreTurnLifecycle: (turnLifecycle) => + publishCodexTurnLifecycle({ + sink: deps.sink, + primaryThreadId: deps.primaryThreadId?.() ?? null, + sessionId: deps.sessionId as string, + threadId, + ...turnLifecycle + }) + } + : {}), flush: items.streams.flush }) }, @@ -128,7 +153,9 @@ export function createCodexJournalTranslator( pendingPrompts: prompts.pending, currentTurnIds: activeTurns.byThread, primaryThreadId: deps.primaryThreadId?.() ?? null, - ordinals: items.ordinals + ordinals: items.ordinals, + settledTurnLifecycle: (threadId, turnId) => + turnBoundaries.settled(threadId, turnId, 'interrupted', deps.now?.() ?? Date.now()) }) if (!admission.accepted) { return admission @@ -175,14 +202,14 @@ export function createCodexJournalTranslator( return genericFrames.appendUnhandled(event.kind, event.payload, event.threadId) } if (event.method === 'turn/started') { - return startTurn(event) + return turnBoundaries.start(event) } const compaction = compactions.handle(event) if (compaction) { return publishActivity(event, compaction) } if (event.method === 'turn/completed') { - return completeTurn(event) + return turnBoundaries.complete(event) } if (event.method === CODEX_TOKEN_USAGE_METHOD) { // Classified `status-chrome`, so the generic-frame path swallows it @@ -252,70 +279,4 @@ export function createCodexJournalTranslator( activeItems: items.activeItems }) } - - function startTurn( - event: Extract - ): CodexJournalTranslationAdmission { - const turnId = readCodexTurnId(event.params) - if (!turnId) { - return CODEX_JOURNAL_ADMITTED - } - if (!activeTurns.canRemember(event.threadId, turnId)) { - return { accepted: false, reason: 'backpressure' } - } - const admission = publishCodexTurnLifecycle({ - sink: deps.sink, - primaryThreadId: deps.primaryThreadId?.() ?? null, - sessionId: event.sessionId, - threadId: event.threadId, - turnId, - state: 'running' - }) - if (admission.accepted) { - activeTurns.remember(event.threadId, turnId) - if (event.threadId === (deps.primaryThreadId?.() ?? null)) { - readActivity = createCodexProviderActivityReader() - deps.sink.setActivity?.(null) - } - } - return admission - } - - function completeTurn(event: { - sessionId: string - threadId: string - params: unknown - }): CodexJournalTranslationAdmission { - const suppressionAdmission = genericFrames.flush() - if (!suppressionAdmission.accepted) { - return suppressionAdmission - } - const turnId = readCodexTurnId(event.params) ?? activeTurns.current(event.threadId) - if (!turnId) { - return CODEX_JOURNAL_ADMITTED - } - // The roster is deliberately NOT swept here. `spawn_agent` children outlive - // the turn that spawned them and go on reporting into the same group, so a - // turn boundary is no evidence contact was lost — and `turn/completed` is - // the only turn-end notification Codex sends, so an abort cannot be told - // apart from a clean finish either. Only `settleSession` may write - // `unverifiable`. - const admission = settleCodexJournalTurn({ - sink: deps.sink, - sessionId: event.sessionId, - threadId: event.threadId, - turnId, - streams: items.streams, - activeItems: items.activeItems - }) - if (admission.accepted) { - items.ordinals.forgetTurn(event.threadId, turnId) - activeTurns.forget(event.threadId, turnId) - if (event.threadId === (deps.primaryThreadId?.() ?? null)) { - readActivity = createCodexProviderActivityReader() - deps.sink.setActivity?.(null) - } - } - return admission - } } diff --git a/src/main/codex/codex-structured-notification-retry.test.ts b/src/main/codex/codex-structured-notification-retry.test.ts new file mode 100644 index 00000000000..33e4292d8f0 --- /dev/null +++ b/src/main/codex/codex-structured-notification-retry.test.ts @@ -0,0 +1,75 @@ +import { describe, expect, it, vi } from 'vitest' +import type { CodexAppServerConnection } from './codex-app-server-connection' +import type { CodexJournalTranslationAdmission } from './codex-structured-journal-contracts' +import { createCodexStructuredNotificationRetry } from './codex-structured-notification-retry' +import type { CodexSession } from './codex-structured-session-state' + +type Translate = Parameters[0]['translate'] + +function sessionWith(connection: CodexAppServerConnection): CodexSession { + return { connection, ended: false } as CodexSession +} + +function translateMock( + ...results: CodexJournalTranslationAdmission[] +): ReturnType> { + const translate = vi.fn() + for (const result of results) { + translate.mockReturnValueOnce(result) + } + return translate +} + +describe('createCodexStructuredNotificationRetry', () => { + it('replays a backpressured turn boundary with its original receipt time', async () => { + vi.useFakeTimers() + try { + const connection = { + pauseReading: vi.fn(), + resumeReading: vi.fn() + } as unknown as CodexAppServerConnection + const session = sessionWith(connection) + const translate = translateMock({ accepted: false, reason: 'backpressure' }) + translate.mockReturnValue({ accepted: true }) + const retries = createCodexStructuredNotificationRetry({ + sessionFor: () => session, + translate + }) + + const admission = retries.handle('session-1', 'turn/started', { turn: { id: 't' } }, 1_000) + expect(admission).toEqual({ accepted: false, reason: 'backpressure' }) + await vi.advanceTimersByTimeAsync(50) + + expect(translate).toHaveBeenCalledTimes(2) + expect(translate.mock.calls.map((call) => call[4])).toEqual([1_000, 1_000]) + expect(connection.resumeReading).not.toHaveBeenCalled() + } finally { + vi.useRealTimers() + } + }) + + it('queues a later notification behind a pending one without inventing a receipt time', () => { + const connection = { + pauseReading: vi.fn(), + resumeReading: vi.fn() + } as unknown as CodexAppServerConnection + const session = sessionWith(connection) + const translate = translateMock() + translate.mockReturnValue({ accepted: false, reason: 'backpressure' }) + const retries = createCodexStructuredNotificationRetry({ + sessionFor: () => session, + translate + }) + + retries.handle('session-1', 'turn/started', { turn: { id: 't' } }, 1_000) + retries.handle('session-1', 'item/completed', { item: { id: 'i' } }) + retries.clear('session-1', connection) + + // Every attempt replays the head of the queue with its own receipt time; + // the later notification never jumps ahead of it. + expect(translate.mock.calls.length).toBeGreaterThan(0) + expect(translate.mock.calls.map((call) => [call[2], call[4]])).toEqual( + translate.mock.calls.map(() => ['turn/started', 1_000]) + ) + }) +}) diff --git a/src/main/codex/codex-structured-notification-retry.ts b/src/main/codex/codex-structured-notification-retry.ts index ae4fccbe6d0..53b95c51403 100644 --- a/src/main/codex/codex-structured-notification-retry.ts +++ b/src/main/codex/codex-structured-notification-retry.ts @@ -6,7 +6,7 @@ const MAX_RETRY_EVENTS = 256 const MAX_RETRY_BYTES = 8 * 1024 * 1024 const RETRY_DELAY_MS = 25 -type PendingNotification = { method: string; params: unknown; bytes: number } +type PendingNotification = { method: string; params: unknown; bytes: number; observedAt?: number } type RetryState = { connection: CodexAppServerConnection events: PendingNotification[] @@ -22,7 +22,8 @@ export function createCodexStructuredNotificationRetry(deps: { sessionId: string, session: CodexSession, method: string, - params: unknown + params: unknown, + observedAt?: number ) => CodexJournalTranslationAdmission }) { const states = new Map() @@ -48,7 +49,13 @@ export function createCodexStructuredNotificationRetry(deps: { fail(sessionId, state, 'notification retry owner is no longer live') break } - const admission = deps.translate(sessionId, session, pending.method, pending.params) + const admission = deps.translate( + sessionId, + session, + pending.method, + pending.params, + pending.observedAt + ) if (!admission.accepted) { if (admission.reason === 'backpressure') { state.timer = setTimeout(() => { @@ -97,7 +104,8 @@ export function createCodexStructuredNotificationRetry(deps: { sessionId: string, connection: CodexAppServerConnection, method: string, - params: unknown + params: unknown, + observedAt: number | undefined ): void => { const bytes = Buffer.byteLength(JSON.stringify({ method, params }), 'utf8') let state = states.get(sessionId) @@ -111,7 +119,12 @@ export function createCodexStructuredNotificationRetry(deps: { fail(sessionId, state, 'notification retry queue overflow') return } - state.events.push({ method, params, bytes }) + state.events.push({ + method, + params, + bytes, + ...(observedAt !== undefined ? { observedAt } : {}) + }) state.bytes += bytes connection.pauseReading?.() } @@ -120,7 +133,8 @@ export function createCodexStructuredNotificationRetry(deps: { handle: ( sessionId: string, method: string, - params: unknown + params: unknown, + observedAt?: number ): CodexJournalTranslationAdmission => { const session = deps.sessionFor(sessionId) if (!session) { @@ -128,13 +142,13 @@ export function createCodexStructuredNotificationRetry(deps: { } const state = states.get(sessionId) if (state && state.events.length > 0) { - enqueue(sessionId, state.connection, method, params) + enqueue(sessionId, state.connection, method, params, observedAt) retry(sessionId, state.connection) return { accepted: false, reason: 'backpressure' } } - const admission = deps.translate(sessionId, session, method, params) + const admission = deps.translate(sessionId, session, method, params, observedAt) if (!admission.accepted) { - enqueue(sessionId, session.connection, method, params) + enqueue(sessionId, session.connection, method, params, observedAt) retry(sessionId, session.connection) } return admission diff --git a/src/main/codex/codex-structured-provider-events.ts b/src/main/codex/codex-structured-provider-events.ts index 0cc793249a9..989232ff1b2 100644 --- a/src/main/codex/codex-structured-provider-events.ts +++ b/src/main/codex/codex-structured-provider-events.ts @@ -1,20 +1,41 @@ import type { CodexAppServerServerRequest } from './codex-app-server-connection' import { disposeCodexServerRequest } from './codex-server-request-disposition' import type { CodexJournalTranslationAdmission } from './codex-structured-journal-translation' +import * as codexRewind from './codex-structured-rewind' import type { CodexSession, CodexStructuredSessionEvent } from './codex-structured-session-state' import { readCodexThreadId, readCodexTurnId } from './codex-structured-thread-facts' +import type { CodexStructuredTurnCancellation } from './codex-structured-turn-cancellation' type EmitCodexEvent = ( session: CodexSession, event: CodexStructuredSessionEvent ) => CodexJournalTranslationAdmission +/** One live notification's journal entry: rewind bookkeeping, cancellation deferral, delivery. */ +export function translateCodexNotification(input: { + sessionId: string + session: CodexSession + method: string + params: unknown + observedAt?: number + turnCancellation: Pick + emit: EmitCodexEvent +}): CodexJournalTranslationAdmission { + const { sessionId, session, method, params, observedAt } = input + codexRewind.observeCodexRewindActivity(session, method, params) + if (input.turnCancellation.handleNotification(sessionId, session, method, params, observedAt)) { + return { accepted: true } + } + return deliverCodexNotification(sessionId, session, method, params, input.emit, observedAt) +} + export function deliverCodexNotification( sessionId: string, session: CodexSession | undefined, method: string, params: unknown, - emit: EmitCodexEvent + emit: EmitCodexEvent, + observedAt?: number ): CodexJournalTranslationAdmission { if (!session) { return { accepted: true } @@ -23,7 +44,14 @@ export function deliverCodexNotification( const turnId = method === 'turn/started' && threadId === session.threadId ? readCodexTurnId(params) : null const turnWaiter = turnId ? session.turnIdWaiters[0] : undefined - const admission = emit(session, { type: 'notification', sessionId, threadId, method, params }) + const admission = emit(session, { + type: 'notification', + sessionId, + threadId, + method, + params, + ...(observedAt !== undefined ? { observedAt } : {}) + }) if (method === 'turn/started' && threadId === session.threadId) { if (admission.accepted && turnId && session.turnIdWaiters[0] === turnWaiter) { session.turnIdWaiters.shift() diff --git a/src/main/codex/codex-structured-session-acquire.ts b/src/main/codex/codex-structured-session-acquire.ts index 8c8b39ca48b..633a1754bcc 100644 --- a/src/main/codex/codex-structured-session-acquire.ts +++ b/src/main/codex/codex-structured-session-acquire.ts @@ -77,6 +77,8 @@ export async function acquireCodexStructuredSession(input: { const translator = acquireInput.events ? createCodexJournalTranslator({ sink: acquireInput.events, + sessionId, + ...(deps.now ? { now: deps.now } : {}), primaryThreadId: () => primaryThreadId, bindPromptItemId: (journalItemId, threadId, promptKey) => acquisition.prompts.bindJournalItemId(journalItemId, threadId, promptKey) @@ -109,13 +111,16 @@ export async function acquireCodexStructuredSession(input: { env: buildCodexStructuredChildEnvironment(launch, acquireInput.spawnToken, sessionId) }, { - onNotification: (method, params) => + onNotification: (method, params) => { + // Stamped at receipt, ahead of any pre-publication buffering or retry. + const observedAt = isCodexTurnBoundary(method) ? (deps.now?.() ?? Date.now()) : undefined input.deliver( acquisition, sessionId, - () => notificationRetries.handle(sessionId, method, params), + () => notificationRetries.handle(sessionId, method, params, observedAt), Buffer.byteLength(JSON.stringify(params ?? null), 'utf8') - ), + ) + }, onServerRequest: (request) => input.deliver( acquisition, @@ -233,3 +238,7 @@ export async function acquireCodexStructuredSession(input: { attempt.finish() } } + +function isCodexTurnBoundary(method: string): boolean { + return method === 'turn/started' || method === 'turn/completed' +} diff --git a/src/main/codex/codex-structured-session-adapter-lifecycle.test.ts b/src/main/codex/codex-structured-session-adapter-lifecycle.test.ts index 3f1cd923e13..b0bac579841 100644 --- a/src/main/codex/codex-structured-session-adapter-lifecycle.test.ts +++ b/src/main/codex/codex-structured-session-adapter-lifecycle.test.ts @@ -232,11 +232,14 @@ describe('CodexStructuredSessionAdapter lifecycle', () => { it('flushes the final coalesced text before a graceful close', async () => { const codex = fakeCodex() const bodies: AgentJournalMessageItem[] = [] + const lifecycles: unknown[] = [] const tombstones: unknown[] = [] const sink: StructuredAgentSessionEventSink = { - appendItem: (_identity, body) => { + appendItem: (identity, body) => { if (body.kind === 'message') { bodies.push(body) + } else if (body.kind === 'status' && body.turnLifecycle) { + lifecycles.push({ identity, turnLifecycle: body.turnLifecycle }) } }, appendTombstone: (identity) => { @@ -266,11 +269,21 @@ describe('CodexStructuredSessionAdapter lifecycle', () => { await adapter.closeSession('session-1') expect(bodies.at(-1)?.blocks).toEqual([{ type: 'text', text: 'last words' }]) - expect(tombstones).toContainEqual({ - provider: 'legacy', - agent: 'codex', - sessionId: 'session-1', - recordId: 'turn-lifecycle:turn-1' + // A requested close interrupts the open turn; the row is revised, not removed. + expect(tombstones).toEqual([]) + expect(lifecycles.at(-1)).toEqual({ + identity: { + provider: 'legacy', + agent: 'codex', + sessionId: 'session-1', + recordId: 'turn-lifecycle:turn-1' + }, + turnLifecycle: { + turnId: 'turn-1', + state: 'interrupted', + startedAt: expect.any(Number), + completedAt: expect.any(Number) + } }) }) }) diff --git a/src/main/codex/codex-structured-session-adapter.ts b/src/main/codex/codex-structured-session-adapter.ts index ebd7c3331bf..9b41f092001 100644 --- a/src/main/codex/codex-structured-session-adapter.ts +++ b/src/main/codex/codex-structured-session-adapter.ts @@ -34,9 +34,9 @@ import { type CodexStructuredSessionEvent } from './codex-structured-session-state' import { - deliverCodexNotification, deliverCodexServerRequest, - deliverCodexUnhandledFrame + deliverCodexUnhandledFrame, + translateCodexNotification } from './codex-structured-provider-events' import { CodexStructuredTurnCancellation } from './codex-structured-turn-cancellation' import { createCodexStructuredNotificationRetry } from './codex-structured-notification-retry' @@ -58,8 +58,16 @@ export class CodexStructuredSessionAdapter implements StructuredAgentSessionAdap constructor(private readonly deps: CodexStructuredSessionAdapterDeps) { this.notificationRetries = createCodexStructuredNotificationRetry({ sessionFor: (sessionId) => this.sessions.get(sessionId), - translate: (sessionId, session, method, params) => - this.translateNotification(sessionId, session, method, params) + translate: (sessionId, session, method, params, observedAt) => + translateCodexNotification({ + sessionId, + session, + method, + params, + observedAt, + turnCancellation: this.turnCancellation, + emit: (current, event) => this.emit(current, event) + }) }) this.turnCancellation = new CodexStructuredTurnCancellation({ captureTurnProcesses: deps.captureTurnProcesses, @@ -68,7 +76,8 @@ export class CodexStructuredSessionAdapter implements StructuredAgentSessionAdap emit: (session, event) => { const admission = this.emit(session, event) if (!admission.accepted && event.type === 'notification') { - this.notificationRetries.handle(event.sessionId, event.method, event.params) + const { sessionId, method, params, observedAt } = event + this.notificationRetries.handle(sessionId, method, params, observedAt) } return admission } @@ -114,21 +123,6 @@ export class CodexStructuredSessionAdapter implements StructuredAgentSessionAdap } } - private translateNotification( - sessionId: string, - session: CodexSession, - method: string, - params: unknown - ): CodexJournalTranslationAdmission { - codexRewind.observeCodexRewindActivity(session, method, params) - if (this.turnCancellation.handleNotification(sessionId, session, method, params)) { - return { accepted: true } - } - return deliverCodexNotification(sessionId, session, method, params, (current, event) => - this.emit(current, event) - ) - } - /** Journal first so observers never see an event ahead of its durable row. */ private emit( session: CodexSession, diff --git a/src/main/codex/codex-structured-session-cancel.test.ts b/src/main/codex/codex-structured-session-cancel.test.ts index aed0722b79b..2ea81d44786 100644 --- a/src/main/codex/codex-structured-session-cancel.test.ts +++ b/src/main/codex/codex-structured-session-cancel.test.ts @@ -80,7 +80,10 @@ async function acquired( codex: ReturnType, events: CodexStructuredSessionEvent[] = [], processControl: Partial< - Pick + Pick< + CodexStructuredSessionAdapterDeps, + 'captureTurnProcesses' | 'terminateTurnProcesses' | 'now' + > > = {} ): Promise { const adapter = new CodexStructuredSessionAdapter({ @@ -260,6 +263,32 @@ describe('CodexStructuredSessionAdapter.cancelTurn', () => { }) }) + it('keeps the receipt time of a completion deferred behind physical termination', async () => { + const events: CodexStructuredSessionEvent[] = [] + let clock = 5_000 + let finishTermination!: (terminated: boolean) => void + const termination = new Promise((resolve) => { + finishTermination = resolve + }) + const codex = fakeCodex() + codex.routes['turn/interrupt'] = () => { + completeTurn(codex) + return {} + } + const adapter = await acquired(codex, events, { + terminateTurnProcesses: async () => termination, + now: () => clock + }) + + const pending = adapter.cancelTurn({ sessionId: 'session-1', turnId: 'turn-1', fence: 7 }) + await vi.waitFor(() => expect(codex.connections[0].calls.at(-1)?.method).toBe('turn/interrupt')) + clock = 9_000 + finishTermination(true) + await expect(pending).resolves.toEqual({ cancelled: true }) + + expect(events.at(-1)).toMatchObject({ method: 'turn/completed', observedAt: 5_000 }) + }) + it('does not strand a deferred completion when the interrupt receipt fails', async () => { const events: CodexStructuredSessionEvent[] = [] const codex = fakeCodex() diff --git a/src/main/codex/codex-structured-session-state.ts b/src/main/codex/codex-structured-session-state.ts index 12ba28d712f..6f09cacfd9c 100644 --- a/src/main/codex/codex-structured-session-state.ts +++ b/src/main/codex/codex-structured-session-state.ts @@ -21,7 +21,15 @@ export type CodexStructuredLaunch = { } export type CodexStructuredSessionEvent = - | { type: 'notification'; sessionId: string; threadId: string; method: string; params: unknown } + | { + type: 'notification' + sessionId: string + threadId: string + method: string + params: unknown + /** Host receipt time of a turn boundary; survives retry and deferral so a replay is not re-stamped. */ + observedAt?: number + } | { type: 'server-request'; sessionId: string; threadId: string; method: string; params: unknown } | { type: 'provider-frame'; sessionId: string; threadId: string; kind: string; payload: unknown } | { diff --git a/src/main/codex/codex-structured-thread-facts.ts b/src/main/codex/codex-structured-thread-facts.ts index 349246ecf29..0abae5b4e64 100644 --- a/src/main/codex/codex-structured-thread-facts.ts +++ b/src/main/codex/codex-structured-thread-facts.ts @@ -37,3 +37,12 @@ export function readCodexTurnId(payload: unknown): string | null { } return nonEmptyString(record(root.turn)?.id) ?? nonEmptyString(root.turnId) } + +/** `turn/completed` carries `turn.status`; thread history puts `status` on the turn record itself. */ +export function readCodexTurnStatus(payload: unknown): string | null { + const root = record(payload) + if (!root) { + return null + } + return nonEmptyString(record(root.turn)?.status) ?? nonEmptyString(root.status) +} diff --git a/src/main/codex/codex-structured-turn-cancellation.ts b/src/main/codex/codex-structured-turn-cancellation.ts index 1f31197e8d5..97257d54fa4 100644 --- a/src/main/codex/codex-structured-turn-cancellation.ts +++ b/src/main/codex/codex-structured-turn-cancellation.ts @@ -50,7 +50,8 @@ export class CodexStructuredTurnCancellation { sessionId: string, session: CodexSession, method: string, - params: unknown + params: unknown, + observedAt?: number ): boolean { const threadId = readCodexThreadId(params) ?? session.threadId if (method !== 'turn/completed' || threadId !== session.threadId) { @@ -66,7 +67,8 @@ export class CodexStructuredTurnCancellation { sessionId, threadId, method, - params + params, + ...(observedAt !== undefined ? { observedAt } : {}) } state.deferredCompletions.set(turnId, event) return true diff --git a/src/main/native-chat/agent-session-wire/provider-turn-activity-routing.test.ts b/src/main/native-chat/agent-session-wire/provider-turn-activity-routing.test.ts index a66ac567a4d..4f33ab85833 100644 --- a/src/main/native-chat/agent-session-wire/provider-turn-activity-routing.test.ts +++ b/src/main/native-chat/agent-session-wire/provider-turn-activity-routing.test.ts @@ -262,6 +262,10 @@ describe('provider turn activity routing', () => { claudeMessage({ type: 'result', subtype: 'success', is_error: false, result: 'Done' }) ) expect(state.activities.at(-1)).toBeNull() - expect(state.tombstones).toHaveLength(1) + expect(state.tombstones).toHaveLength(0) + expect(state.rows.at(-1)).toMatchObject({ + kind: 'status', + turnLifecycle: { turnId: TURN_ID, state: 'completed' } + }) }) }) diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-attach-flow.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-attach-flow.ts index bb889ad23e3..ad84b9997be 100644 --- a/src/main/native-chat/agent-session-wire/structured-agent-session-attach-flow.ts +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-attach-flow.ts @@ -46,10 +46,13 @@ export type AttachFlowInput = { callerKey: string params: AgentSessionAttachParams now: () => number - /** Publishes the journal before clients can send against the new owner. */ + /** Publishes the journal before clients can send against the new owner. `acquiredOwner` is + * true only when this attach spawned the provider child, so a re-attach to a live one is not + * mistaken for a cold acquire. */ onAttached: ( attached: AttachedJournal, - acquisitionGeneration: string | null + acquisitionGeneration: string | null, + acquiredOwner: boolean ) => Promise | void /** Host-owned provider sink, bound to the journal inside `onAttached`. */ eventSink?: StructuredAgentSessionEventSink @@ -84,6 +87,7 @@ export async function performAttach( let record: AgentSessionRecord let acquisitionGeneration: string | null = null + let acquiredOwner = false let reservedRecord: AgentSessionRecord | null = null let unsupportedReservationSettlementAttempted = false let replayed = false @@ -139,6 +143,7 @@ export async function performAttach( const acquired = await acquireOwner(input, record) record = acquired.record acquisitionGeneration = acquired.acquisitionGeneration + acquiredOwner = true } } catch (error) { const spawnToken = reservedRecord?.lease.reservedSpawnToken @@ -213,7 +218,7 @@ export async function performAttach( adapter: input.adapter }) await importAdoptedTranscript(params, attached, record, preparedTranscript.items) - await input.onAttached(attached, acquisitionGeneration) + await input.onAttached(attached, acquisitionGeneration, acquiredOwner) await store.recordOperationOutcome({ callerKey: input.callerKey, operationId: params.envelope.clientOperationId, diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-attach-orchestration.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-attach-orchestration.ts index 3a58d71b625..f59c7c9dc9c 100644 --- a/src/main/native-chat/agent-session-wire/structured-agent-session-attach-orchestration.ts +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-attach-orchestration.ts @@ -22,6 +22,7 @@ import { } from './structured-agent-session-launch-env' import { refuseAgentSessionMutation } from './structured-agent-session-mutation-admission' import { retryPendingStructuredAgentSessionSettlement } from './structured-agent-session-settlement-retry' +import { settleStaleRunningTurnsOnAcquire } from './structured-agent-session-stale-turn-verdict' import type { StructuredAgentSessionAttachContext } from './structured-agent-session-attach-context' import type { DeferredStructuredAgentSessionEventSink } from './structured-agent-session-event-sink' import { agentSessionJournalCloseRetries } from '../agent-session-journal/journal-close-retry' @@ -95,13 +96,22 @@ export function attachStructuredAgentSession( eventSink.close() context.runtimeState.discardEventSink(sessionId) }, - onAttached: async (attached, acquisitionGeneration) => { + onAttached: async (attached, acquisitionGeneration, acquiredOwner) => { const fence = context.deps.store.getRecord(sessionId)?.lease.runtimeFence ?? 0 const previous = context.sessions.get(sessionId) const previousFence = previous?.fence // Site 8: the provisional journal has no owner until the map takes it, // and the barrier below throws by design. try { + if (acquiredOwner) { + // Before the drain: the buffered events are the new child's, never a stale row's. + await settleStaleRunningTurnsOnAcquire({ + journal: attached.journal, + sessionId, + fence, + acquisitionGeneration + }) + } await bindAndDrain(eventSink, attached.journal, fence, (activity) => context.subscribers.publish(sessionId, attached.journal, activity) ) diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-event-sink.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-event-sink.ts index 6952b6d93e6..784e3aa7b20 100644 --- a/src/main/native-chat/agent-session-wire/structured-agent-session-event-sink.ts +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-event-sink.ts @@ -27,6 +27,8 @@ export type StructuredAgentSessionAppendOptions = { coalescingKey?: string /** Marks a critical lifecycle operation for lifecycle barriers and diagnostics. */ lifecycle?: boolean + /** Host clock to stamp on the row instead of its append time. */ + observedAt?: number } export type StructuredAgentSessionEventSink = { @@ -162,7 +164,11 @@ export function createDeferredStructuredAgentSessionEventSink( { bytes: estimateStructuredAgentSessionItemBytes(identity, body), coalescingKey: options.coalescingKey, - run: (bound) => bound.journal.appendItem(identity, body, { fence: bound.fence }) + run: (bound) => + bound.journal.appendItem(identity, body, { + fence: bound.fence, + ...(options.observedAt === undefined ? {} : { observedAt: options.observedAt }) + }) }, options ) @@ -172,7 +178,11 @@ export function createDeferredStructuredAgentSessionEventSink( { bytes: estimateStructuredAgentSessionItemBytes(identity, body), coalescingKey: options.coalescingKey, - run: (bound) => bound.journal.appendItem(identity, body, { fence: bound.fence }) + run: (bound) => + bound.journal.appendItem(identity, body, { + fence: bound.fence, + ...(options.observedAt === undefined ? {} : { observedAt: options.observedAt }) + }) }, options ), diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-host.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-host.ts index 2df2fdf5412..1f11555b021 100644 --- a/src/main/native-chat/agent-session-wire/structured-agent-session-host.ts +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-host.ts @@ -329,8 +329,8 @@ export class StructuredAgentSessionHost { history: StructuredAgentSessionBackgroundTaskChannel['history'] = (request) => this.backgroundTasks.history(request) - /** The fully reduced timeline, for readers that cannot tolerate a page's ambiguity — a settled - * turn is tombstoned, so an item's ABSENCE from a bounded page proves nothing. */ + /** The fully reduced timeline, for readers that cannot tolerate a page's ambiguity — rows are + * revised or tombstoned in place, so an item's ABSENCE from a bounded page proves nothing. */ journalSnapshot = (sessionId: string): AgentJournalSnapshot => this.requireSession(sessionId).journal.snapshot() diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-settlement-retry.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-settlement-retry.ts index 9fc68a9fca2..4e5de3f2566 100644 --- a/src/main/native-chat/agent-session-wire/structured-agent-session-settlement-retry.ts +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-settlement-retry.ts @@ -4,6 +4,7 @@ import type { StructuredAgentSessionHostDeps, StructuredAgentSessionHostSession } from './structured-agent-session-host-types' +import { turnVerdictFromDeathEvidence } from './structured-agent-session-stale-turn-verdict' import { retryUnexpectedExitSettlement, type StructuredAgentSessionUnexpectedExitContext @@ -80,7 +81,9 @@ export async function retryLoadedStructuredAgentSessionSettlement(input: { acquisitionGeneration: retrySession.acquisitionGeneration ?? 'recovery' }, session: retrySession, - stableSettlementId: record.lease.settlementRetryId + stableSettlementId: record.lease.settlementRetryId, + // Only an observed exit earns an end time; a probe-proven death never saw one. + verdict: turnVerdictFromDeathEvidence(record.lease.deathEvidence) }) if (!ok) { return false diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-stale-turn-verdict.test.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-stale-turn-verdict.test.ts new file mode 100644 index 00000000000..273861ce1e9 --- /dev/null +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-stale-turn-verdict.test.ts @@ -0,0 +1,162 @@ +import { describe, expect, it, vi } from 'vitest' +import { agentJournalItemKey } from '../../../shared/agent-session-journal-item-key' +import type { AgentJournalRenderItem } from '../../../shared/agent-session-journal-types' +import type { AgentSessionJournal } from '../agent-session-journal/journal-store' +import { + runningTurnLifecycleRevisions, + settleStaleRunningTurnsOnAcquire, + turnVerdictFromDeathEvidence +} from './structured-agent-session-stale-turn-verdict' + +const THREAD = 'thread-1' +const RUNNING_IDENTITY = { + provider: 'codex' as const, + threadId: THREAD, + turnId: 'turn-2', + ordinal: 0 +} + +function lifecycleItem( + turnId: string, + state: 'running' | 'completed', + sequence: number, + extra: { startedAt?: number; completedAt?: number } = {} +): AgentJournalRenderItem { + return { + itemId: agentJournalItemKey({ provider: 'codex', threadId: THREAD, turnId, ordinal: 0 }), + revision: 1, + sequence, + observedAt: sequence, + body: { kind: 'status', text: 'Working', turnLifecycle: { turnId, state, ...extra } } + } +} + +describe('turn verdict from death evidence', () => { + it('earns an end time only from an observed exit', () => { + expect( + turnVerdictFromDeathEvidence({ kind: 'exit-observed', detail: 'exit', observedAt: 500 }) + ).toEqual({ state: 'interrupted', completedAt: 500 }) + expect( + turnVerdictFromDeathEvidence({ kind: 'pid-absent', detail: 'gone', observedAt: 500 }) + ).toEqual({ state: 'unverifiable' }) + expect( + turnVerdictFromDeathEvidence({ kind: 'identity-mismatch', detail: 'pid', observedAt: 500 }) + ).toEqual({ state: 'unverifiable' }) + expect(turnVerdictFromDeathEvidence(null)).toEqual({ state: 'unverifiable' }) + }) +}) + +describe('running turn lifecycle revisions', () => { + it('revises only running rows, keeping identity, text and start', () => { + const items = [ + lifecycleItem('turn-1', 'completed', 1, { startedAt: 10, completedAt: 20 }), + lifecycleItem('turn-2', 'running', 2, { startedAt: 30 }) + ] + expect(runningTurnLifecycleRevisions(items, { state: 'interrupted', completedAt: 40 })).toEqual( + [ + { + kind: 'item', + identity: RUNNING_IDENTITY, + body: { + kind: 'status', + text: 'Working', + turnLifecycle: { + turnId: 'turn-2', + state: 'interrupted', + startedAt: 30, + completedAt: 40 + } + } + } + ] + ) + }) + + it('never carries or invents an end time for an unverifiable verdict', () => { + const [revision] = runningTurnLifecycleRevisions( + [lifecycleItem('turn-2', 'running', 2, { startedAt: 30, completedAt: 99 })], + { state: 'unverifiable' } + ) + expect( + revision?.kind === 'item' && revision.body.kind === 'status' && revision.body.turnLifecycle + ).toEqual({ turnId: 'turn-2', state: 'unverifiable', startedAt: 30 }) + }) + + it('skips rows without a parseable identity', () => { + const item = { ...lifecycleItem('turn-2', 'running', 2), itemId: 'not-an-item-key' } + expect(runningTurnLifecycleRevisions([item], { state: 'unverifiable' })).toEqual([]) + }) +}) + +describe('stale running turns on a cold acquire', () => { + function journalWith(items: AgentJournalRenderItem[]) { + const appendLifecycleBatch = vi.fn(async () => ({ epoch: 'epoch-1', sequence: 9 })) + const journal = { + snapshot: () => ({ items }), + cursor: () => ({ epoch: 'epoch-1', sequence: 8 }), + appendLifecycleBatch + } as unknown as AgentSessionJournal + return { journal, appendLifecycleBatch } + } + + it('marks a running row from the dead generation unverifiable without an end time', async () => { + const { journal, appendLifecycleBatch } = journalWith([ + lifecycleItem('turn-1', 'completed', 1, { startedAt: 10, completedAt: 20 }), + lifecycleItem('turn-2', 'running', 2, { startedAt: 30 }) + ]) + + await expect( + settleStaleRunningTurnsOnAcquire({ + journal, + sessionId: 'session-1', + fence: 14, + acquisitionGeneration: 'generation-2' + }) + ).resolves.toBe(1) + + expect(appendLifecycleBatch).toHaveBeenCalledExactlyOnceWith({ + settlementId: 'stale-turn:session-1:14:generation-2', + fence: 14, + recovered: true, + mutations: [ + { + kind: 'item', + identity: RUNNING_IDENTITY, + body: { + kind: 'status', + text: 'Working', + turnLifecycle: { turnId: 'turn-2', state: 'unverifiable', startedAt: 30 } + } + } + ] + }) + }) + + it('writes nothing when no turn is running', async () => { + const { journal, appendLifecycleBatch } = journalWith([ + lifecycleItem('turn-1', 'completed', 1, { startedAt: 10, completedAt: 20 }) + ]) + await expect( + settleStaleRunningTurnsOnAcquire({ + journal, + sessionId: 'session-1', + fence: 14, + acquisitionGeneration: 'generation-2' + }) + ).resolves.toBe(0) + expect(appendLifecycleBatch).not.toHaveBeenCalled() + }) + + it('keys the settlement on the journal position when the adapter minted no generation', async () => { + const { journal, appendLifecycleBatch } = journalWith([lifecycleItem('turn-2', 'running', 2)]) + await settleStaleRunningTurnsOnAcquire({ + journal, + sessionId: 'session-1', + fence: 14, + acquisitionGeneration: null + }) + expect(appendLifecycleBatch).toHaveBeenCalledWith( + expect.objectContaining({ settlementId: 'stale-turn:session-1:14:seq-8' }) + ) + }) +}) diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-stale-turn-verdict.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-stale-turn-verdict.ts new file mode 100644 index 00000000000..eefdfc83eef --- /dev/null +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-stale-turn-verdict.ts @@ -0,0 +1,94 @@ +// What the host may durably say about a turn whose provider child is gone. +// +// `interrupted` requires the host to have seen the child exit; that receipt is the only end time it +// is allowed to record. Everything weaker — a pid probe, an identity mismatch, a journal found +// running on a cold acquire — is `unverifiable` and carries no end at all. + +import { parseAgentJournalItemKey } from '../../../shared/agent-session-journal-item-key' +import type { + AgentJournalRenderItem, + AgentJournalTurnLifecycle +} from '../../../shared/agent-session-journal-types' +import type { AgentSessionDeathEvidence } from '../../../shared/agent-session-record' +import { partitionJournalLifecycleMutations } from '../agent-session-journal/journal-lifecycle-batch-partition' +import type { JournalLifecycleMutationInput } from '../agent-session-journal/journal-row-builders' +import type { AgentSessionJournal } from '../agent-session-journal/journal-store' + +export type StructuredAgentSessionTurnVerdict = + | { state: 'interrupted'; completedAt: number } + | { state: 'unverifiable' } + +export const UNVERIFIABLE_TURN_VERDICT: StructuredAgentSessionTurnVerdict = { + state: 'unverifiable' +} + +export function turnVerdictFromDeathEvidence( + evidence: AgentSessionDeathEvidence | null | undefined +): StructuredAgentSessionTurnVerdict { + return evidence?.kind === 'exit-observed' + ? { state: 'interrupted', completedAt: evidence.observedAt } + : UNVERIFIABLE_TURN_VERDICT +} + +/** Revises every still-running lifecycle item in place, keeping its identity and start. */ +export function runningTurnLifecycleRevisions( + items: readonly AgentJournalRenderItem[], + verdict: StructuredAgentSessionTurnVerdict +): JournalLifecycleMutationInput[] { + const revisions: JournalLifecycleMutationInput[] = [] + for (const item of items) { + if (item.body.kind !== 'status' || item.body.turnLifecycle?.state !== 'running') { + continue + } + const identity = parseAgentJournalItemKey(item.itemId) + if (!identity) { + continue + } + revisions.push({ + kind: 'item', + identity, + body: { ...item.body, turnLifecycle: settledLifecycle(item.body.turnLifecycle, verdict) } + }) + } + return revisions +} + +function settledLifecycle( + lifecycle: AgentJournalTurnLifecycle, + verdict: StructuredAgentSessionTurnVerdict +): AgentJournalTurnLifecycle { + const settled: AgentJournalTurnLifecycle = { turnId: lifecycle.turnId, state: verdict.state } + if (lifecycle.startedAt !== undefined) { + settled.startedAt = lifecycle.startedAt + } + if (verdict.state === 'interrupted') { + settled.completedAt = verdict.completedAt + } + return settled +} + +/** A running row found when a NEW child is acquired belongs to a generation whose exit nobody + * observed. Must run before that child's buffered events land, or a live turn would be judged. */ +export async function settleStaleRunningTurnsOnAcquire(input: { + journal: AgentSessionJournal + sessionId: string + fence: number + acquisitionGeneration: string | null +}): Promise { + const { journal } = input + const revisions = runningTurnLifecycleRevisions( + journal.snapshot().items, + UNVERIFIABLE_TURN_VERDICT + ) + const generation = input.acquisitionGeneration ?? `seq-${journal.cursor().sequence}` + const settlementId = `stale-turn:${input.sessionId}:${input.fence}:${generation}` + for (const chunk of partitionJournalLifecycleMutations(settlementId, revisions)) { + await journal.appendLifecycleBatch({ + settlementId: chunk.settlementId, + fence: input.fence, + recovered: true, + mutations: chunk.mutations + }) + } + return revisions.length +} diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-unexpected-exit.test.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-unexpected-exit.test.ts index 084ffc7547d..75ecdf184be 100644 --- a/src/main/native-chat/agent-session-wire/structured-agent-session-unexpected-exit.test.ts +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-unexpected-exit.test.ts @@ -1,4 +1,6 @@ import { describe, expect, it, vi } from 'vitest' +import { agentJournalItemKey } from '../../../shared/agent-session-journal-item-key' +import type { AgentJournalRenderItem } from '../../../shared/agent-session-journal-types' import type { AgentSessionRecord } from '../../../shared/agent-session-record' import type { StructuredAgentSessionHostSession } from './structured-agent-session-host-types' import { @@ -92,6 +94,110 @@ describe('provider-exit recovery tickets', () => { expect(session.hasProviderChild).toBe(false) }) + it('revises a running lifecycle row to interrupted at exit receipt instead of tombstoning it', async () => { + const running = { + provider: 'codex' as const, + threadId: 'thread-1', + turnId: 'turn-2', + ordinal: 0 + } + const items: AgentJournalRenderItem[] = [ + { + itemId: agentJournalItemKey({ ...running, turnId: 'turn-1' }), + revision: 1, + sequence: 1, + observedAt: 1, + body: { + kind: 'status', + text: 'Done', + turnLifecycle: { turnId: 'turn-1', state: 'completed', startedAt: 10, completedAt: 20 } + } + }, + { + itemId: agentJournalItemKey(running), + revision: 1, + sequence: 2, + observedAt: 2, + body: { + kind: 'status', + text: 'Working', + turnLifecycle: { turnId: 'turn-2', state: 'running', startedAt: 30 } + } + } + ] + const appendLifecycleBatch = vi.fn(async () => ({ epoch: 'epoch-1', sequence: 3 })) + const session = { + hasProviderChild: true, + fence: 7, + acquisitionGeneration: GENERATION, + journal: { snapshot: () => ({ items }), appendLifecycleBatch } + } as unknown as StructuredAgentSessionHostSession + + await settleUnexpectedStructuredAgentSessionExit( + { + store: { + getRecord: () => ({ + lease: { + handoffStage: null, + runtimeFence: 7, + runtimeKind: 'native', + claimStatus: 'live', + ownerProcess: 'provider', + reservedSpawnToken: null, + processlessAt: null + } + }), + transitionHandoff: async () => ({ lease: { runtimeFence: 8 } }) + }, + sessions: new Map([[SESSION, session]]), + flushLifecycle: async () => ({ ok: true }), + publishFence: vi.fn(), + hasResumeCapableHolder: () => true, + serialize: async (_sessionId, task) => task(), + now: () => 1_234 + } as never, + { + type: 'ended', + sessionId: SESSION, + reason: 'provider exited', + cause: 'unexpected-exit', + fence: 7, + acquisitionGeneration: GENERATION, + settlementRetryRequired: true + } + ) + + expect(appendLifecycleBatch).toHaveBeenCalledExactlyOnceWith({ + settlementId: `provider-exit:${SESSION}:7:${GENERATION}`, + fence: 7, + recovered: true, + mutations: [ + { + kind: 'item', + identity: { + provider: 'orca', + clientMessageId: `provider-exit:${SESSION}:7:${GENERATION}` + }, + body: { kind: 'status', text: 'Provider exited: provider exited' } + }, + { + kind: 'item', + identity: running, + body: { + kind: 'status', + text: 'Working', + turnLifecycle: { + turnId: 'turn-2', + state: 'interrupted', + startedAt: 30, + completedAt: 1_234 + } + } + } + ] + }) + }) + it('does not release or reacquire while terminal settlement retry is still failing', async () => { const session = { hasProviderChild: true, diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-unexpected-exit.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-unexpected-exit.ts index ddc4af9f2d3..cbf5bd339d4 100644 --- a/src/main/native-chat/agent-session-wire/structured-agent-session-unexpected-exit.ts +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-unexpected-exit.ts @@ -1,4 +1,8 @@ import { parseAgentJournalItemKey } from '../../../shared/agent-session-journal-item-key' +import { + runningTurnLifecycleRevisions, + type StructuredAgentSessionTurnVerdict +} from './structured-agent-session-stale-turn-verdict' import type { AgentJournalItemBody, AgentJournalRenderItem @@ -47,6 +51,8 @@ export async function settleUnexpectedStructuredAgentSessionExit( return null } const unexpectedEvent = event as UnexpectedExitLifecycleEvent + // Receipt of the exit is the one end time the host may record for a running turn. + const observedAt = context.now() return context.serialize(unexpectedEvent.sessionId, async () => { const session = context.sessions.get(unexpectedEvent.sessionId) if ( @@ -86,7 +92,8 @@ export async function settleUnexpectedStructuredAgentSessionExit( context, event: unexpectedEvent, session, - stableSettlementId + stableSettlementId, + verdict: { state: 'interrupted', completedAt: observedAt } }) if (!retried) { settlementFailed = true @@ -168,12 +175,14 @@ export async function retryUnexpectedExitSettlement(input: { event: UnexpectedExitLifecycleEvent session: Pick stableSettlementId: string + verdict: StructuredAgentSessionTurnVerdict }): Promise { try { const mutations = unexpectedExitFallbackMutations( input.event, input.session, - input.stableSettlementId + input.stableSettlementId, + input.verdict ) for (const chunk of partitionJournalLifecycleMutations(input.stableSettlementId, mutations)) { await input.session.journal.appendLifecycleBatch({ @@ -193,11 +202,12 @@ export async function retryUnexpectedExitSettlement(input: { function unexpectedExitFallbackMutations( event: UnexpectedExitLifecycleEvent, session: Pick, - stableSettlementId: string + stableSettlementId: string, + verdict: StructuredAgentSessionTurnVerdict ): JournalLifecycleMutationInput[] { const mutations: JournalLifecycleMutationInput[] = [] - const tombstones: JournalLifecycleMutationInput[] = [] - for (const item of session.journal.snapshot().items) { + const { items } = session.journal.snapshot() + for (const item of items) { const identity = parseAgentJournalItemKey(item.itemId) if (!identity) { continue @@ -206,16 +216,14 @@ function unexpectedExitFallbackMutations( if (terminal) { mutations.push({ kind: 'item', identity, body: terminal }) } - if (item.body.kind === 'status' && item.body.turnLifecycle?.state === 'running') { - tombstones.push({ kind: 'tombstone', identity }) - } } mutations.push({ kind: 'item', identity: { provider: 'orca', clientMessageId: stableSettlementId }, body: { kind: 'status', text: boundJournalStatusText(`Provider exited: ${event.reason}`) } }) - mutations.push(...tombstones) + // Lifecycle rows settle last, in place: the turn's endpoints outlive the child. + mutations.push(...runningTurnLifecycleRevisions(items, verdict)) return mutations } diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-wedged-profile-migration.test.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-wedged-profile-migration.test.ts index dfeaa650129..b1209096f0b 100644 --- a/src/main/native-chat/agent-session-wire/structured-agent-session-wedged-profile-migration.test.ts +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-wedged-profile-migration.test.ts @@ -200,13 +200,25 @@ async function seedRunningTurn(provider: 'codex' | 'claude' = 'codex'): Promise< { kind: 'status', text: 'Agent is working...', - turnLifecycle: { turnId: 'turn-1', state: 'running' } + turnLifecycle: { turnId: 'turn-1', state: 'running', startedAt: NOW - 5_000 } }, { fence: 13 } ) await journal.close() } +function turnLifecycle(turnId: string) { + const item = restoredJournal() + .snapshot() + .items.find( + (candidate) => + candidate.body.kind === 'status' && candidate.body.turnLifecycle?.turnId === turnId + ) + return item?.body.kind === 'status' + ? { ...item.body.turnLifecycle, recovered: item.recovered } + : null +} + function restoredJournal(): AgentSessionJournal { const restored = ( host as unknown as { sessions: Map } @@ -289,6 +301,13 @@ describe('already-wedged profiles become usable on load', () => { expect(acquire).toHaveBeenCalledOnce() expect(activeStructuredAgentSessionTurnId(restoredJournal().snapshot().items)).toBe(null) + // A pid probe proved the owner gone; nobody saw it exit, so the turn has no end. + expect(turnLifecycle('turn-1')).toEqual({ + turnId: 'turn-1', + state: 'unverifiable', + startedAt: NOW - 5_000, + recovered: true + }) expect(store.getRecord(SESSION)?.lease).toMatchObject({ claimStatus: 'live', handoffStage: null, @@ -314,6 +333,14 @@ describe('already-wedged profiles become usable on load', () => { expect(acquire).toHaveBeenCalledOnce() expect(activeStructuredAgentSessionTurnId(restoredJournal().snapshot().items)).toBe(null) + // The exit was observed, so its receipt is the turn's end. + expect(turnLifecycle('turn-1')).toEqual({ + turnId: 'turn-1', + state: 'interrupted', + startedAt: NOW - 5_000, + completedAt: NOW - 1_000, + recovered: true + }) expect(store.getRecord(SESSION)?.lease).toMatchObject({ claimStatus: 'live', handoffStage: null, @@ -322,6 +349,57 @@ describe('already-wedged profiles become usable on load', () => { }) }) + it('marks a running turn left behind by a released lease unverifiable on a cold acquire', async () => { + // No settlement latch: the record was released cleanly, but the journal still says a turn is + // running. The child that wrote it is gone and nothing observed its exit. + await seedStore(wedgedRecord({ claimStatus: 'released', handoffStage: null })) + await seedRunningTurn() + openHost() + + expect(await host.attach(CALLER, hostTestAttachParams(13))).toMatchObject({ ok: true }) + + expect(acquire).toHaveBeenCalledOnce() + expect(turnLifecycle('turn-1')).toEqual({ + turnId: 'turn-1', + state: 'unverifiable', + startedAt: NOW - 5_000, + recovered: true + }) + expect( + restoredJournal() + .snapshot() + .items.some( + (item) => item.body.kind === 'status' && item.body.text.startsWith('Provider exited') + ) + ).toBe(false) + }) + + it("leaves the live generation's running turn alone on a re-attach", async () => { + await seedStore(wedgedRecord({ claimStatus: 'released', handoffStage: null })) + // The child this host spawns stays provably alive across the second attach. + openHost({ + probeOwner: async () => ({ outcome: 'identity-matched', matchedOn: ['spawn-token'] }) + }) + const params = hostTestAttachParams(13) + expect(await host.attach(CALLER, params)).toMatchObject({ ok: true }) + const fence = store.getRecord(SESSION)!.lease.runtimeFence + await restoredJournal().appendItem( + { provider: 'codex', threadId: THREAD, turnId: 'turn-2', ordinal: 0 }, + { + kind: 'status', + text: 'Agent is working...', + turnLifecycle: { turnId: 'turn-2', state: 'running', startedAt: NOW } + }, + { fence } + ) + + // A reconnecting client replays its attach; the same operation admits the live owner. + expect(await host.attach(CALLER, params)).toMatchObject({ ok: true, replayed: true }) + + expect(acquire).toHaveBeenCalledOnce() + expect(turnLifecycle('turn-2')).toEqual({ turnId: 'turn-2', state: 'running', startedAt: NOW }) + }) + it('re-adjudicates a conflicted manual-recovery record whose owner is provably gone', async () => { // A crash can leave a conflicted current-schema row in manual recovery; positive death proof // must make it acquirable again without discarding the provider handle. diff --git a/src/main/native-chat/agent-session-wire/structured-rewind-journal-body.test.ts b/src/main/native-chat/agent-session-wire/structured-rewind-journal-body.test.ts index 3e6b70c2bcc..167c67c5ecf 100644 --- a/src/main/native-chat/agent-session-wire/structured-rewind-journal-body.test.ts +++ b/src/main/native-chat/agent-session-wire/structured-rewind-journal-body.test.ts @@ -34,6 +34,22 @@ describe('rewind recovery of newer durable records', () => { text: JSON.stringify(status) }) }) + it.each(['interrupted', 'unverifiable'] as const)( + 'keeps a %s turn and its recorded endpoints', + (state) => { + const status = { + kind: 'status' as const, + text: 'Working', + turnLifecycle: { + turnId: 'turn', + state, + startedAt: 10, + ...(state === 'interrupted' ? { completedAt: 20 } : {}) + } + } + expect(restoreRewindJournalBody(status)).toEqual(status) + } + ) it('does not reject a saved recovery prefix over a newer refusal reason', () => { expect( AgentSessionRewindRecordSchema.safeParse({ diff --git a/src/main/native-chat/agent-session-wire/structured-rewind-journal-body.ts b/src/main/native-chat/agent-session-wire/structured-rewind-journal-body.ts index b1c32633af4..a2cab1d54ab 100644 --- a/src/main/native-chat/agent-session-wire/structured-rewind-journal-body.ts +++ b/src/main/native-chat/agent-session-wire/structured-rewind-journal-body.ts @@ -1,5 +1,8 @@ import { isAdmissibleAgentJournalItemBody } from '../../../shared/agent-session-journal-schemas' -import type { AgentJournalItemBody } from '../../../shared/agent-session-journal-types' +import { + AGENT_JOURNAL_TURN_LIFECYCLE_STATES, + type AgentJournalItemBody +} from '../../../shared/agent-session-journal-types' import type { AgentSessionRewindRecord } from '../../../shared/agent-session-rewind' import { NATIVE_CHAT_ROLES } from '../../../shared/native-chat-types' @@ -49,8 +52,7 @@ export function restoreRewindJournalBody(body: StoredBody): AgentJournalItemBody } else if ( body.kind === 'status' && body.turnLifecycle && - body.turnLifecycle.state !== 'running' && - body.turnLifecycle.state !== 'completed' + !(AGENT_JOURNAL_TURN_LIFECYCLE_STATES as readonly string[]).includes(body.turnLifecycle.state) ) { normalized = fallback() } diff --git a/src/main/runtime/orchestration/structured-mailbox-pointer-host.ts b/src/main/runtime/orchestration/structured-mailbox-pointer-host.ts index 4b80b8df5d7..7704e549d2f 100644 --- a/src/main/runtime/orchestration/structured-mailbox-pointer-host.ts +++ b/src/main/runtime/orchestration/structured-mailbox-pointer-host.ts @@ -33,10 +33,10 @@ export function structuredSessionPointerCallerKey(sessionId: string): string { /** * The idle gate for a structured session, read off its FULL reduced timeline. * - * Never a bounded page. Settlement tombstones the running turn's lifecycle item rather than - * rewriting it to `completed`, so on any tail window an idle session and a busy one whose - * lifecycle item scrolled off look identical — and idle-with-history is the normal steady state of - * a working agent. Shared so the pointer lane and group addressing cannot disagree about it. + * Never a bounded page. A settled turn's lifecycle item is revised in place, so on any tail window + * an idle session and a busy one whose lifecycle item scrolled off look identical — and + * idle-with-history is the normal steady state of a working agent. Shared so the pointer lane and + * group addressing cannot disagree about it. */ export function readStructuredSessionGateFacts( sessionId: string diff --git a/src/main/runtime/structured-agent-session-integration.test.ts b/src/main/runtime/structured-agent-session-integration.test.ts index aa14aaa5639..f5a59033d73 100644 --- a/src/main/runtime/structured-agent-session-integration.test.ts +++ b/src/main/runtime/structured-agent-session-integration.test.ts @@ -661,8 +661,10 @@ describe('a structured codex session over agentSession.*', () => { expect(older.page.hasOlder).toBe(false) // Every step of the conversation, in order, from the durable journal alone — // no page overlaps another, and nothing the live stream showed is missing. + // The turn's lifecycle row outlives the turn: it is revised, never tombstoned. expect([...older.page.items, ...tail.page.items].map((item) => item.body?.kind)).toEqual([ 'message', + 'status', 'message', 'tool-call', 'approval', @@ -671,6 +673,7 @@ describe('a structured codex session over agentSession.*', () => { ]) expect([...older.page.items, ...tail.page.items].map(textOf)).toEqual([ 'list files', + '', 'Two files.', '', '', diff --git a/src/renderer/src/components/native-chat/NativeChatMessageList.tsx b/src/renderer/src/components/native-chat/NativeChatMessageList.tsx index c6da9030a2c..233b40ac8c7 100644 --- a/src/renderer/src/components/native-chat/NativeChatMessageList.tsx +++ b/src/renderer/src/components/native-chat/NativeChatMessageList.tsx @@ -19,6 +19,7 @@ import type { NativeChatTurnActivity } from './native-chat-turn-activity' import { NativeChatTurnActivityLine } from './NativeChatTurnActivityLine' import type { AgentJournalRenderItem } from '../../../../shared/agent-session-journal-types' +import type { NativeChatSettledTurn } from '../../../../shared/native-chat-turn-status' import { nativeChatTurnDiffs, type NativeChatDiffReveal, @@ -45,6 +46,7 @@ export function NativeChatMessageList({ onLinkClick, allowFileUriLinks = false, workingStartedAt, + settledTurns, failedDeliveryMessageIds, showTurnStatus = true, turnActivity, @@ -58,6 +60,8 @@ export function NativeChatMessageList({ /** Chat-only text multiplier (1 = default), driven by the zoom shortcuts. */ fontScale: number workingStartedAt?: number | null + /** Host-recorded turn durations keyed by user message id (structured lane). */ + settledTurns?: ReadonlyMap onLinkClick?: CommentMarkdownLinkClickHandler allowFileUriLinks?: boolean failedDeliveryMessageIds?: ReadonlySet @@ -149,7 +153,8 @@ export function NativeChatMessageList({ messages, latestUserIndex, isWorking: showTurnStatus && isWorking, - workingStartedAt: showTurnStatus ? workingStartedAt : null + workingStartedAt: showTurnStatus ? workingStartedAt : null, + settledTurns: showTurnStatus ? settledTurns : null }) const prependAnchorRef = useRef<{ scrollHeight: number; scrollTop: number } | null>(null) diff --git a/src/renderer/src/components/native-chat/NativeChatMessageList.turn-timing.test.tsx b/src/renderer/src/components/native-chat/NativeChatMessageList.turn-timing.test.tsx new file mode 100644 index 00000000000..afcce0f9531 --- /dev/null +++ b/src/renderer/src/components/native-chat/NativeChatMessageList.turn-timing.test.tsx @@ -0,0 +1,72 @@ +// @vitest-environment happy-dom + +import '@testing-library/jest-dom/vitest' + +import { cleanup, render, screen } from '@testing-library/react' +import { afterEach, describe, expect, it, vi } from 'vitest' +import type { NativeChatLiveSession } from './use-native-chat-live-session' +import { NativeChatMessageList } from './NativeChatMessageList' + +afterEach(cleanup) + +const session: NativeChatLiveSession = { + messages: [ + { + id: 'user-settled', + role: 'user', + blocks: [{ type: 'text', text: 'Settled on the host' }], + timestamp: 1, + source: 'transcript' + }, + { + id: 'assistant-settled', + role: 'assistant', + blocks: [{ type: 'text', text: 'Done.' }], + timestamp: 2, + source: 'transcript' + } + ], + status: 'ready', + sessionId: 'session-1', + agent: 'codex', + hasMore: false, + loadingEarlier: false, + loadEarlier: vi.fn(), + readPhase: 'ready' +} + +const settledTurns = new Map([['user-settled', { startedAt: 1, workedSeconds: 197 }]]) + +describe('NativeChatMessageList host-settled turn timing', () => { + it('renders a host-settled duration without ever clocking the turn locally', () => { + // A local clock nowhere near the host's: the value must still be the host's. + const now = vi.spyOn(Date, 'now').mockReturnValue(1_700_000_000_000) + try { + const { rerender } = render( + + ) + expect(screen.getByText('Worked for 3m 17s')).toBeInTheDocument() + now.mockReturnValue(1_700_000_099_000) + rerender( + + ) + expect(screen.getByText('Worked for 3m 17s')).toBeInTheDocument() + } finally { + now.mockRestore() + } + }) +}) diff --git a/src/renderer/src/components/native-chat/NativeChatStructuredSession.tsx b/src/renderer/src/components/native-chat/NativeChatStructuredSession.tsx index 25181b5cb23..f7d4863ff01 100644 --- a/src/renderer/src/components/native-chat/NativeChatStructuredSession.tsx +++ b/src/renderer/src/components/native-chat/NativeChatStructuredSession.tsx @@ -196,7 +196,8 @@ export function NativeChatStructuredSession( isWorking={controller.isWorking} expandSignal={false} fontScale={fontScale.scale} - workingStartedAt={null} + workingStartedAt={controller.workingStartedAt} + settledTurns={controller.settledTurns} showTurnStatus turnActivity={controller.turnActivity} onLinkClick={onLinkClick} diff --git a/src/renderer/src/components/native-chat/use-native-chat-turn-status.ts b/src/renderer/src/components/native-chat/use-native-chat-turn-status.ts index eb703523dd9..ba90d67b131 100644 --- a/src/renderer/src/components/native-chat/use-native-chat-turn-status.ts +++ b/src/renderer/src/components/native-chat/use-native-chat-turn-status.ts @@ -4,6 +4,7 @@ import { nativeChatTurnHasResponse, reduceNativeChatTurnTiming, selectNativeChatTurnStatuses, + type NativeChatSettledTurn, type NativeChatTurnStatus, type NativeChatTurnTimingByTurn } from '../../../../shared/native-chat-turn-status' @@ -14,12 +15,15 @@ export function useNativeChatTurnStatus({ messages, latestUserIndex, isWorking, - workingStartedAt + workingStartedAt, + settledTurns }: { messages: readonly NativeChatMessage[] latestUserIndex: number isWorking: boolean workingStartedAt?: number | null + /** Host-recorded durations; they outrank whatever this client observed. */ + settledTurns?: ReadonlyMap | null }): { active: NativeChatTurnStatus | null completedByTurn: Readonly> @@ -48,6 +52,7 @@ export function useNativeChatTurnStatus({ activeTurnKey, isWorking, workingStartedAt, - hasCurrentTurnResponse + hasCurrentTurnResponse, + settledByTurn: settledTurns ?? undefined }) } diff --git a/src/renderer/src/components/native-chat/use-structured-agent-session.test.tsx b/src/renderer/src/components/native-chat/use-structured-agent-session.test.tsx index abf185cb913..f81d71a4cfd 100644 --- a/src/renderer/src/components/native-chat/use-structured-agent-session.test.tsx +++ b/src/renderer/src/components/native-chat/use-structured-agent-session.test.tsx @@ -10,6 +10,7 @@ const mocks = vi.hoisted(() => ({ })) let fence = 3 let sessionCommands: { name: string; kind: 'command' | 'skill' }[] | undefined +let items: AgentJournalRenderItem[] = [] vi.mock('@/runtime/structured-agent-session-client', () => ({ callStructuredAgentSession: mocks.call @@ -24,7 +25,7 @@ vi.mock('./use-structured-agent-session-read', () => ({ state: { fence, commands: sessionCommands, - items: [], + items, submissions: [], status: 'ready', error: null, @@ -52,6 +53,7 @@ import { resolveStructuredLaunchSeedOptions } from '../../../../shared/native-chat-session-option-defaults' import type { PersistedNativeChatSessionOptions } from '../../../../shared/native-chat-session-options' +import type { AgentJournalRenderItem } from '../../../../shared/agent-session-journal-types' import { useStructuredAgentSession } from './use-structured-agent-session' /** Replay every host mutation in order, exactly as the runtime does. */ @@ -480,6 +482,84 @@ describe('useStructuredAgentSession options', () => { }) }) +describe('turn timing', () => { + beforeEach(() => { + vi.clearAllMocks() + items = [] + mocks.call.mockImplementation((_target, method) => + method === 'agentSession.options' ? Promise.resolve(OPTIONS) : Promise.resolve(null) + ) + }) + + it('exposes host-settled durations and a skew-free live anchor', () => { + vi.useFakeTimers() + try { + vi.setSystemTime(50_000) + items = [ + { + itemId: 'u1', + revision: 0, + sequence: 1, + observedAt: 9_000_000, + body: { kind: 'message', role: 'user', blocks: [{ type: 'text', text: 'one' }] } + }, + { + itemId: 'l1', + revision: 1, + sequence: 2, + observedAt: 9_000_100, + body: { + kind: 'status', + text: 'Done', + turnLifecycle: { + turnId: 't1', + state: 'completed', + startedAt: 9_000_000, + completedAt: 9_004_000 + } + } + }, + { + itemId: 'u2', + revision: 0, + sequence: 3, + observedAt: 9_010_000, + body: { kind: 'message', role: 'user', blocks: [{ type: 'text', text: 'two' }] } + }, + { + itemId: 'l2', + revision: 1, + sequence: 4, + observedAt: 9_010_300, + body: { + kind: 'status', + text: 'Working', + turnLifecycle: { turnId: 't2', state: 'running', startedAt: 9_010_000 } + } + } + ] + const { result, rerender } = renderHook(() => + useStructuredAgentSession({ + sessionId: 'session-1', + target: LOCAL_TARGET, + agent: 'codex', + isVisible: true + }) + ) + expect(result.current.isWorking).toBe(true) + expect(result.current.workingStartedAt).toBe(50_000 - 300) + expect([...result.current.settledTurns]).toEqual([ + ['u1', { startedAt: 9_000_000, workedSeconds: 4 }] + ]) + vi.setSystemTime(80_000) + rerender() + expect(result.current.workingStartedAt).toBe(50_000 - 300) + } finally { + vi.useRealTimers() + } + }) +}) + describe('session command catalog stream', () => { beforeEach(() => { vi.clearAllMocks() diff --git a/src/renderer/src/components/native-chat/use-structured-agent-session.ts b/src/renderer/src/components/native-chat/use-structured-agent-session.ts index d5980fc90e0..2e901c4abe5 100644 --- a/src/renderer/src/components/native-chat/use-structured-agent-session.ts +++ b/src/renderer/src/components/native-chat/use-structured-agent-session.ts @@ -39,6 +39,7 @@ import { import { useStructuredAgentSessionMessages } from './use-structured-agent-session-messages' import { selectStructuredAgentTurnActivity } from './native-chat-turn-activity' import { enqueueSessionOptionSettingsWrite } from './native-chat-session-option-settings-write' +import { useStructuredAgentTurnTiming } from './use-structured-agent-turn-timing' export type { StructuredPromptItem } from './structured-agent-session-message-projection' @@ -151,6 +152,7 @@ export function useStructuredAgentSession(args: { ) const isMonitoringBackgroundTasks = turnId === null && state.backgroundTasks?.state === 'monitoring' + const turnTiming = useStructuredAgentTurnTiming(state.items, turnId) useEffect(() => { if (!isVisible || !optionCatalog) { @@ -272,6 +274,8 @@ export function useStructuredAgentSession(args: { !commandPending.current && outboxController.send(...input), retry: outboxController.retry, isWorking: turnId !== null, + workingStartedAt: turnTiming.workingStartedAt, + settledTurns: turnTiming.settledTurns, turnActivity, isMonitoringBackgroundTasks, backgroundTasks: state.backgroundTasks?.tasks ?? [], diff --git a/src/renderer/src/components/native-chat/use-structured-agent-turn-timing.test.tsx b/src/renderer/src/components/native-chat/use-structured-agent-turn-timing.test.tsx new file mode 100644 index 00000000000..409c7a657c6 --- /dev/null +++ b/src/renderer/src/components/native-chat/use-structured-agent-turn-timing.test.tsx @@ -0,0 +1,103 @@ +// @vitest-environment happy-dom + +import { renderHook } from '@testing-library/react' +import { afterEach, describe, expect, it, vi } from 'vitest' +import type { AgentJournalRenderItem } from '../../../../shared/agent-session-journal-types' +import { useStructuredAgentTurnTiming } from './use-structured-agent-turn-timing' + +// Host clock sits an hour ahead of the client's so any leak of a host timestamp +// into the local anchor shows up as a huge offset. +const HOST_START = 3_600_000_000 +const CLIENT_NOW = 12_345_000 + +function user(itemId: string, sequence: number): AgentJournalRenderItem { + return { + itemId, + revision: 0, + sequence, + observedAt: HOST_START + sequence, + body: { kind: 'message', role: 'user', blocks: [{ type: 'text', text: itemId }] } + } +} + +function lifecycle( + turnId: string, + sequence: number, + turnLifecycle: Omit< + NonNullable['turnLifecycle']>, + 'turnId' + >, + observedAt: number +): AgentJournalRenderItem { + return { + itemId: `lifecycle-${turnId}`, + revision: 1, + sequence, + observedAt, + body: { kind: 'status', text: 'Working', turnLifecycle: { turnId, ...turnLifecycle } } + } +} + +afterEach(() => { + vi.useRealTimers() +}) + +describe('useStructuredAgentTurnTiming', () => { + it('hands settled host durations through keyed by user message', () => { + const items = [ + user('u1', 1), + lifecycle( + 't1', + 2, + { state: 'completed', startedAt: HOST_START, completedAt: HOST_START + 197_900 }, + HOST_START + 5 + ) + ] + const { result } = renderHook(() => useStructuredAgentTurnTiming(items, null)) + expect(result.current.workingStartedAt).toBeNull() + expect([...result.current.settledTurns]).toEqual([ + ['u1', { startedAt: HOST_START, workedSeconds: 197 }] + ]) + }) + + it('anchors the live counter on the local clock, once per turn, free of host skew', () => { + vi.useFakeTimers() + vi.setSystemTime(CLIENT_NOW) + // The host appended the row 2.5s after it saw the turn start. + const running = [ + user('u1', 1), + lifecycle('t1', 2, { state: 'running', startedAt: HOST_START }, HOST_START + 2_500) + ] + const { result, rerender } = renderHook( + ({ items, turnId }: { items: AgentJournalRenderItem[]; turnId: string | null }) => + useStructuredAgentTurnTiming(items, turnId), + { initialProps: { items: running, turnId: 't1' as string | null } } + ) + expect(result.current.workingStartedAt).toBe(CLIENT_NOW - 2_500) + + vi.setSystemTime(CLIENT_NOW + 30_000) + rerender({ items: [...running], turnId: 't1' }) + expect(result.current.workingStartedAt).toBe(CLIENT_NOW - 2_500) + + rerender({ items: running, turnId: null }) + expect(result.current.workingStartedAt).toBeNull() + + vi.setSystemTime(CLIENT_NOW + 60_000) + const next = [ + ...running, + user('u2', 3), + lifecycle('t2', 4, { state: 'running', startedAt: HOST_START + 50_000 }, HOST_START + 50_100) + ] + rerender({ items: next, turnId: 't2' }) + expect(result.current.workingStartedAt).toBe(CLIENT_NOW + 60_000 - 100) + }) + + it('leaves the anchor null when an older host records no start', () => { + vi.useFakeTimers() + vi.setSystemTime(CLIENT_NOW) + const items = [user('u1', 1), lifecycle('t1', 2, { state: 'running' }, HOST_START)] + const { result } = renderHook(() => useStructuredAgentTurnTiming(items, 't1')) + expect(result.current.workingStartedAt).toBeNull() + expect(result.current.settledTurns.size).toBe(0) + }) +}) diff --git a/src/renderer/src/components/native-chat/use-structured-agent-turn-timing.ts b/src/renderer/src/components/native-chat/use-structured-agent-turn-timing.ts new file mode 100644 index 00000000000..3609fe8eadb --- /dev/null +++ b/src/renderer/src/components/native-chat/use-structured-agent-turn-timing.ts @@ -0,0 +1,45 @@ +import { useMemo, useState } from 'react' +import type { AgentJournalRenderItem } from '../../../../shared/agent-session-journal-types' +import type { NativeChatSettledTurn } from '../../../../shared/native-chat-turn-status' +import { + selectStructuredAgentRunningTurnTiming, + selectStructuredAgentSettledTurns, + structuredAgentTurnLocalStartedAt +} from '../../../../shared/structured-agent-session-turn-timing' + +type TurnAnchor = { turnId: string; startedAt: number | null } + +/** The live turn's local-clock anchor. Null when its row carries no host start + * (older hosts), so local observation applies. */ +function anchorRunningTurn(items: readonly AgentJournalRenderItem[], turnId: string): TurnAnchor { + const timing = selectStructuredAgentRunningTurnTiming(items, turnId) + return { + turnId, + startedAt: timing ? structuredAgentTurnLocalStartedAt(timing, Date.now()) : null + } +} + +/** Host-recorded turn timing for the structured lane: settled durations straight + * off the journal, and a skew-free start for the live counter stamped once per + * turn so re-renders never move it. */ +export function useStructuredAgentTurnTiming( + items: readonly AgentJournalRenderItem[], + turnId: string | null +): { settledTurns: ReadonlyMap; workingStartedAt: number | null } { + const settledTurns = useMemo(() => selectStructuredAgentSettledTurns(items), [items]) + const [anchor, setAnchor] = useState(null) + // Stamp during render (React's derive-from-props pattern) so the first paint of + // a new turn already counts from the right instant. + if (turnId === null) { + if (anchor !== null) { + setAnchor(null) + } + return { settledTurns, workingStartedAt: null } + } + if (anchor?.turnId !== turnId) { + const next = anchorRunningTurn(items, turnId) + setAnchor(next) + return { settledTurns, workingStartedAt: next.startedAt } + } + return { settledTurns, workingStartedAt: anchor.startedAt } +} diff --git a/src/shared/agent-session-journal-schemas.test.ts b/src/shared/agent-session-journal-schemas.test.ts index 93b2b460bb0..c23f7915589 100644 --- a/src/shared/agent-session-journal-schemas.test.ts +++ b/src/shared/agent-session-journal-schemas.test.ts @@ -67,6 +67,16 @@ const CANONICAL_BODIES: AgentJournalItemBody[] = [ text: 'turn', turnLifecycle: { turnId: 'turn-1', state: 'running' }, providerFrame: { provider: 'codex', kind: 'raw', payload: PAYLOAD } + }, + { + kind: 'status', + text: 'turn', + turnLifecycle: { turnId: 'turn-2', state: 'completed', startedAt: 1_000, completedAt: 188_000 } + }, + { + kind: 'status', + text: 'turn', + turnLifecycle: { turnId: 'turn-3', state: 'unverifiable', startedAt: 1_000 } } ] diff --git a/src/shared/agent-session-journal-schemas.ts b/src/shared/agent-session-journal-schemas.ts index 89c2d9f7293..fcafbcf7df6 100644 --- a/src/shared/agent-session-journal-schemas.ts +++ b/src/shared/agent-session-journal-schemas.ts @@ -164,7 +164,14 @@ export const AgentJournalItemBodySchema = z.discriminatedUnion('kind', [ text: z.string(), presentation: z.string().optional(), tone: z.string().optional(), - turnLifecycle: z.object({ turnId: z.string(), state: z.string().min(1) }).optional(), + turnLifecycle: z + .object({ + turnId: z.string(), + state: z.string().min(1), + startedAt: z.number().finite().positive().optional(), + completedAt: z.number().finite().positive().optional() + }) + .optional(), providerFrame: ProviderFrame.optional() }) ]) diff --git a/src/shared/agent-session-journal-types.ts b/src/shared/agent-session-journal-types.ts index c0074e015f5..b721e48c58f 100644 --- a/src/shared/agent-session-journal-types.ts +++ b/src/shared/agent-session-journal-types.ts @@ -145,15 +145,33 @@ export type AgentJournalQuestionItem = { resolution: AgentJournalResolution } +export const AGENT_JOURNAL_TURN_LIFECYCLE_STATES = [ + 'running', + 'completed', + 'interrupted', + 'unverifiable' +] as const +export type AgentJournalTurnLifecycleState = (typeof AGENT_JOURNAL_TURN_LIFECYCLE_STATES)[number] + +export type AgentJournalTurnLifecycle = { + turnId: string + state: AgentJournalTurnLifecycleState + startedAt?: number + completedAt?: number +} + export type AgentJournalStatusItem = { kind: 'status' text: string /** Optional display hints; unknown values retain the ordinary text fallback. */ presentation?: string tone?: string - /** Durable root-turn lifecycle used by clients to expose cancellation only - * while the provider can still accept it. */ - turnLifecycle?: { turnId: string; state: 'running' | 'completed' } + /** Durable root-turn lifecycle. `running` exposes cancellation while the + * provider can still accept it; the item is revised to a terminal state, never + * tombstoned, so the turn's endpoints survive. Timestamps are the execution + * host's clock at provider-event receipt. `unverifiable` carries no end: the + * host lost the child without observing its exit. */ + turnLifecycle?: AgentJournalTurnLifecycle /** Additive fallback for provider traffic this host cannot model yet. Older * clients still render `text`; newer clients expose the bounded frame. */ providerFrame?: { diff --git a/src/shared/native-chat-turn-status.ts b/src/shared/native-chat-turn-status.ts index 1012f8fc604..32655439b46 100644 --- a/src/shared/native-chat-turn-status.ts +++ b/src/shared/native-chat-turn-status.ts @@ -165,19 +165,27 @@ export function reduceNativeChatTurnTiming( } } -/** Split the timing map into the active turn's status and the settled ones. */ +/** A turn duration the execution host recorded, which outranks anything this + * platform observed locally. */ +export type NativeChatSettledTurn = { startedAt: number; workedSeconds: number } + +/** Split the timing map into the active turn's status and the settled ones. + * Host-recorded durations override the locally observed ones per turn; local + * observation remains the floor for hosts that record nothing. */ export function selectNativeChatTurnStatuses( timingByTurn: NativeChatTurnTimingByTurn, { activeTurnKey, isWorking, workingStartedAt, - hasCurrentTurnResponse + hasCurrentTurnResponse, + settledByTurn }: { activeTurnKey: string isWorking: boolean workingStartedAt?: number | null hasCurrentTurnResponse: boolean + settledByTurn?: ReadonlyMap } ): { active: NativeChatTurnStatus | null; completedByTurn: Record } { const completedByTurn = Object.fromEntries( @@ -188,6 +196,13 @@ export function selectNativeChatTurnStatuses( { startedAt: timing.startedAt, thinking: false, workedSeconds: timing.workedSeconds } ]) ) as Record + for (const [turnKey, settled] of settledByTurn ?? []) { + completedByTurn[turnKey] = { + startedAt: settled.startedAt, + thinking: false, + workedSeconds: settled.workedSeconds + } + } return { active: isWorking ? { diff --git a/src/shared/structured-agent-session-turn-timing.test.ts b/src/shared/structured-agent-session-turn-timing.test.ts new file mode 100644 index 00000000000..ddcf6a8e983 --- /dev/null +++ b/src/shared/structured-agent-session-turn-timing.test.ts @@ -0,0 +1,184 @@ +import { describe, expect, it } from 'vitest' +import type { AgentJournalRenderItem } from './agent-session-journal-types' +import { selectNativeChatTurnStatuses } from './native-chat-turn-status' +import { + completedStructuredAgentTurnSeconds, + selectStructuredAgentRunningTurnTiming, + selectStructuredAgentSettledTurns, + selectStructuredAgentTurnTimings, + structuredAgentTurnLocalStartedAt +} from './structured-agent-session-turn-timing' + +let sequence = 0 +function user(itemId: string): AgentJournalRenderItem { + sequence += 1 + return { + itemId, + revision: 0, + sequence, + observedAt: 1_000 + sequence, + body: { kind: 'message', role: 'user', blocks: [{ type: 'text', text: itemId }] } + } +} +function lifecycle( + turnId: string, + lifecycle: Partial< + NonNullable['turnLifecycle'] + >, + observedAt = 1_000 + sequence + 1 +): AgentJournalRenderItem { + sequence += 1 + return { + itemId: `legacy:codex:s:turn-lifecycle%3A${turnId}`, + revision: 1, + sequence, + observedAt, + body: { + kind: 'status', + text: 'Codex is working…', + turnLifecycle: { turnId, state: 'running', ...lifecycle } + } + } +} +function assistant(): AgentJournalRenderItem { + sequence += 1 + return { + itemId: `a${sequence}`, + revision: 0, + sequence, + observedAt: 1_000 + sequence, + body: { kind: 'message', role: 'assistant', blocks: [{ type: 'text', text: 'ok' }] } + } +} + +describe('selectStructuredAgentTurnTimings', () => { + it('keys each timed lifecycle row by the user message that opened the turn', () => { + const items = [ + user('u1'), + lifecycle('t1', { state: 'completed', startedAt: 10_000, completedAt: 197_500 }), + assistant(), + user('u2'), + lifecycle('t2', { state: 'running', startedAt: 300_000 }) + ] + const timings = selectStructuredAgentTurnTimings(items) + expect(timings.get('u1')).toMatchObject({ + state: 'completed', + startedAt: 10_000, + completedAt: 197_500 + }) + expect(timings.get('u2')).toMatchObject({ state: 'running', startedAt: 300_000 }) + expect(timings.get('u2')?.completedAt).toBeUndefined() + }) + + it('skips lifecycle rows that carry no start (older hosts, conversation commands)', () => { + const items = [user('u1'), lifecycle('compact:1', {})] + expect(selectStructuredAgentTurnTimings(items).size).toBe(0) + }) + + it('gives a prompt folded into a running turn no timing of its own', () => { + const items = [ + user('u1'), + lifecycle('t1', { state: 'completed', startedAt: 5_000, completedAt: 9_000 }), + user('u2-steer'), + assistant() + ] + const timings = selectStructuredAgentTurnTimings(items) + expect([...timings.keys()]).toEqual(['u1']) + }) + + it('drops an end that precedes its start', () => { + const items = [ + user('u1'), + lifecycle('t1', { state: 'completed', startedAt: 9_000, completedAt: 5_000 }) + ] + expect(selectStructuredAgentTurnTimings(items).get('u1')?.completedAt).toBeUndefined() + }) +}) + +describe('completedStructuredAgentTurnSeconds', () => { + it('floors whole seconds for completed and interrupted turns', () => { + expect( + completedStructuredAgentTurnSeconds({ + state: 'completed', + startedAt: 1_000, + completedAt: 188_900, + observedAt: 1_000 + }) + ).toBe(187) + expect( + completedStructuredAgentTurnSeconds({ + state: 'interrupted', + startedAt: 1_000, + completedAt: 4_999, + observedAt: 1_000 + }) + ).toBe(3) + }) + + it('claims nothing for running or unverifiable turns', () => { + expect( + completedStructuredAgentTurnSeconds({ state: 'running', startedAt: 1_000, observedAt: 1_000 }) + ).toBeNull() + expect( + completedStructuredAgentTurnSeconds({ + state: 'unverifiable', + startedAt: 1_000, + observedAt: 1_000 + }) + ).toBeNull() + expect(completedStructuredAgentTurnSeconds(undefined)).toBeNull() + }) +}) + +describe('structuredAgentTurnLocalStartedAt', () => { + it('moves the local first sighting back by the host-side append lag only', () => { + const timing = { state: 'running' as const, startedAt: 50_000, observedAt: 52_500 } + // Client clock is 1h ahead of the host: the anchor must not inherit that skew. + expect(structuredAgentTurnLocalStartedAt(timing, 3_600_000 + 60_000)).toBe(3_600_000 + 57_500) + }) + + it('never moves the anchor forward when the row predates its own start', () => { + expect( + structuredAgentTurnLocalStartedAt( + { state: 'running', startedAt: 50_000, observedAt: 40_000 }, + 100 + ) + ).toBe(100) + }) +}) + +describe('host-settled turns override local observation', () => { + it('wins per turn and leaves locally observed turns from an older host intact', () => { + const settled = selectStructuredAgentSettledTurns([ + user('u1'), + lifecycle('t1', { state: 'completed', startedAt: 10_000, completedAt: 197_000 }) + ]) + const statuses = selectNativeChatTurnStatuses( + { u0: { startedAt: 500, workedSeconds: 4 }, u1: { startedAt: 900, workedSeconds: 2 } }, + { + activeTurnKey: 'u1', + isWorking: false, + hasCurrentTurnResponse: true, + settledByTurn: settled + } + ) + expect(statuses.completedByTurn.u1?.workedSeconds).toBe(187) + expect(statuses.completedByTurn.u0?.workedSeconds).toBe(4) + expect(statuses.active?.workedSeconds).toBe(187) + }) +}) + +describe('selectStructuredAgentRunningTurnTiming', () => { + it('finds the live turn by id and returns null for an older host row without a start', () => { + const items = [user('u1'), lifecycle('t1', { state: 'running', startedAt: 7_000 }, 7_250)] + expect(selectStructuredAgentRunningTurnTiming(items, 't1')).toEqual({ + state: 'running', + startedAt: 7_000, + observedAt: 7_250 + }) + expect(selectStructuredAgentRunningTurnTiming(items, 'other')).toBeNull() + expect( + selectStructuredAgentRunningTurnTiming([user('u2'), lifecycle('t2', {})], 't2') + ).toBeNull() + }) +}) diff --git a/src/shared/structured-agent-session-turn-timing.ts b/src/shared/structured-agent-session-turn-timing.ts new file mode 100644 index 00000000000..db6312cbfed --- /dev/null +++ b/src/shared/structured-agent-session-turn-timing.ts @@ -0,0 +1,115 @@ +// Turn timing read straight off durable lifecycle items. The execution host +// stamps both endpoints on its own clock, so a completed value is the same on +// every client and needs no local clock. Shared by desktop and mobile. + +import type { + AgentJournalRenderItem, + AgentJournalTurnLifecycleState +} from './agent-session-journal-types' +import type { NativeChatSettledTurn } from './native-chat-turn-status' + +export type StructuredAgentTurnTiming = { + state: AgentJournalTurnLifecycleState + /** Host clock at provider turn-start receipt. */ + startedAt: number + /** Host clock at the terminal provider event; absent while running or unverifiable. */ + completedAt?: number + /** Host clock when the lifecycle row was appended; with `startedAt` it gives + * the host-side lag a client must subtract to anchor a live counter. */ + observedAt: number +} + +function readTiming(item: AgentJournalRenderItem): StructuredAgentTurnTiming | null { + const body = item.body + if (body.kind !== 'status' || !body.turnLifecycle) { + return null + } + const { state, startedAt, completedAt } = body.turnLifecycle + if (startedAt === undefined || !Number.isFinite(startedAt) || startedAt <= 0) { + return null + } + const end = + completedAt !== undefined && Number.isFinite(completedAt) && completedAt >= startedAt + ? completedAt + : undefined + return { + state, + startedAt, + ...(end !== undefined ? { completedAt: end } : {}), + observedAt: item.observedAt + } +} + +/** Timing keyed by the user message that opened each turn. A lifecycle row + * belongs to the nearest user message before it in journal order — the + * submission row is written ahead of dispatch, so it always precedes the + * provider's turn-start, and a prompt Codex folds into an already-running turn + * correctly claims no timing of its own. Lifecycle rows without `startedAt` + * (older hosts, conversation commands) are skipped. */ +export function selectStructuredAgentTurnTimings( + items: readonly AgentJournalRenderItem[] +): ReadonlyMap { + const timings = new Map() + let userItemId: string | null = null + for (const item of items) { + if (item.body.kind === 'message' && item.body.role === 'user') { + userItemId = item.itemId + continue + } + const timing = readTiming(item) + if (timing && userItemId !== null) { + timings.set(userItemId, timing) + } + } + return timings +} + +/** The live turn's lifecycle timing, or null when its row carries no host start + * (an older host), in which case a surface falls back to local observation. */ +export function selectStructuredAgentRunningTurnTiming( + items: readonly AgentJournalRenderItem[], + turnId: string +): StructuredAgentTurnTiming | null { + for (let index = items.length - 1; index >= 0; index -= 1) { + const item = items[index] + if (item?.body.kind === 'status' && item.body.turnLifecycle?.turnId === turnId) { + return readTiming(item) + } + } + return null +} + +/** Whole seconds a settled turn ran, or null when the host never observed its end. */ +export function completedStructuredAgentTurnSeconds( + timing: StructuredAgentTurnTiming | undefined +): number | null { + return timing && + (timing.state === 'completed' || timing.state === 'interrupted') && + timing.completedAt !== undefined + ? Math.floor((timing.completedAt - timing.startedAt) / 1000) + : null +} + +/** A local-clock anchor for the live counter that carries no host/client skew: + * the client's first sighting of the running row, moved back by the host-side + * lag between turn-start receipt and the row's append. Both terms are single-clock. */ +export function structuredAgentTurnLocalStartedAt( + timing: StructuredAgentTurnTiming, + firstSeenAt: number +): number { + return firstSeenAt - Math.max(0, timing.observedAt - timing.startedAt) +} + +/** The settled turns a chat surface hands to the shared turn-status selector. */ +export function selectStructuredAgentSettledTurns( + items: readonly AgentJournalRenderItem[] +): ReadonlyMap { + const settled = new Map() + for (const [userItemId, timing] of selectStructuredAgentTurnTimings(items)) { + const workedSeconds = completedStructuredAgentTurnSeconds(timing) + if (workedSeconds !== null) { + settled.set(userItemId, { startedAt: timing.startedAt, workedSeconds }) + } + } + return settled +}