diff --git a/frontend/src/components/HydrationTimingPanel.tsx b/frontend/src/components/HydrationTimingPanel.tsx index 47eba42d..087bfd1c 100644 --- a/frontend/src/components/HydrationTimingPanel.tsx +++ b/frontend/src/components/HydrationTimingPanel.tsx @@ -30,12 +30,13 @@ const POSITION_CLASS = * Developer-mode-only overlay for startup and stack-hydration timing. * * Mount this only when developer mode is on for the active node; it does not - * gate itself. It shows a collapsed chip with the boot-to-`list_visible` - * elapsed time, expanding to a phase table with copy/clear actions. It sits - * below toasts and modals and never covers the mobile tab bar or safe area. + * gate itself. It shows a collapsed chip with the foreground (attempt- or + * session-relative) `list_visible` elapsed time and its anchor, expanding to a + * phase table with copy/clear actions. It sits below toasts and modals and + * never covers the mobile tab bar or safe area. */ export function HydrationTimingPanel() { - const { listVisibleMs } = useHydrationTiming(); + const { listVisibleMs, listAnchor } = useHydrationTiming(); const [expanded, setExpanded] = useState(false); useEffect(() => { @@ -47,7 +48,10 @@ export function HydrationTimingPanel() { return () => window.removeEventListener('keydown', onKey); }, [expanded]); - const chipLabel = listVisibleMs == null ? 'list …' : `list ${formatMs(listVisibleMs)}`; + const chipLabel = + listVisibleMs == null + ? 'list …' + : `list ${formatMs(listVisibleMs)} · ${listAnchor}`; const handleCopy = useCallback(async () => { try { @@ -98,6 +102,16 @@ export function HydrationTimingPanel() { {chipLabel} +
+ + Boot age {formatOffset(report.bootAgeMs)} + + + Session age{' '} + {formatOffset(report.sessionAgeMs)} + +
+
diff --git a/frontend/src/components/__tests__/HydrationTimingPanel.test.tsx b/frontend/src/components/__tests__/HydrationTimingPanel.test.tsx index 1c7c211c..1b873e54 100644 --- a/frontend/src/components/__tests__/HydrationTimingPanel.test.tsx +++ b/frontend/src/components/__tests__/HydrationTimingPanel.test.tsx @@ -4,10 +4,15 @@ import type { HydrationReport, HydrationSnapshot } from '@/lib/hydrationTiming'; let mockSnapshot: HydrationSnapshot; let mockListVisibleMs: number | null; +let mockListAnchor: 'attempt' | 'session' | null; let mockReport: HydrationReport; vi.mock('@/hooks/useHydrationTiming', () => ({ - useHydrationTiming: () => ({ snapshot: mockSnapshot, listVisibleMs: mockListVisibleMs }), + useHydrationTiming: () => ({ + snapshot: mockSnapshot, + listVisibleMs: mockListVisibleMs, + listAnchor: mockListAnchor, + }), })); const clearReportMock = vi.fn(); @@ -23,25 +28,39 @@ import { HydrationTimingPanel } from '../HydrationTimingPanel'; function snapshot(events: HydrationSnapshot['events'] = []): HydrationSnapshot { return { - schemaVersion: 1, clock: 'performance.now', bootSessionId: 'boot-1', bootStartAt: 0, nodeSessionId: 'node-2', nodeId: 1, + nodeSessionStartAt: 0, + lastAttempt: null, events, }; } function report(over: Partial = {}): HydrationReport { return { - schemaVersion: 1, + schemaVersion: 2, capturedAt: 0, clock: 'performance.now', bootSessionId: 'boot-1', nodeSessionId: 'node-2', nodeId: 1, listVisibleMs: 1200, + bootAgeMs: 620000, + bootAuthResolvedMs: 200, + bootNodesResolvedMs: 400, + bootShellCommittedMs: 500, + sessionAgeMs: 4200, + sessionListVisibleMs: 1200, + sessionListHydratedMs: 1500, + lastAttemptId: 'attempt-1', + lastAttemptListVisibleMs: 420, + lastAttemptListHydratedMs: 700, + lastAttemptHydrationGapMs: 280, + lastAttemptProxied: null, + lastAttemptNodeId: null, anyProxied: false, phases: [ { phase: 'boot_start', kind: 'milestone', offsetMs: 0, critical: true, outcome: 'ok' }, @@ -55,18 +74,27 @@ beforeEach(() => { clearReportMock.mockClear(); copyMock.mockClear(); mockSnapshot = snapshot(); - mockListVisibleMs = 1200; + mockListVisibleMs = 420; + mockListAnchor = 'attempt'; mockReport = report(); }); describe('HydrationTimingPanel', () => { - it('shows the list_visible elapsed time on the collapsed chip', () => { + it('shows the foreground list_visible elapsed time and its anchor on the collapsed chip', () => { render(); - expect(screen.getByTestId('hydration-chip')).toHaveTextContent('list 1.2s'); + expect(screen.getByTestId('hydration-chip')).toHaveTextContent('list 420ms · attempt'); + }); + + it('shows the session anchor when no foreground attempt exists', () => { + mockListAnchor = 'session'; + mockListVisibleMs = 100; + render(); + expect(screen.getByTestId('hydration-chip')).toHaveTextContent('list 100ms · session'); }); it('shows an ellipsis before list_visible commits', () => { mockListVisibleMs = null; + mockListAnchor = null; render(); expect(screen.getByTestId('hydration-chip')).toHaveTextContent('list …'); }); @@ -83,6 +111,13 @@ describe('HydrationTimingPanel', () => { expect(screen.getByTestId('hydration-chip')).toBeInTheDocument(); }); + it('shows boot age and session age as context alongside the chip', () => { + render(); + fireEvent.click(screen.getByTestId('hydration-chip')); + expect(screen.getByText(/Boot age/)).toHaveTextContent('620.0s'); + expect(screen.getByText(/Session age/)).toHaveTextContent('4.2s'); + }); + it('collapses on Escape', () => { render(); fireEvent.click(screen.getByTestId('hydration-chip')); diff --git a/frontend/src/hooks/__tests__/useHydrationTiming.test.tsx b/frontend/src/hooks/__tests__/useHydrationTiming.test.tsx new file mode 100644 index 00000000..a24f7589 --- /dev/null +++ b/frontend/src/hooks/__tests__/useHydrationTiming.test.tsx @@ -0,0 +1,62 @@ +import { describe, it, expect, vi } from 'vitest'; +import { renderHook, waitFor } from '@testing-library/react'; + +type Store = typeof import('../../lib/hydrationTiming'); + +/** Fresh module instance so the module-scoped store starts clean. */ +async function loadStore(): Promise { + vi.resetModules(); + return import('../../lib/hydrationTiming'); +} + +describe('useHydrationTiming', () => { + it('stays stable without new events (no store emit)', async () => { + await loadStore(); + const { useHydrationTiming } = await import('../useHydrationTiming'); + const { result } = renderHook(() => useHydrationTiming()); + + expect(result.current.listVisibleMs).toBeNull(); + expect(result.current.listAnchor).toBeNull(); + const firstSnapshot = result.current.snapshot; + + // No store mutation, so no coalesced emit: the snapshot identity and chip + // value must remain stable over time. + await new Promise((resolve) => setTimeout(resolve, 300)); + expect(result.current.snapshot).toBe(firstSnapshot); + expect(result.current.listVisibleMs).toBeNull(); + expect(result.current.listAnchor).toBeNull(); + }); + + it('re-renders with the attempt anchor when a list attempt commits while mounted', async () => { + const store = await loadStore(); + const { useHydrationTiming } = await import('../useHydrationTiming'); + const { result } = renderHook(() => useHydrationTiming()); + expect(result.current.listAnchor).toBeNull(); + + store.beginNodeSession(1); + const a = store.newAttemptId(); + store.commitMilestone('list_visible', a); + + await waitFor(() => expect(result.current.listAnchor).toBe('attempt')); + expect(result.current.listVisibleMs).not.toBeNull(); + }); + + it('falls back to the session anchor when no foreground attempt exists', async () => { + const store = await loadStore(); + store.beginNodeSession(1); + const a = store.newAttemptId(); + store.commitMilestone('list_visible', a); + for (let i = 0; i < 200; i++) store.newAttemptId(); // evict `a` from the attempt map + + // Wait for a coalesced emit to rebuild the snapshot with the session + // anchor; the initial snapshot already has lastAttempt null. + await waitFor(() => { + expect(store.getSnapshot().nodeSessionStartAt).not.toBeNull(); + expect(store.getSnapshot().lastAttempt).toBeNull(); + }); + const { useHydrationTiming } = await import('../useHydrationTiming'); + const { result } = renderHook(() => useHydrationTiming()); + expect(result.current.listAnchor).toBe('session'); + expect(result.current.listVisibleMs).not.toBeNull(); + }); +}); diff --git a/frontend/src/hooks/useHydrationTiming.ts b/frontend/src/hooks/useHydrationTiming.ts index 34a52bf8..b2932cca 100644 --- a/frontend/src/hooks/useHydrationTiming.ts +++ b/frontend/src/hooks/useHydrationTiming.ts @@ -1,21 +1,49 @@ import { useSyncExternalStore } from 'react'; -import { subscribe, getSnapshot, listVisibleMsFrom } from '@/lib/hydrationTiming'; +import { + subscribe, + getSnapshot, + getAttemptListVisibleMsFrom, + getSessionListVisibleMsFrom, +} from '@/lib/hydrationTiming'; import type { HydrationSnapshot } from '@/lib/hydrationTiming'; -export interface UseHydrationTiming { - snapshot: HydrationSnapshot; - /** Elapsed ms from boot to `list_visible`, or null before it commits. */ - listVisibleMs: number | null; +/** Chip readout: the foreground list hydration latency plus the anchor it was + * resolved against. The union keeps `listAnchor` non-null exactly when + * `listVisibleMs` is non-null. */ +type ListReadout = + | { listVisibleMs: number; listAnchor: 'attempt' | 'session' } + | { listVisibleMs: null; listAnchor: null }; + +type UseHydrationTiming = { snapshot: HydrationSnapshot } & ListReadout; + +/** Derive the chip readout from the snapshot React last read, not live store + * state, so the chip stays consistent with the events on screen. */ +function deriveListReadout(snapshot: HydrationSnapshot): ListReadout { + const foreground = snapshot.lastAttempt; + if (foreground != null) { + const attemptMs = getAttemptListVisibleMsFrom( + snapshot.events, + foreground.attemptId, + foreground.createdAt, + ); + if (attemptMs != null) return { listVisibleMs: attemptMs, listAnchor: 'attempt' }; + } + const sessionMs = getSessionListVisibleMsFrom( + snapshot.events, + snapshot.nodeSessionId, + snapshot.nodeSessionStartAt, + ); + return sessionMs == null + ? { listVisibleMs: null, listAnchor: null } + : { listVisibleMs: sessionMs, listAnchor: 'session' }; } /** Subscribe to the hydration timing store and expose the current snapshot - * plus the derived `list_visible` elapsed time for the collapsed chip. - * Derives from the snapshot React last read so the chip stays consistent - * with the events on screen, not a later live store mutation. */ + * plus the derived foreground `list_visible` elapsed time for the collapsed + * chip: attempt-relative when a foreground attempt exists, otherwise + * session-relative, never boot-relative, so a node switch minutes after boot + * cannot present page age as hydration time. */ export function useHydrationTiming(): UseHydrationTiming { const snapshot = useSyncExternalStore(subscribe, getSnapshot, getSnapshot); - return { - snapshot, - listVisibleMs: listVisibleMsFrom(snapshot.events, snapshot.bootStartAt), - }; + return { snapshot, ...deriveListReadout(snapshot) }; } diff --git a/frontend/src/lib/__tests__/hydrationTiming.test.ts b/frontend/src/lib/__tests__/hydrationTiming.test.ts index 2f31185f..4f1f742c 100644 --- a/frontend/src/lib/__tests__/hydrationTiming.test.ts +++ b/frontend/src/lib/__tests__/hydrationTiming.test.ts @@ -22,6 +22,14 @@ function stubClock(getT: () => number): void { }); } +/** Push 250 span pairs so the oldest events evict past the 200-event cap. */ +function evictOldestEvents(store: Store): void { + for (let i = 0; i < 250; i++) { + const handle = store.beginSpan('fetch_headers'); + store.endSpan(handle); + } +} + afterEach(() => { vi.unstubAllGlobals(); vi.restoreAllMocks(); @@ -43,10 +51,7 @@ describe('hydrationTiming store', () => { it('evicts the oldest events beyond the 200-event cap (FIFO)', async () => { const store = await loadStore(); - for (let i = 0; i < 250; i++) { - const handle = store.beginSpan('fetch_headers'); - store.endSpan(handle); - } + evictOldestEvents(store); const report = store.getHydrationReport(); expect(report.phases).toHaveLength(200); // boot_start was the very first event, so it has been evicted. @@ -112,7 +117,7 @@ describe('hydrationTiming store', () => { expect(phases).not.toContain('list_visible'); }); - it('reports list_visible elapsed from boot_start', async () => { + it('reports list_visible elapsed from boot_start (compat) and session/attempt anchors', async () => { let t = 0; const store = await loadStore(() => stubClock(() => t)); t = 1200; @@ -120,7 +125,11 @@ describe('hydrationTiming store', () => { const a = store.newAttemptId(); store.commitMilestone('list_visible', a); expect(store.getListVisibleMs()).toBe(1200); - expect(store.getHydrationReport().listVisibleMs).toBe(1200); + const report = store.getHydrationReport(); + expect(report.listVisibleMs).toBe(1200); + expect(report.schemaVersion).toBe(2); + expect(report.sessionListVisibleMs).toBe(0); + expect(report.lastAttemptListVisibleMs).toBe(0); }); it('returns null list_visible timing before it commits', async () => { @@ -182,4 +191,282 @@ describe('hydrationTiming store', () => { expect(after.events.some((e) => e.phase === 'auth_resolved')).toBe(true); unsubscribe(); }); + + it('reports a late node-session list_visible relative to the session, not boot', async () => { + let t = 0; + const store = await loadStore(() => stubClock(() => t)); + t = 600_000; // page has been alive for ten minutes before the node session + store.beginNodeSession(1); + const a = store.newAttemptId(); + t = 600_010; + store.commitMilestone('list_visible', a); + const report = store.getHydrationReport(); + // The foreground hydration duration is 10 ms, never the 600 s boot age. + expect(report.lastAttemptListVisibleMs).toBe(10); + expect(report.sessionListVisibleMs).toBe(10); + expect(report.bootAgeMs).toBe(600_010); + expect(report.listVisibleMs).toBe(600_010); // raw boot-relative compat field + }); + + it('keeps a stack-detail attempt from stealing the foreground list attempt', async () => { + let t = 0; + const store = await loadStore(() => stubClock(() => t)); + store.beginNodeSession(1); + t = 10; + const listAttempt = store.newAttemptId(); + t = 50; + store.commitMilestone('list_visible', listAttempt); + t = 60; + const detailAttempt = store.newAttemptId(); // never commits list_visible + const report = store.getHydrationReport(); + expect(report.lastAttemptId).toBe(listAttempt); + expect(report.lastAttemptId).not.toBe(detailAttempt); + expect(report.lastAttemptListVisibleMs).toBe(40); + }); + + it('leaves lastAttemptListHydratedMs null until the foreground attempt hydrates', async () => { + const store = await loadStore(); + store.beginNodeSession(1); + const a = store.newAttemptId(); + store.commitMilestone('list_visible', a); + const report = store.getHydrationReport(); + expect(report.lastAttemptId).toBe(a); + expect(report.lastAttemptListVisibleMs).not.toBeNull(); + expect(report.lastAttemptListHydratedMs).toBeNull(); + expect(report.lastAttemptHydrationGapMs).toBeNull(); + }); + + it('never reports a superseded attempt as the foreground attempt', async () => { + const store = await loadStore(); + store.beginNodeSession(1); + const a = store.newAttemptId(); + store.commitMilestone('list_visible', a); + store.beginNodeSession(2); // supersedes session 1 and prunes its events + const report = store.getHydrationReport(); + expect(report.lastAttemptId).toBeNull(); + expect(report.lastAttemptListVisibleMs).toBeNull(); + }); + + it('never reports an aborted attempt as the foreground attempt', async () => { + const store = await loadStore(); + store.beginNodeSession(1); + const a = store.newAttemptId(); + store.commitMilestone('list_visible', a); + store.abortAttempt(a); + const report = store.getHydrationReport(); + expect(report.lastAttemptId).toBeNull(); + expect(report.lastAttemptListVisibleMs).toBeNull(); + }); + + it('preserves a failed attempt outcome without presenting it as a clean success', async () => { + const store = await loadStore(); + store.beginNodeSession(1); + const a = store.newAttemptId(); + store.commitMilestone('list_visible', a, { outcome: 'error' }); + const report = store.getHydrationReport(); + expect(report.lastAttemptId).toBe(a); + expect(report.phases.find((p) => p.phase === 'list_visible')?.outcome).toBe('error'); + }); + + it('degrades attempt-relative fields gracefully when the attempt map evicts the record', async () => { + const store = await loadStore(); + store.beginNodeSession(1); + const a = store.newAttemptId(); + store.commitMilestone('list_visible', a); + for (let i = 0; i < 200; i++) store.newAttemptId(); // MAX_ATTEMPTS evicts `a` + const report = store.getHydrationReport(); + expect(report.lastAttemptId).toBeNull(); + expect(report.lastAttemptListVisibleMs).toBeNull(); + expect(report.sessionListVisibleMs).not.toBeNull(); + }); + + it('degrades boot-relative fields gracefully when the event cap evicts boot markers', async () => { + const store = await loadStore(); + store.markMilestone('auth_resolved'); + store.beginNodeSession(1); + evictOldestEvents(store); + const report = store.getHydrationReport(); + expect(report.bootAuthResolvedMs).toBeNull(); + expect(report.bootAgeMs).not.toBeNull(); + expect(report.sessionAgeMs).not.toBeNull(); + }); + + it('clearReport preserves the session anchor and session age', async () => { + const store = await loadStore(); + store.beginNodeSession(1); + const a = store.newAttemptId(); + store.commitMilestone('list_visible', a); + await waitFor(() => expect(store.getSnapshot().nodeSessionStartAt).not.toBeNull()); + + store.clearReport(); + await waitFor(() => + expect(store.getSnapshot().events.some((e) => e.phase === 'list_visible')).toBe(false), + ); + + const report = store.getHydrationReport(); + expect(report.sessionAgeMs).not.toBeNull(); + expect(report.sessionListVisibleMs).toBeNull(); + expect(store.getSnapshot().nodeSessionStartAt).not.toBeNull(); + }); + + it('populates boot-relative auth, nodes, and shell durations from boot-scoped events', async () => { + let t = 0; + const store = await loadStore(() => stubClock(() => t)); + t = 100; + store.markMilestone('auth_resolved'); + t = 250; + store.markMilestone('nodes_resolved'); + t = 400; + store.markMilestone('shell_committed'); + const report = store.getHydrationReport(); + expect(report.bootAuthResolvedMs).toBe(100); + expect(report.bootNodesResolvedMs).toBe(250); + expect(report.bootShellCommittedMs).toBe(400); + }); + + it('stamps the foreground attempt proxy flag and node id from its own event', async () => { + const store = await loadStore(); + store.beginNodeSession(7); + const a = store.newAttemptId(); + store.commitMilestone('list_visible', a, { proxied: true }); + const report = store.getHydrationReport(); + expect(report.lastAttemptProxied).toBe(true); + expect(report.lastAttemptNodeId).toBe(7); + }); + + it('exposes every session-correct schema-2 field on the report', async () => { + const store = await loadStore(); + store.beginNodeSession(1); + const a = store.newAttemptId(); + store.commitMilestone('list_visible', a); + const report = store.getHydrationReport(); + expect(report.schemaVersion).toBe(2); + for (const key of [ + 'bootAgeMs', + 'bootAuthResolvedMs', + 'bootNodesResolvedMs', + 'bootShellCommittedMs', + 'sessionAgeMs', + 'sessionListVisibleMs', + 'sessionListHydratedMs', + 'lastAttemptId', + 'lastAttemptListVisibleMs', + 'lastAttemptListHydratedMs', + 'lastAttemptHydrationGapMs', + 'lastAttemptProxied', + 'lastAttemptNodeId', + ]) { + expect(report).toHaveProperty(key); + } + }); + + it('reports positive same-attempt visible, hydrated, and gap durations', async () => { + let t = 0; + const store = await loadStore(() => stubClock(() => t)); + store.beginNodeSession(1); + t = 100; + const a = store.newAttemptId(); + t = 250; + store.commitMilestone('list_visible', a); + t = 400; + store.commitMilestone('list_hydrated', a); + const report = store.getHydrationReport(); + expect(report.lastAttemptId).toBe(a); + expect(report.lastAttemptListVisibleMs).toBe(150); + expect(report.lastAttemptListHydratedMs).toBe(300); + expect(report.lastAttemptHydrationGapMs).toBe(150); + }); + + it('never borrows another attempt hydration for the foreground attempt', async () => { + let t = 0; + const store = await loadStore(() => stubClock(() => t)); + store.beginNodeSession(1); + t = 100; + const first = store.newAttemptId(); + t = 250; + store.commitMilestone('list_visible', first); + t = 400; + store.commitMilestone('list_hydrated', first); + t = 500; + const second = store.newAttemptId(); + t = 600; + store.commitMilestone('list_visible', second); + const report = store.getHydrationReport(); + expect(report.lastAttemptId).toBe(second); + expect(report.lastAttemptListVisibleMs).toBe(100); + expect(report.lastAttemptListHydratedMs).toBeNull(); + expect(report.lastAttemptHydrationGapMs).toBeNull(); + }); + + it('a failed hydration marked via markMilestone never reads as hydrated', async () => { + const store = await loadStore(); + store.beginNodeSession(1); + const a = store.newAttemptId(); + store.commitMilestone('list_visible', a); + // Real failure path (useStackListState): the statuses fetch threw, so + // list_hydrated is marked uncommitted with an error outcome, never + // committed as a completed hydration. + store.markMilestone('list_hydrated', { attemptId: a, outcome: 'error' }); + const report = store.getHydrationReport(); + expect(report.lastAttemptId).toBe(a); + expect(report.lastAttemptListVisibleMs).not.toBeNull(); + expect(report.lastAttemptListHydratedMs).toBeNull(); + expect(report.lastAttemptHydrationGapMs).toBeNull(); + expect(report.phases.find((p) => p.phase === 'list_hydrated')?.outcome).toBe('error'); + }); + + it('reports session-correct values across a node switch', async () => { + let t = 0; + const store = await loadStore(() => stubClock(() => t)); + store.beginNodeSession(1); + t = 300_000; // first hydration five minutes into the page + const a = store.newAttemptId(); + t = 300_010; + store.commitMilestone('list_visible', a); + t = 600_000; // node switch at ten minutes + store.beginNodeSession(2); + const b = store.newAttemptId(); + t = 600_010; + store.commitMilestone('list_visible', b); + const report = store.getHydrationReport(); + expect(report.lastAttemptId).toBe(b); + expect(report.sessionListVisibleMs).toBe(10); + expect(report.lastAttemptListVisibleMs).toBe(10); + expect(report.listVisibleMs).toBe(600_010); // boot-relative compat stays boot age + }); + + it('degrades gracefully when the event cap evicts the foreground list_visible', async () => { + const store = await loadStore(); + store.beginNodeSession(1); + const a = store.newAttemptId(); + store.commitMilestone('list_visible', a); + evictOldestEvents(store); + const report = store.getHydrationReport(); + expect(report.lastAttemptId).toBeNull(); // list_visible evicted; record survives + expect(report.lastAttemptListVisibleMs).toBeNull(); + expect(report.sessionListVisibleMs).toBeNull(); + expect(report.sessionAgeMs).not.toBeNull(); + }); + + it('leaves lastAttemptProxied null for a local attempt', async () => { + const store = await loadStore(); + store.beginNodeSession(1); + const a = store.newAttemptId(); + store.commitMilestone('list_visible', a); + const report = store.getHydrationReport(); + expect(report.lastAttemptProxied).toBeNull(); + expect(report.lastAttemptNodeId).toBe(1); + }); + + it('abortAttempt rebuilds the snapshot so an aborted attempt cannot linger as foreground', async () => { + const store = await loadStore(); + store.beginNodeSession(1); + const a = store.newAttemptId(); + store.commitMilestone('list_visible', a); + await waitFor(() => expect(store.getSnapshot().lastAttempt?.attemptId).toBe(a)); + + store.abortAttempt(a); // no open spans: only the scheduled emit can clear it + await waitFor(() => expect(store.getSnapshot().lastAttempt).toBeNull()); + expect(store.getHydrationReport().lastAttemptId).toBeNull(); + }); }); diff --git a/frontend/src/lib/hydrationTiming.ts b/frontend/src/lib/hydrationTiming.ts index 629a4dc5..6f170b62 100644 --- a/frontend/src/lib/hydrationTiming.ts +++ b/frontend/src/lib/hydrationTiming.ts @@ -78,12 +78,18 @@ export interface HydrationEvent { } export interface HydrationSnapshot { - schemaVersion: 1; clock: HydrationClock; bootSessionId: string; bootStartAt: number | null; nodeSessionId: string | null; nodeId: number | null; + /** Clock time when the active node session began; null before the first node resolves. */ + nodeSessionStartAt: number | null; + /** Resolved foreground list attempt (see `resolveForegroundAttempt`); null + * until a list attempt commits `list_visible`. Unversioned by policy: the + * snapshot never leaves the process; `HydrationReport` is the versioned, + * serialized artifact. */ + lastAttempt: ForegroundAttempt | null; events: readonly HydrationEvent[]; } @@ -104,7 +110,7 @@ export interface HydrationReportPhase { } export interface HydrationReport { - schemaVersion: 1; + schemaVersion: 2; /** Wall-clock capture time (Date.now), only for human reference. */ capturedAt: number; clock: HydrationClock; @@ -112,7 +118,37 @@ export interface HydrationReport { bootSessionId: string; nodeSessionId: string | null; nodeId: number | null; + /** Raw boot-relative elapsed ms from `boot_start` to the most recent + * `list_visible`, kept for diagnostic back-compat. The truthful foreground + * duration is `lastAttemptListVisibleMs` (attempt-relative). */ listVisibleMs: number | null; + /** Page age at capture: `boot_start` to now. */ + bootAgeMs: number | null; + /** `boot_start` to `auth_resolved`. */ + bootAuthResolvedMs: number | null; + /** `boot_start` to `nodes_resolved`. */ + bootNodesResolvedMs: number | null; + /** `boot_start` to `shell_committed`. */ + bootShellCommittedMs: number | null; + /** Elapsed ms since the active node session began (node-session age). */ + sessionAgeMs: number | null; + /** `node-session start` to the session's most recent committed `list_visible`. */ + sessionListVisibleMs: number | null; + /** `node-session start` to the session's most recent committed `list_hydrated`. */ + sessionListHydratedMs: number | null; + /** Foreground list attempt: the newest committed `list_visible` attempt in + * the active node session that is still live (not aborted or superseded). */ + lastAttemptId: string | null; + /** `attempt start` to its committed `list_visible`. */ + lastAttemptListVisibleMs: number | null; + /** `attempt start` to its committed `list_hydrated`; null until the foreground attempt hydrates. */ + lastAttemptListHydratedMs: number | null; + /** `list_visible` to `list_hydrated` for the same foreground attempt. */ + lastAttemptHydrationGapMs: number | null; + /** Proxy flag from the foreground attempt's own `list_visible` event. */ + lastAttemptProxied: boolean | null; + /** Node id from the foreground attempt's own `list_visible` event. */ + lastAttemptNodeId: number | null; anyProxied: boolean; phases: HydrationReportPhase[]; } @@ -195,8 +231,10 @@ function round(n: number): number { return Math.round(n * 100) / 100; } -interface AttemptRecord { +export interface AttemptRecord { sessionId: string; + /** Clock time when the attempt was created (`newAttemptId`). */ + createdAt: number; aborted: boolean; superseded: boolean; } @@ -222,6 +260,7 @@ function newSessionId(prefix: string): string { const bootSessionId = newSessionId('boot'); let bootStartAt: number | null = null; let nodeSessionId: string | null = null; +let nodeSessionStartAt: number | null = null; let currentNodeId: number | null = null; let events: HydrationEvent[] = []; @@ -306,13 +345,15 @@ let flushScheduled = false; let lastEmitAt = 0; function rebuildSnapshot(): void { + const foreground = resolveForegroundAttempt(events, nodeSessionId, attempts); snapshot = { - schemaVersion: 1, clock: clockKind, bootSessionId, bootStartAt, nodeSessionId, nodeId: currentNodeId, + nodeSessionStartAt, + lastAttempt: foreground, events: events.slice(), }; } @@ -380,6 +421,7 @@ export function beginNodeSession(nodeId: number): string { committedKeys.clear(); } nodeSessionId = newSessionId('node'); + nodeSessionStartAt = now(); currentNodeId = nodeId; scheduleEmit(); return nodeSessionId; @@ -387,7 +429,12 @@ export function beginNodeSession(nodeId: number): string { export function newAttemptId(): string { const id = newSessionId('attempt'); - attempts.set(id, { sessionId: currentSessionId(), aborted: false, superseded: false }); + attempts.set(id, { + sessionId: currentSessionId(), + createdAt: now(), + aborted: false, + superseded: false, + }); if (attempts.size > MAX_ATTEMPTS) { const oldest = attempts.keys().next().value; if (oldest !== undefined) attempts.delete(oldest); @@ -418,6 +465,9 @@ export function abortAttempt(attemptId: string): void { nodeId: sessionNodeId(span.sessionId), }); } + // Rebuild the snapshot even when no span was open, so the aborted attempt + // cannot linger as the resolved foreground attempt until unrelated activity. + scheduleEmit(); } export function markMilestone(phase: HydrationMark, opts: MilestoneOptions = {}): void { @@ -556,23 +606,200 @@ export function classifyCritical(phase: string): boolean { return !BACKGROUND_PHASES.has(phase); } -/** Elapsed ms from `boot_start` to the most recent `list_visible` in `events`. */ +/** Newest event in `eventList` matching `predicate`, or null. */ +function findLatestEvent( + eventList: readonly HydrationEvent[], + predicate: (e: HydrationEvent) => boolean, +): HydrationEvent | null { + for (let i = eventList.length - 1; i >= 0; i--) { + if (predicate(eventList[i])) return eventList[i]; + } + return null; +} + +/** Raw boot-relative elapsed ms from `boot_start` to the most recent + * `list_visible`, with no session or attempt filtering. Retained as the + * compatibility surface; consumers needing a truthful foreground hydration + * duration should use `getAttemptListVisibleMsFrom` (attempt-relative) or + * `getSessionListVisibleMsFrom` (session-relative). */ export function listVisibleMsFrom( eventList: readonly HydrationEvent[], bootAt: number | null, ): number | null { if (bootAt == null) return null; + const event = findLatestEvent(eventList, (e) => e.phase === 'list_visible'); + return event == null ? null : round(event.t0 - bootAt); +} + +/** Boot-relative compatibility getter: elapsed ms from `boot_start` to the + * most recent `list_visible` across all sessions, or null. */ +export function getListVisibleMs(): number | null { + return listVisibleMsFrom(events, bootStartAt); +} + +// --------------------------------------------------------------------------- +// Session-correct derivations. The `*From` functions below are pure scans +// over the event list and explicit anchors, so React consumers can derive +// from the snapshot they last read (see `useHydrationTiming`). The no-arg +// getters wrap them with live module state for the report capture, a +// point-in-time read rather than a reactive derivation. +// --------------------------------------------------------------------------- + +export interface ForegroundAttempt { + attemptId: string; + createdAt: number; + /** Proxy flag from the foreground `list_visible` event itself. */ + proxied: boolean | null; + /** Node id from the foreground `list_visible` event itself. */ + nodeId: number | null; +} + +/** The foreground list attempt: the newest committed `list_visible` event in + * the active node session whose attempt record is still live (exists, not + * aborted, not superseded, same session). Selection is anchored on committed + * events, so a later stack-detail attempt can never steal the headline; the + * attempt map only filters for liveness and supplies `createdAt`. */ +export function resolveForegroundAttempt( + eventList: readonly HydrationEvent[], + sessionId: string | null, + attemptRecords: ReadonlyMap, +): ForegroundAttempt | null { + if (sessionId == null) return null; for (let i = eventList.length - 1; i >= 0; i--) { - if (eventList[i].phase === 'list_visible') { - return round(eventList[i].t0 - bootAt); - } + const event = eventList[i]; + if (event.phase !== 'list_visible' || event.commit !== true) continue; + if (event.sessionId !== sessionId) continue; + const attemptId = event.attemptId; + if (!attemptId) continue; + const record = attemptRecords.get(attemptId); + if (!record || record.aborted || record.superseded) continue; + if (record.sessionId !== sessionId) continue; + return { + attemptId, + createdAt: record.createdAt, + proxied: event.proxied ?? null, + nodeId: event.nodeId ?? null, + }; } return null; } -/** Elapsed ms from `boot_start` to the most recent `list_visible`, or null. */ -export function getListVisibleMs(): number | null { - return listVisibleMsFrom(events, bootStartAt); +/** Elapsed ms from `boot_start` to the most recent `phase` event belonging to + * the boot session, or null when the phase has not fired (or was evicted). */ +export function getBootMilestoneMsFrom( + eventList: readonly HydrationEvent[], + sessionId: string, + phase: string, + bootAt: number | null, +): number | null { + if (bootAt == null) return null; + const event = findLatestEvent( + eventList, + (e) => e.phase === phase && e.sessionId === sessionId, + ); + return event == null ? null : round(event.t0 - bootAt); +} + +/** Elapsed ms from the active node-session start to its most recent committed + * `list_visible`, or null before one exists. */ +export function getSessionListVisibleMsFrom( + eventList: readonly HydrationEvent[], + sessionId: string | null, + sessionStartAt: number | null, +): number | null { + if (sessionStartAt == null) return null; + const event = findLatestEvent( + eventList, + (e) => e.phase === 'list_visible' && e.commit === true && e.sessionId === sessionId, + ); + return event == null ? null : round(event.t0 - sessionStartAt); +} + +/** Elapsed ms from the active node-session start to its most recent committed + * `list_hydrated`, or null before one exists. */ +export function getSessionListHydratedMsFrom( + eventList: readonly HydrationEvent[], + sessionId: string | null, + sessionStartAt: number | null, +): number | null { + if (sessionStartAt == null) return null; + const event = findLatestEvent( + eventList, + (e) => e.phase === 'list_hydrated' && e.commit === true && e.sessionId === sessionId, + ); + return event == null ? null : round(event.t0 - sessionStartAt); +} + +/** Elapsed ms from the attempt's creation to its committed `list_visible`, or + * null. Only commit-aligned events count, matching `resolveForegroundAttempt` + * and the session getters; an uncommitted error mark never reads as success. */ +export function getAttemptListVisibleMsFrom( + eventList: readonly HydrationEvent[], + attemptId: string, + attemptCreatedAt: number, +): number | null { + const event = findLatestEvent( + eventList, + (e) => e.phase === 'list_visible' && e.attemptId === attemptId && e.commit === true, + ); + return event == null ? null : round(event.t0 - attemptCreatedAt); +} + +/** Elapsed ms from the attempt's creation to its committed `list_hydrated`, or + * null until the attempt actually hydrates. Only commit-aligned events count, + * so a failed hydration marked via `markMilestone` never reads as completed. + * Never borrowed from another attempt. */ +export function getAttemptListHydratedMsFrom( + eventList: readonly HydrationEvent[], + attemptId: string, + attemptCreatedAt: number, +): number | null { + const event = findLatestEvent( + eventList, + (e) => e.phase === 'list_hydrated' && e.attemptId === attemptId && e.commit === true, + ); + return event == null ? null : round(event.t0 - attemptCreatedAt); +} + +/** Elapsed ms from committed `list_visible` to committed `list_hydrated` for + * the same attempt, or null when either phase has not committed for it (or + * when hydration committed before visibility, which is not a valid gap). + * Defined only when visible precedes hydrated. */ +export function getAttemptHydrationGapMsFrom( + eventList: readonly HydrationEvent[], + attemptId: string, +): number | null { + const visible = findLatestEvent( + eventList, + (e) => e.attemptId === attemptId && e.commit === true && e.phase === 'list_visible', + ); + const hydrated = findLatestEvent( + eventList, + (e) => e.attemptId === attemptId && e.commit === true && e.phase === 'list_hydrated', + ); + if (visible == null || hydrated == null || hydrated.t0 < visible.t0) return null; + return round(hydrated.t0 - visible.t0); +} + +/** Page age at call time: elapsed ms from `boot_start` to now, or null. */ +function getBootAgeMs(): number | null { + return bootStartAt == null ? null : round(now() - bootStartAt); +} + +/** Active node-session age at call time: elapsed ms from `beginNodeSession` + * to now, or null before the first node resolves. */ +function getSessionAgeMs(): number | null { + return nodeSessionStartAt == null ? null : round(now() - nodeSessionStartAt); +} + +/** Session-relative `list_visible` for the active node session, or null. */ +function getSessionListVisibleMs(): number | null { + return getSessionListVisibleMsFrom(events, nodeSessionId, nodeSessionStartAt); +} + +/** Session-relative `list_hydrated` for the active node session, or null. */ +function getSessionListHydratedMs(): number | null { + return getSessionListHydratedMsFrom(events, nodeSessionId, nodeSessionStartAt); } function toReportPhase(event: HydrationEvent): HydrationReportPhase { @@ -594,9 +821,14 @@ function toReportPhase(event: HydrationEvent): HydrationReportPhase { }; } +function bootMilestoneMs(phase: string): number | null { + return getBootMilestoneMsFrom(events, bootSessionId, phase, bootStartAt); +} + export function getHydrationReport(): HydrationReport { + const foreground = resolveForegroundAttempt(events, nodeSessionId, attempts); return { - schemaVersion: 1, + schemaVersion: 2, capturedAt: Date.now(), clock: clockKind, ...(appVersion ? { appVersion } : {}), @@ -604,6 +836,26 @@ export function getHydrationReport(): HydrationReport { nodeSessionId, nodeId: currentNodeId, listVisibleMs: getListVisibleMs(), + bootAgeMs: getBootAgeMs(), + bootAuthResolvedMs: bootMilestoneMs('auth_resolved'), + bootNodesResolvedMs: bootMilestoneMs('nodes_resolved'), + bootShellCommittedMs: bootMilestoneMs('shell_committed'), + sessionAgeMs: getSessionAgeMs(), + sessionListVisibleMs: getSessionListVisibleMs(), + sessionListHydratedMs: getSessionListHydratedMs(), + lastAttemptId: foreground?.attemptId ?? null, + lastAttemptListVisibleMs: + foreground != null + ? getAttemptListVisibleMsFrom(events, foreground.attemptId, foreground.createdAt) + : null, + lastAttemptListHydratedMs: + foreground != null + ? getAttemptListHydratedMsFrom(events, foreground.attemptId, foreground.createdAt) + : null, + lastAttemptHydrationGapMs: + foreground != null ? getAttemptHydrationGapMsFrom(events, foreground.attemptId) : null, + lastAttemptProxied: foreground?.proxied ?? null, + lastAttemptNodeId: foreground?.nodeId ?? null, anyProxied: events.some((e) => e.proxied === true), phases: events.map(toReportPhase), };