diff --git a/apps/electron-backend-e2e/src/performance/playback-journey-record.spec.ts b/apps/electron-backend-e2e/src/performance/playback-journey-record.spec.ts index 2b4246025..a382f76f5 100644 --- a/apps/electron-backend-e2e/src/performance/playback-journey-record.spec.ts +++ b/apps/electron-backend-e2e/src/performance/playback-journey-record.spec.ts @@ -181,6 +181,7 @@ test('maps the media-terminated probe, IPC window and mock ledger to exact count 'renderer.domMutationsToPlaying': 6_188, 'renderer.httpRequestsToPlaying': 2, 'renderer.ipcCallsToPlaying': 4, + 'renderer.ipcSerialDepthToPlaying': 3, 'renderer.layoutShiftScore': 0.001, 'renderer.longTasks': 0, }); @@ -225,6 +226,71 @@ test('maps the media-terminated probe, IPC window and mock ledger to exact count assert.equal(record.evidence['ipcCallsAfterPlaying'], 3); }); +test('derives the serial IPC depth from the capture timeline, not the call count', () => { + const record = toPlaybackIterationRecord(1, false, measurement()); + // xtreamRequest overlaps getEpgMapping and updateRemoteControlStatus, so + // four calls take three round trips. + assert.deepEqual(record.evidence['ipcSerialDepth'], { + chain: ['setUserAgent', 'getEpgMapping', 'updateRemoteControlStatus'], + depth: 3, + depthLowerBound: 3, + inFlightAtEnd: 0, + }); + assert.deepEqual(record.evidence['ipcTimeline'], [ + '+setUserAgent', + '-setUserAgent', + '+xtreamRequest', + '+getEpgMapping', + '-getEpgMapping', + '+updateRemoteControlStatus', + '-updateRemoteControlStatus', + '-xtreamRequest', + ]); + assert.equal(record.evidence['ipcTimelineAmbiguousCompletions'], 0); + + const base = measurement(); + const parallel = toPlaybackIterationRecord(1, false, { + ...base, + ipc: { + ...base.ipc, + ambiguousTimelineCompletions: 1, + timeline: [ + { method: 'setUserAgent', phase: 'start' }, + { method: 'xtreamRequest', phase: 'start' }, + { method: 'getEpgMapping', phase: 'start' }, + { method: 'updateRemoteControlStatus', phase: 'start' }, + { method: 'getEpgMapping', phase: 'end' }, + { method: 'setUserAgent', phase: 'end' }, + { method: 'xtreamRequest', phase: 'end' }, + ], + }, + }); + assert.equal(parallel.counters['renderer.ipcCallsToPlaying'], 4); + // A call still in flight at `playing` is excluded from the depth. + assert.equal(parallel.counters['renderer.ipcSerialDepthToPlaying'], 1); + assert.equal( + (parallel.evidence['ipcSerialDepth'] as { inFlightAtEnd: number }) + .inFlightAtEnd, + 1 + ); + assert.equal(parallel.evidence['ipcTimelineAmbiguousCompletions'], 1); +}); + +test('fails the iteration on a timeline completion without a start', () => { + const base = measurement(); + assert.throws( + () => + toPlaybackIterationRecord(0, false, { + ...base, + ipc: { + ...base.ipc, + timeline: [{ method: 'xtreamRequest', phase: 'end' }], + }, + }), + /journey-ipc-serial-depth-unmatched-end:xtreamRequest/ + ); +}); + test('rejects measurements that did not start at a live channel or did not play a video', () => { const base = measurement(); const start = base.renderer.start as Start; @@ -345,7 +411,7 @@ test('rejects activity that moved between the settle snapshot and the click', () ); }); -test('summarizes playback iterations with J3 counters and unavailable reasons', () => { +test('summarizes playback iterations with every J3 counter measured', () => { const iterations = [0, 1, 2].map((index) => toPlaybackIterationRecord(index, index === 0, { ...measurement(), @@ -364,7 +430,10 @@ test('summarizes playback iterations with J3 counters and unavailable reasons', assert.equal(entry.wallClock['clickToPlayingMs.p50'], 349.8); assert.equal(entry.wallClock['clickToLoadedMetadataMs.p90'], 95); assert.equal(entry.counters['renderer.cdTicksToPlaying'], 14); - assert.deepEqual(Object.keys(entry.unavailable).sort(), [ - 'renderer.ipcSerialDepthToPlaying', - ]); + assert.equal(entry.counters['renderer.ipcSerialDepthToPlaying'], 3); + assert.deepEqual( + entry.counterStability['renderer.ipcSerialDepthToPlaying'], + { stable: true, values: [3, 3] } + ); + assert.deepEqual(entry.unavailable, {}); }); diff --git a/apps/electron-backend-e2e/src/performance/playback-journey-record.ts b/apps/electron-backend-e2e/src/performance/playback-journey-record.ts index 9851580d8..5980ecb8b 100644 --- a/apps/electron-backend-e2e/src/performance/playback-journey-record.ts +++ b/apps/electron-backend-e2e/src/performance/playback-journey-record.ts @@ -2,6 +2,7 @@ import { journeyActivityBeforeClick, type JourneyClickSettle, } from './journey-click-settle'; +import { computeJourneyIpcSerialDepth } from './journey-ipc-serial-depth'; import type { JourneyMainIpcCaptureState } from './journey-main-ipc-capture'; import { countJourneyMockRoutes, @@ -23,6 +24,7 @@ export const PLAYBACK_JOURNEY_COUNTER = { DOM_MUTATIONS: 'renderer.domMutationsToPlaying', HTTP_REQUESTS: 'renderer.httpRequestsToPlaying', IPC_CALLS: 'renderer.ipcCallsToPlaying', + IPC_SERIAL_DEPTH: 'renderer.ipcSerialDepthToPlaying', LAYOUT_SHIFT_SCORE: 'renderer.layoutShiftScore', LONG_TASKS: 'renderer.longTasks', } as const; @@ -37,12 +39,13 @@ export const PLAYBACK_JOURNEY_WALL_CLOCK = { /** How long requests after `playing` are observed, for evidence only. */ export const PLAYBACK_JOURNEY_AFTER_PLAYING_WINDOW_MS = 1_000; +/** + * Counters the plan lists for J3 that this harness cannot measure. Every one + * is measured now; the list stays so a future gap is reported, not faked. + */ export const PLAYBACK_JOURNEY_UNAVAILABLE_COUNTERS: Readonly< Record -> = Object.freeze({ - 'renderer.ipcSerialDepthToPlaying': - 'The serial-depth helper is being added for J1 in a separate thread and is not on master yet; J3 adopts it once it lands.', -}); +> = Object.freeze({}); export interface PlaybackJourneyMeasurement { /** Logo requests to picsum.photos cancelled in the main process. */ @@ -148,6 +151,7 @@ export function toPlaybackIterationRecord( `playback-journey-record-cd-ticks-${renderer.capabilities.changeDetectionTicks}` ); } + const serialDepth = computeJourneyIpcSerialDepth(ipc.timeline); return Object.freeze({ counters: Object.freeze({ [PLAYBACK_JOURNEY_COUNTER.CD_TICKS]: cdTicks, @@ -155,6 +159,7 @@ export function toPlaybackIterationRecord( renderer.counters.domMutations, [PLAYBACK_JOURNEY_COUNTER.HTTP_REQUESTS]: http.toPlaying.length, [PLAYBACK_JOURNEY_COUNTER.IPC_CALLS]: ipc.callsBeforeSentinel, + [PLAYBACK_JOURNEY_COUNTER.IPC_SERIAL_DEPTH]: serialDepth.depth, // The click's 500 ms input window covers the start of the // journey, so shifts flagged hadRecentInput are included, as // in J2. @@ -196,6 +201,13 @@ export function toPlaybackIterationRecord( }), ipcCallsAfterPlaying: ipc.callsAfterSentinel, ipcCallsByMethod: ipc.callsByMethod, + ipcSerialDepth: serialDepth, + ipcTimelineAmbiguousCompletions: ipc.ambiguousTimelineCompletions, + // `+method` for a start, `-method` for a completion. + ipcTimeline: ipc.timeline.map( + ({ method, phase }) => + `${phase === 'start' ? '+' : '-'}${method}` + ), layoutShift: Object.freeze({ recentInput: roundThousandth( renderer.counters.recentInputLayoutShiftScore diff --git a/docs/architecture/performance-journeys.md b/docs/architecture/performance-journeys.md index 541f47f59..776350400 100644 --- a/docs/architecture/performance-journeys.md +++ b/docs/architecture/performance-journeys.md @@ -821,6 +821,7 @@ ignored. | Counter | Source | | -------------------------------- | --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | | `renderer.ipcCallsToPlaying` | Bridge `start` trace events between the start and end sentinels, as `renderer.ipcCallsToFirstPage` in J2. | +| `renderer.ipcSerialDepthToPlaying` | `computeJourneyIpcSerialDepth` over the capture's timeline between the start and end sentinels, as `renderer.ipcSerialDepthToResults` in J4 (see [Serial IPC depth](#serial-ipc-depth)). `evidence.ipcSerialDepth.chain` and `evidence.ipcTimeline` show the calls; `evidence.ipcTimelineAmbiguousCompletions` counts completions the start marker left ambiguous. | | `renderer.httpRequestsToPlaying` | Requests the ledger proxy received from the click stamp until the `playing` stamp, from either process (the stream request comes from the renderer, Xtream API calls from the main process). Both stamps are `performance.timeOrigin + performance.now()` of processes on the same host clock, as in J2. Unlike J2's counter the window ends at the terminal, not at a quiet mock: a live stream has no quiet end. Later requests are kept as `evidence.httpRequestsAfterPlayingByRoute`, the ones in the window as `evidence.httpRequestsByRoute`. | | `renderer.domMutationsToPlaying` | `MutationRecord`s from the click until the `playing` event, including records still queued when it fires. | | `renderer.cdTicksToPlaying` | `ApplicationRef` ticks from the click until the `playing` event, read like `renderer.cdTicksToFirstPage` in J2 (see [Change-detection ticks](#change-detection-ticks)). Not yet measured on a run; the counter shipped after J3's first measurements. | @@ -841,10 +842,7 @@ above a sub-millisecond origin difference. `evidence.httpRequestsAfterPlayingByR window of 1 s after `playing` (the test waits that long before reading the ledger), not a quiet mock as in J2: a live stream has no quiet end. -One counter is listed under `unavailable`. -`renderer.ipcSerialDepthToPlaying` is missing because the serial-depth -helper (see [Startup work before the first card](#startup-work-before-the-first-card)) -was not on `master` when J3 landed; J3 adopts it once the J1 thread adds it. +No counter is listed under `unavailable`. `main.sqlStatementsToPlaying` is not measured for the same reason as J2's SQL counter. @@ -877,6 +875,13 @@ mutation and request counts. On the runner `renderer.httpRequestsToPlaying` and `renderer.layoutShiftScore` are enforced as guards; see [Enforced journey counters](#enforced-journey-counters). +`renderer.ipcSerialDepthToPlaying` came later. One local macOS +`perf:journeys` run on 2026-10-10 read 3 in all six iterations, warm-up +included, with `depthLowerBound` 3, no ambiguous completion and no call in +flight at `playing`. The chain was `getEpgMapping` → `xtreamRequest` → +`updateRemoteControlStatus`; the last is the second of two +`updateRemoteControlStatus` calls in the window (five calls in all). + ## J4 `search`: type a query until the results settle `search.journey.ts` follows J3: the profile is seeded once through the "Add @@ -1299,6 +1304,9 @@ Not enforced, with the reason: - J3 `renderer.ipcCallsToPlaying` (4 or 5) and `renderer.domMutationsToPlaying` (6,182, 6,183 or 6,199): not identical, and the EPG rendering work changes the mutation count. +- J3 `renderer.ipcSerialDepthToPlaying` (3 locally): added after these + runs and not yet measured on the runner; a candidate once `master` runs + agree. - J4: not measured yet. Runner counters differ from a Mac (the Linux-only `getWindowState` call, for