diff --git a/apps/mobile/src/components/agents/child-session-sheet.tsx b/apps/mobile/src/components/agents/child-session-sheet.tsx index 010fbeb9c5..433ac83c5c 100644 --- a/apps/mobile/src/components/agents/child-session-sheet.tsx +++ b/apps/mobile/src/components/agents/child-session-sheet.tsx @@ -1,9 +1,10 @@ -import { type ReactNode } from 'react'; +import { useEffect, type ReactNode } from 'react'; import { View } from 'react-native'; import { useSafeAreaInsets } from 'react-native-safe-area-context'; import { useTranslation } from 'react-i18next'; import { type ChildSessionHydrationState, + type KiloSessionId, type OlderMessagesError, type StoredMessage, } from '@kilocode/cloud-agent-sdk'; @@ -12,6 +13,10 @@ import { EmptyState } from '@/components/empty-state'; import { QueryError } from '@/components/query-error'; import { SheetHeader } from '@/components/sheet-header'; import { Bot } from '@/components/ui/icons'; +import { + markChildFirstContent, + takeChildSessionOpenTiming, +} from '@/lib/child-session-open-timing'; import { type SessionModelOption } from '@/lib/hooks/use-session-model-options'; import { @@ -83,6 +88,15 @@ export function ChildSessionSheet({ const sheetBottomInset = Math.max(insets.bottom, 16); let content: ReactNode = null; + useEffect(() => { + if (state !== 'content') return; + markChildFirstContent(sessionId as KiloSessionId); + const timing = takeChildSessionOpenTiming(); + if (timing) { + console.debug('child_session_open', timing); + } + }, [state, sessionId]); + if (state === 'content') { content = ( { cacheFilePart(partId, file); }, + onChildSessionOpenTiming: ({ childSessionId, networkMs, storageMs }) => { + setChildOpenPhases(childSessionId, networkMs, storageMs); + }, resolveSession: async (kiloSessionId: KiloSessionId): Promise => { // Read-only is only ever returned once we have successful evidence the // session isn't cloud-agent or remote. A failed query here must diff --git a/apps/mobile/src/components/agents/session-detail-content.tsx b/apps/mobile/src/components/agents/session-detail-content.tsx index 027b1f7b04..aa42d8a003 100644 --- a/apps/mobile/src/components/agents/session-detail-content.tsx +++ b/apps/mobile/src/components/agents/session-detail-content.tsx @@ -120,6 +120,7 @@ import { SESSION_VIEWED_EVENT, } from '@/lib/analytics/posthog'; import { moveA11yFocus } from '@/lib/a11y/announce'; +import { markChildOpenStart } from '@/lib/child-session-open-timing'; import { useAvailableModels } from '@/lib/hooks/use-available-models'; import { useCurrentUserId } from '@/lib/hooks/use-current-user-id'; import { useModelPreferences } from '@/lib/hooks/use-model-preferences'; @@ -635,6 +636,7 @@ export function SessionDetailContent({ const handleOpenChildSession = useCallback( (childSessionId: KiloSessionId, childTitle: string) => { + markChildOpenStart(childSessionId); clearChildSheetReleaseTimeout(); setChildSessionSheet(current => openChildSessionSheet(current, { sessionId: childSessionId, title: childTitle }) diff --git a/apps/mobile/src/lib/child-session-open-timing.test.ts b/apps/mobile/src/lib/child-session-open-timing.test.ts new file mode 100644 index 0000000000..b2564db9a5 --- /dev/null +++ b/apps/mobile/src/lib/child-session-open-timing.test.ts @@ -0,0 +1,96 @@ +import { afterEach, describe, expect, it, vi } from 'vitest'; + +import { type KiloSessionId } from '@kilocode/cloud-agent-sdk'; + +import type * as ChildSessionOpenTimingModule from './child-session-open-timing'; + +async function freshTiming(): Promise { + vi.resetModules(); + const mod = import('./child-session-open-timing'); + // satisfy require-await without return-await + await Promise.resolve(); + return mod; +} + +describe('child-session-open-timing', () => { + afterEach(() => { + vi.useRealTimers(); + }); + + it('reports the fresh-open phase math: tap, network, storage, and render', async () => { + vi.useFakeTimers(); + vi.setSystemTime(new Date('2024-01-01T00:00:00.000Z')); + + const { markChildOpenStart, markChildFirstContent, setChildOpenPhases, takeChildSessionOpenTiming } = + await freshTiming(); + + markChildOpenStart('child-1' as KiloSessionId); + vi.advanceTimersByTime(50); + setChildOpenPhases('child-1' as KiloSessionId, 50, 30); + vi.advanceTimersByTime(100); + markChildFirstContent('child-1' as KiloSessionId); + + const timing = takeChildSessionOpenTiming(); + expect(timing).toEqual({ + tapToFirstContentMs: 150, + networkMs: 50, + storageMs: 30, + renderMs: 70, + phase: 'fresh', + }); + }); + + it('reports a cached open with no network/storage and phase cached', async () => { + vi.useFakeTimers(); + vi.setSystemTime(new Date('2024-01-01T00:00:00.000Z')); + + const { markChildOpenStart, markChildFirstContent, takeChildSessionOpenTiming } = + await freshTiming(); + + markChildOpenStart('child-2' as KiloSessionId); + vi.advanceTimersByTime(200); + markChildFirstContent('child-2' as KiloSessionId); + + expect(takeChildSessionOpenTiming()).toEqual({ + tapToFirstContentMs: 200, + networkMs: 0, + storageMs: 0, + renderMs: 200, + phase: 'cached', + }); + }); + + it('returns null before first content and is taken exactly once', async () => { + vi.useFakeTimers(); + vi.setSystemTime(new Date('2024-01-01T00:00:00.000Z')); + + const { markChildOpenStart, markChildFirstContent, takeChildSessionOpenTiming } = + await freshTiming(); + + markChildOpenStart('child-3' as KiloSessionId); + expect(takeChildSessionOpenTiming()).toBeNull(); + + markChildFirstContent('child-3' as KiloSessionId); + const first = takeChildSessionOpenTiming(); + expect(first).not.toBeNull(); + + expect(takeChildSessionOpenTiming()).toBeNull(); + }); + + it('ignores marks from a superseded open', async () => { + vi.useFakeTimers(); + vi.setSystemTime(new Date('2024-01-01T00:00:00.000Z')); + + const { markChildOpenStart, markChildFirstContent, setChildOpenPhases, takeChildSessionOpenTiming } = + await freshTiming(); + + markChildOpenStart('child-a' as KiloSessionId); + markChildOpenStart('child-b' as KiloSessionId); + + // Late marks for the superseded session must not corrupt the current open. + setChildOpenPhases('child-a' as KiloSessionId, 999, 999); + markChildFirstContent('child-a' as KiloSessionId); + + expect(takeChildSessionOpenTiming()).toBeNull(); + }); +}); diff --git a/apps/mobile/src/lib/child-session-open-timing.ts b/apps/mobile/src/lib/child-session-open-timing.ts new file mode 100644 index 0000000000..a111ea14e2 --- /dev/null +++ b/apps/mobile/src/lib/child-session-open-timing.ts @@ -0,0 +1,71 @@ +// One-shot child-session open timing, modelled on `startup-timing`. The tap +// (markChildOpenStart) opens the clock; markChildFirstContent closes it when +// the sheet first shows content; setChildOpenPhases records the SDK-reported +// network/storage cost when the hydrate completes. `takeChildSessionOpenTiming` +// returns the payload exactly once per open, or null when no content arrived +// yet or the payload was already taken. +// +// `phase` is `fresh` when the SDK completed a hydrate (setChildOpenPhases ran) +// and `cached` when content was already in the store and no fetch happened. + +import { type KiloSessionId } from '@kilocode/cloud-agent-sdk'; + +export type ChildSessionOpenTiming = { + /** Tap to first rendered content, in milliseconds. */ + tapToFirstContentMs: number; + networkMs: number; + storageMs: number; + renderMs: number; + phase: 'fresh' | 'cached'; +}; + +type ChildOpenRecord = { + sessionId: KiloSessionId; + startMs: number; + networkMs?: number; + storageMs?: number; + firstContentMs?: number; +}; + +// Only the open sheet is measured at a time; the last open wins. +let current: ChildOpenRecord | undefined = undefined; +let taken = false; + +export function markChildOpenStart(sessionId: KiloSessionId): void { + current = { sessionId, startMs: Date.now() }; + taken = false; +} + +export function markChildFirstContent(sessionId: KiloSessionId): void { + if (!current || current.sessionId !== sessionId || current.firstContentMs !== undefined) return; + current.firstContentMs = Date.now(); +} + +export function setChildOpenPhases( + sessionId: KiloSessionId, + networkMs: number, + storageMs: number +): void { + if (!current || current.sessionId !== sessionId) return; + current.networkMs = networkMs; + current.storageMs = storageMs; +} + +// Returns the event payload exactly once per open, and only after first +// content actually rendered. Null means "nothing to send" — never send a +// partial open, and never send twice. Callers may poll this freely. +export function takeChildSessionOpenTiming(): ChildSessionOpenTiming | null { + if (taken || !current || current.firstContentMs === undefined) return null; + taken = true; + const { startMs, firstContentMs, networkMs, storageMs } = current; + const tapToFirstContentMs = firstContentMs - startMs; + const network = networkMs ?? 0; + const storage = storageMs ?? 0; + return { + tapToFirstContentMs, + networkMs: network, + storageMs: storage, + renderMs: Math.max(0, tapToFirstContentMs - network - storage), + phase: networkMs === undefined ? 'cached' : 'fresh', + }; +} diff --git a/apps/web/src/components/cloud-agent-next/ChildSessionDrawer.tsx b/apps/web/src/components/cloud-agent-next/ChildSessionDrawer.tsx index 2892848676..91926c9588 100644 --- a/apps/web/src/components/cloud-agent-next/ChildSessionDrawer.tsx +++ b/apps/web/src/components/cloud-agent-next/ChildSessionDrawer.tsx @@ -67,6 +67,7 @@ export function ChildSessionDrawer({ ? getChildSessionHydrationState(selectedSessionId) : IDLE_HYDRATION_STATE; const previousStackDepthRef = useRef(stack.length); + const firstContentMarkedSessionRef = useRef(null); const backButtonRef = useRef(null); const headingFocusRef = useRef(null); const scrollContainerRef = useRef(null); @@ -159,9 +160,23 @@ export function ChildSessionDrawer({ useEffect(() => { if (!selectedSessionId) return; + performance.mark(`child-open-${selectedSessionId}`); void manager.hydrateChildSession(selectedSessionId); }, [manager, selectedSessionId]); + useEffect(() => { + if (!selectedSessionId) return; + if (hydrationState.status !== 'ready' || messages.length === 0) return; + if (firstContentMarkedSessionRef.current === selectedSessionId) return; + firstContentMarkedSessionRef.current = selectedSessionId; + performance.mark(`child-first-content-${selectedSessionId}`); + performance.measure( + `child-open-${selectedSessionId}`, + `child-open-${selectedSessionId}`, + `child-first-content-${selectedSessionId}` + ); + }, [hydrationState.status, messages.length, selectedSessionId]); + useEffect(() => { if (!shouldAutoScroll) return; scheduleScrollToBottom(); diff --git a/apps/web/src/components/cloud-agent-next/CloudAgentProvider.tsx b/apps/web/src/components/cloud-agent-next/CloudAgentProvider.tsx index 603b39c7ed..5a0e627a8e 100644 --- a/apps/web/src/components/cloud-agent-next/CloudAgentProvider.tsx +++ b/apps/web/src/components/cloud-agent-next/CloudAgentProvider.tsx @@ -346,6 +346,29 @@ export function CloudAgentProvider({ children, organizationId }: CloudAgentProvi kilo_session_id: kiloSessionId, }); }, + onChildSessionOpenTiming: ({ childSessionId, networkMs, storageMs }) => { + // The first-content mark lands after React commits the ready state, so + // defer one frame and read the open measure the drawer created. + const emit = () => { + const openEntry = performance + .getEntriesByName(`child-open-${childSessionId}`, 'measure') + .at(-1); + const renderMs = openEntry + ? Math.max(0, openEntry.duration - networkMs - storageMs) + : 0; + posthogRef.current?.capture('child_session_open', { + child_session_id: childSessionId, + network_ms: networkMs, + storage_ms: storageMs, + render_ms: renderMs, + }); + }; + if (typeof requestAnimationFrame === 'function') { + requestAnimationFrame(emit); + } else { + emit(); + } + }, }); } diff --git a/packages/cloud-agent-sdk/src/session-manager.test.ts b/packages/cloud-agent-sdk/src/session-manager.test.ts index 6cacfc1746..5227632d72 100644 --- a/packages/cloud-agent-sdk/src/session-manager.test.ts +++ b/packages/cloud-agent-sdk/src/session-manager.test.ts @@ -2857,6 +2857,60 @@ describe('createSessionManager', () => { }); }); + it('reports child-session open timing to the config sink once per hydrate', async () => { + const childMessage = createStoredMessage('msg-child-timing', 'child-timing', 'assistant'); + const childPart = stubTextPart({ + id: 'part-child-timing', + sessionID: 'child-timing', + messageID: childMessage.info.id, + text: 'Timed child message', + }); + const onChildSessionOpenTiming = jest.fn() as jest.MockedFunction< + NonNullable + >; + const config = createMockConfig({ + fetchSnapshot: jest.fn().mockResolvedValue( + makeSnapshot({ id: 'child-timing', parentID: 'ses-root' }, [ + { info: childMessage.info, parts: [childPart] }, + ]) + ), + onChildSessionOpenTiming, + }); + const mgr = createSessionManager(config); + + await mgr.switchSession(kiloId('ses-root')); + await mgr.hydrateChildSession(kiloId('child-timing')); + + expect(onChildSessionOpenTiming).toHaveBeenCalledTimes(1); + const timing = onChildSessionOpenTiming.mock.calls[0]?.[0]; + expect(timing?.childSessionId).toBe(kiloId('child-timing')); + expect(timing?.networkMs).toBeGreaterThanOrEqual(0); + expect(timing?.storageMs).toBeGreaterThanOrEqual(0); + expect(timing?.phase).toBe('fresh'); + }); + + it('does not fail hydration when the timing sink throws', async () => { + const onChildSessionOpenTiming = jest.fn().mockImplementation(() => { + throw new Error('timing sink failure'); + }) as jest.MockedFunction>; + const config = createMockConfig({ + fetchSnapshot: jest + .fn() + .mockResolvedValue(makeSnapshot({ id: 'child-sink-throw', parentID: 'ses-root' })), + onChildSessionOpenTiming, + }); + const mgr = createSessionManager(config); + + await mgr.switchSession(kiloId('ses-root')); + await mgr.hydrateChildSession(kiloId('child-sink-throw')); + + const state = atomValue<(childSessionId: string) => { status: string }>( + config.store, + mgr.atoms.childSessionHydrationState + ); + expect(state('child-sink-throw')).toEqual(expect.objectContaining({ status: 'ready' })); + }); + it('merges fetched history into live child messages without duplicating them', async () => { const childMessage = createStoredMessage('msg-child-live', 'child-live', 'assistant'); const livePart = stubTextPart({ diff --git a/packages/cloud-agent-sdk/src/session-manager.ts b/packages/cloud-agent-sdk/src/session-manager.ts index babb25df39..6bd3e1a4bc 100644 --- a/packages/cloud-agent-sdk/src/session-manager.ts +++ b/packages/cloud-agent-sdk/src/session-manager.ts @@ -317,6 +317,21 @@ type SessionManagerConfig = { * preview the file later (e.g. mobile). Web never passes it. */ onFilePart?: (partId: string, file: { mime: string; filename?: string; url: string }) => void; + /** + * Optional measurement sink for child-session open latency. Called exactly + * once per completed hydrate with wall-clock milliseconds for the network + * fetch and the storage replay. Consumers use it to record tap-to-first- + * content timing (mobile) or emit a PostHog event (web). `phase` is `fresh` + * for a cold open that fetched from the network and `cached` when the child + * already had messages in storage. The sink is advisory: a throwing sink + * never fails a hydrate. + */ + onChildSessionOpenTiming?: (timing: { + childSessionId: KiloSessionId; + networkMs: number; + storageMs: number; + phase: 'fresh' | 'cached'; + }) => void; onRemoteSessionOpened?: (data: { kiloSessionId: KiloSessionId }) => void; onRemoteSessionMessageSent?: (data: { kiloSessionId: KiloSessionId }) => void; }; @@ -1030,6 +1045,25 @@ function createSessionManager(config: SessionManagerConfig): SessionManager { } } + function reportChildSessionOpenTiming( + childSessionId: KiloSessionId, + networkMs: number, + storageMs: number, + hadCachedMessages: boolean + ): void { + if (!config.onChildSessionOpenTiming) return; + try { + config.onChildSessionOpenTiming({ + childSessionId, + networkMs, + storageMs, + phase: hadCachedMessages ? 'cached' : 'fresh', + }); + } catch { + // Measurement sinks are advisory; a throwing sink must never fail a hydrate. + } + } + async function hydrateChildSession(childSessionId: KiloSessionId): Promise { const existingState = store.get(childSessionHydrationStatesAtom).get(childSessionId); if (existingState?.status === 'ready') return; @@ -1045,12 +1079,15 @@ function createSessionManager(config: SessionManagerConfig): SessionManager { if (!storage || !rootSessionId) return; const generation = childSessionHydrationGeneration; + const hadCachedMessages = store.get(childMessagesAtom)(childSessionId).length > 0; setChildSessionHydrationState(childSessionId, { status: 'loading' }); const request = (async () => { try { if (config.fetchSnapshotPage) { + const networkStart = Date.now(); const page = await config.fetchSnapshotPage(childSessionId, {}); + const networkMs = Date.now() - networkStart; if (!isCurrentChildSessionHydration(generation, rootSessionId, storage)) return; // A null page (worker 404) or any typed failure on the first page is @@ -1070,7 +1107,9 @@ function createSessionManager(config: SessionManagerConfig): SessionManager { return; } + const storageStart = Date.now(); replayChildMessages(storage, page.messages); + const storageMs = Date.now() - storageStart; setChildSessionHydrationState(childSessionId, { status: 'ready', cursor: page.nextCursor, @@ -1079,14 +1118,19 @@ function createSessionManager(config: SessionManagerConfig): SessionManager { olderError: null, omittedItemCount: page.omittedItemCount, }); + reportChildSessionOpenTiming(childSessionId, networkMs, storageMs, hadCachedMessages); return; } // Legacy fallback: full snapshot, no pagination state. + const networkStart = Date.now(); const snapshot = await config.fetchSnapshot(childSessionId); + const networkMs = Date.now() - networkStart; if (!isCurrentChildSessionHydration(generation, rootSessionId, storage)) return; + const storageStart = Date.now(); replayChildMessages(storage, snapshot.messages); + const storageMs = Date.now() - storageStart; setChildSessionHydrationState(childSessionId, { status: 'ready', cursor: null, @@ -1095,6 +1139,7 @@ function createSessionManager(config: SessionManagerConfig): SessionManager { olderError: null, omittedItemCount: 0, }); + reportChildSessionOpenTiming(childSessionId, networkMs, storageMs, hadCachedMessages); } catch (err) { if (!isCurrentChildSessionHydration(generation, rootSessionId, storage)) return; setChildSessionHydrationState(childSessionId, {