diff --git a/apps/electron-backend-e2e/src/performance/journey-renderer-probe.spec.ts b/apps/electron-backend-e2e/src/performance/journey-renderer-probe.spec.ts index f8e90a123..168308468 100644 --- a/apps/electron-backend-e2e/src/performance/journey-renderer-probe.spec.ts +++ b/apps/electron-backend-e2e/src/performance/journey-renderer-probe.spec.ts @@ -13,6 +13,9 @@ import { JOURNEY_OPEN_SOURCE_PROBE_STATE_KEY, JOURNEY_OPEN_SOURCE_START_SENTINEL_ID, JOURNEY_PROBE_STATE_KEY, + JOURNEY_SETTLE_CAP_MS, + JOURNEY_SETTLE_QUIET_MS, + JOURNEY_SETTLE_ROOT_SELECTOR, journeyRendererProbeScript, type JourneyRendererProbeOptions, type JourneyRendererProbeState, @@ -45,7 +48,14 @@ interface Fixture { const PAGE = `
IPTVnator
-`; +
`; + +/** Short settle timers so the launch fixtures do not wait 500 ms each. */ +const FAST_SETTLE = { + capMs: 1_000, + quietMs: 30, + rootSelector: JOURNEY_SETTLE_ROOT_SELECTOR, +} as const; function installFakePerformance( window: JSDOM['window'], @@ -114,7 +124,11 @@ function createFixture( }); return createFixtureFromDom( dom, - { ...createLaunchJourneyProbeOptions(), ...optionOverrides }, + { + ...createLaunchJourneyProbeOptions(), + settle: FAST_SETTLE, + ...optionOverrides, + }, bridge ); } @@ -171,16 +185,20 @@ const liveStates: (() => JourneyRendererProbeState)[] = []; /** * Waits `ms`, then until every probe that reached its terminal batch has also - * passed the post-paint cutoff (a rAF plus a timer). A fixed delay alone - * flakes when the harness runs all spec files in parallel. + * passed the post-paint cutoff (a rAF plus a timer) and closed its settle + * window. A fixed delay alone flakes when the harness runs all spec files in + * parallel. */ async function settle(ms = 40): Promise { await new Promise((resolve) => setTimeout(resolve, ms)); - const deadline = Date.now() + 2_000; + const deadline = Date.now() + 3_000; while ( liveStates.some((read) => { const state = read(); - return state.terminal !== null && !state.final; + return ( + state.terminal !== null && + (!state.final || state.settle.status === 'pending') + ); }) && Date.now() < deadline ) { @@ -193,7 +211,7 @@ function renderFirstCard(fixture: Fixture): void { document.getElementById('initial-splash')?.remove(); const rail = document.createElement('section'); rail.setAttribute('data-test-id', 'dashboard-recent-sources-rail'); - document.querySelector('app-root')?.append(rail); + document.querySelector('main.workspace-content')?.append(rail); const card = document.createElement('div'); card.setAttribute('data-test-id', 'dashboard-recent-sources-rail-card'); rail.append(card); @@ -361,6 +379,140 @@ test('sums layout shifts without recent input and counts long tasks over 50 ms u assert.equal(fixture.state().counters.longTasks, 3); }); +function layoutShift( + startTime: number, + value: number, + hadRecentInput = false +): FakeEntry { + return { entryType: 'layout-shift', hadRecentInput, startTime, value }; +} + +async function waitFor( + predicate: () => boolean, + timeoutMs = 3_000 +): Promise { + const deadline = Date.now() + timeoutMs; + while (!predicate()) { + if (Date.now() > deadline) throw new Error('waitFor timed out'); + await new Promise((resolve) => setTimeout(resolve, 5)); + } +} + +test('keeps summing shifts without recent input after the first-card cutoff until the workspace content is quiet', async () => { + const fixture = createFixture({ + settle: { ...FAST_SETTLE, capMs: 5_000, quietMs: 80 }, + }); + const [observer] = fixture.observers as [FakeObserver]; + const now = () => fixture.window.performance.now(); + const content = fixture.window.document.querySelector( + 'main.workspace-content' + ) as HTMLElement; + observer.emit([layoutShift(now(), 0.25)]); + renderFirstCard(fixture); + await waitFor(() => fixture.rawState().final); + const cutoff = fixture.state(); + assert.equal(cutoff.counters.layoutShiftScore, 0.25); + assert.equal(cutoff.settle.status, 'pending'); + assert.equal(cutoff.settle.observedTarget, 'root'); + assert.equal(cutoff.counters.layoutShiftScoreSettled, 0); + assert.equal(observer.disconnected, false); + + // A skeleton rail that resolved empty collapses about 15 ms after the + // first card and pulls the rails below upwards (#1738). + observer.emit([layoutShift(now(), 0.5), layoutShift(now(), 0.3, true)]); + for (let step = 0; step < 3; step += 1) { + await new Promise((resolve) => setTimeout(resolve, 20)); + content.append(fixture.window.document.createElement('div')); + } + // Queued, not yet delivered, when the settle point is sampled. + observer.queue.push( + layoutShift(now(), 0.125), + layoutShift(now() + 60_000, 9) + ); + // Outside the settle root: does not keep the window open. + fixture.window.document.body.setAttribute('data-late', '1'); + await settle(); + const state = fixture.state(); + assert.equal(state.settle.status, 'quiet'); + assert.equal(state.settle.domMutations, 3); + assert.ok(state.settle.epochMs !== null && state.settle.epochMs > 0); + assert.ok( + state.settle.epochMs - (state.settle.lastMutationEpochMs ?? 0) >= 75, + 'the quiet period restarts at the last mutation' + ); + assert.equal(state.counters.layoutShiftScoreSettled, 0.875); + // The first-card counters were frozen at the cutoff. + assert.equal(state.counters.layoutShiftScore, 0.25); + assert.equal(state.counters.recentInputLayoutShiftScore, 0); + assert.equal(observer.disconnected, true); + assert.doesNotThrow(() => assertJourneyRendererProbeState(state)); + + observer.emit([layoutShift(now(), 1)]); + content.append(fixture.window.document.createElement('div')); + await settle(); + assert.equal(fixture.state().counters.layoutShiftScoreSettled, 0.875); + assert.equal(fixture.state().settle.domMutations, 3); +}); + +test('the cap ends the settle window while the workspace content keeps mutating', async () => { + const fixture = createFixture({ + settle: { ...FAST_SETTLE, capMs: 250, quietMs: 150 }, + }); + const [observer] = fixture.observers as [FakeObserver]; + const now = () => fixture.window.performance.now(); + const { document } = fixture.window; + renderFirstCard(fixture); + await waitFor(() => fixture.rawState().final); + const content = document.querySelector('main.workspace-content'); + const ticker = setInterval(() => { + content?.setAttribute('data-tick', String(now())); + }, 10); + try { + observer.emit([layoutShift(now(), 0.0625)]); + await waitFor(() => fixture.rawState().settle.status !== 'pending'); + observer.emit([layoutShift(now(), 0.5)]); + await new Promise((resolve) => setTimeout(resolve, 50)); + } finally { + clearInterval(ticker); + } + const state = fixture.state(); + assert.equal(state.settle.status, 'cap'); + assert.ok(state.settle.domMutations > 0); + assert.ok( + (state.settle.epochMs ?? 0) - (state.firstCardPaintEpochMs ?? 0) >= 245, + 'the cap is measured from the first-card cutoff' + ); + assert.equal(state.counters.layoutShiftScoreSettled, 0.0625); + assert.doesNotThrow(() => assertJourneyRendererProbeState(state)); +}); + +test('watches the document element when the settle root is missing', async () => { + const fixture = createFixture({ + settle: { ...FAST_SETTLE, rootSelector: 'app-missing-root' }, + }); + renderFirstCard(fixture); + await settle(); + const state = fixture.state(); + assert.equal(state.settle.observedTarget, 'documentElement'); + assert.equal(state.settle.status, 'quiet'); +}); + +test('refuses a probe whose settle window is still open', async () => { + const fixture = createFixture({ + settle: { ...FAST_SETTLE, capMs: 60_000, quietMs: 60_000 }, + }); + renderFirstCard(fixture); + await waitFor(() => fixture.rawState().final); + assert.throws( + () => assertJourneyRendererProbeState(fixture.state()), + /settle-pending/ + ); + // Mark the window closed so later tests' `settle()` does not wait on it, + // and stop its timers so they do not keep the runner alive. + fixture.rawState().settle.status = 'cap'; + fixture.window.close(); +}); + test('does not end while the splash is present, off the workspace route, or before a card is visible', async () => { const withSplash = createFixture(); const rail = withSplash.window.document.createElement('div'); @@ -437,6 +589,13 @@ test('launch options target the workspace source cards and the shared sentinel', assert.equal(options.routeFragment, '/workspace'); assert.match(options.cardSelector, /dashboard-recent-sources-rail-card/); assert.match(options.cardSelector, /app-playlist-item/); + assert.deepEqual(options.settle, { + capMs: JOURNEY_SETTLE_CAP_MS, + quietMs: JOURNEY_SETTLE_QUIET_MS, + rootSelector: 'main.workspace-content', + }); + assert.equal(JOURNEY_SETTLE_QUIET_MS, 500); + assert.equal(JOURNEY_SETTLE_CAP_MS, 3_000); }); // J2 "Open a source": the probe is armed in a loaded document and starts at @@ -643,6 +802,10 @@ test('drops performance entries from before the click and keeps recent-input shi assert.equal(state.final, true); assert.equal(state.counters.layoutShiftScore, 0.125); assert.equal(state.counters.recentInputLayoutShiftScore, 0.25); + // J2 has no settle window: the observers close at the cutoff. + assert.equal(state.settle.status, 'disabled'); + assert.equal(state.counters.layoutShiftScoreSettled, 0); + assert.ok(fixture.observers.every((observer) => observer.disconnected)); assert.equal(state.counters.longTasks, 1); assert.deepEqual(state.longTaskDurationsMs, [90]); }); diff --git a/apps/electron-backend-e2e/src/performance/journey-renderer-probe.ts b/apps/electron-backend-e2e/src/performance/journey-renderer-probe.ts index f54728746..b1190e3bb 100644 --- a/apps/electron-backend-e2e/src/performance/journey-renderer-probe.ts +++ b/apps/electron-backend-e2e/src/performance/journey-renderer-probe.ts @@ -12,7 +12,9 @@ import type { Page } from '@playwright/test'; * `window` (which runs before any listener of the app) and starts counting at * the first click inside `startClick.selector`. It counts DOM mutations, * layout shifts and long tasks until the journey's terminal condition and - * then emits one JSON blob under `options.stateKey`. + * then emits one JSON blob under `options.stateKey`. With `options.settle` + * (J1) it keeps summing layout shifts after the first card until the page + * has settled, for shifts such as collapsing skeletons that land later. * * IPC invocations are not counted here: the bridge object exposed by * `contextBridge` is frozen, so the probe cannot wrap it. Instead the probe @@ -50,6 +52,23 @@ export interface JourneyRendererProbeStartClick { readonly sentinelId: string; } +/** + * J1's settle window after the first card: it ends once nothing under + * `rootSelector` has mutated for `quietMs`, or `capMs` after the first-card + * cutoff, whichever comes first. See docs/architecture/performance-journeys.md. + */ +export interface JourneyRendererProbeSettleOptions { + readonly capMs: number; + readonly quietMs: number; + /** Falls back to the document element when nothing matches. */ + readonly rootSelector: string; +} + +export const JOURNEY_SETTLE_QUIET_MS = 500; +export const JOURNEY_SETTLE_CAP_MS = 3_000; +/** The workspace shell's content pane; the rail and header stay outside. */ +export const JOURNEY_SETTLE_ROOT_SELECTOR = 'main.workspace-content'; + export interface JourneyRendererProbeOptions { /** Selector for the element whose visibility ends the journey. */ readonly cardSelector: string; @@ -59,6 +78,8 @@ export interface JourneyRendererProbeOptions { /** Pathname fragment the terminal route must contain. */ readonly routeFragment: string; readonly sentinelId: string; + /** Absent: no settle window, the probe ends at the first-card cutoff. */ + readonly settle?: JourneyRendererProbeSettleOptions; readonly sentinelMethod: string; /** Element id of the inline splash that must be gone at the end. */ readonly splashId: string; @@ -71,6 +92,11 @@ export interface JourneyRendererProbeCounters { domMutations: number; /** Shifts with `hadRecentInput === false` (the CLS definition). */ layoutShiftScore: number; + /** + * The same filter from the journey's start until the settle point. Zero + * while `settle.status` is `pending` or `disabled`. + */ + layoutShiftScoreSettled: number; longTasks: number; /** * Shifts with `hadRecentInput === true`. Zero for J1, which has no @@ -113,6 +139,15 @@ export interface JourneyRendererProbeState { readonly epochMs: number | null; readonly status: 'bridge-missing' | 'failed' | 'not-sent' | 'sent'; }; + /** `final` freezes the first-card counters; the settle window ends later. */ + settle: { + /** Mutation records under the settle root after the cutoff. */ + domMutations: number; + epochMs: number | null; + lastMutationEpochMs: number | null; + observedTarget: 'documentElement' | 'root' | null; + status: 'cap' | 'disabled' | 'pending' | 'quiet'; + }; start: { /** `min(event.timeStamp, listener time)` as epoch milliseconds. */ readonly epochMs: number; @@ -145,6 +180,7 @@ export function journeyRendererProbeScript( } const epoch = (): number => performance.timeOrigin + performance.now(); const startClick = options.startClick ?? null; + const settleOptions = options.settle ?? null; const companionSelectors = options.companionSelectors ?? []; const bridge = target['electron'] as Record | undefined; const state: JourneyRendererProbeState = { @@ -159,6 +195,7 @@ export function journeyRendererProbeScript( counters: { domMutations: 0, layoutShiftScore: 0, + layoutShiftScoreSettled: 0, longTasks: 0, recentInputLayoutShiftScore: 0, }, @@ -178,6 +215,13 @@ export function journeyRendererProbeScript( preStart: { domMutations: 0, lastMutationEpochMs: null }, schemaVersion: 1, sentinel: { epochMs: null, status: 'not-sent' }, + settle: { + domMutations: 0, + epochMs: null, + lastMutationEpochMs: null, + observedTarget: null, + status: settleOptions === null ? 'disabled' : 'pending', + }, start: null, terminal: null, }; @@ -249,13 +293,24 @@ export function journeyRendererProbeScript( // cutoff wait here so the cutoff applies to them as well. const pendingLayoutShifts: PerformanceEntry[] = []; const pendingLongTasks: PerformanceEntry[] = []; + // Every layout shift delivered until the settle point, kept apart from + // the first-card path so that counter stays exactly as it was; the + // settle bound is applied once it is known. + const settleLayoutShifts: PerformanceEntry[] = []; + const collectSettleShifts = (entries: readonly PerformanceEntry[]) => { + if (state.settle.status === 'pending') { + settleLayoutShifts.push(...entries); + } + }; const observe = ( type: string, accept: (entries: readonly PerformanceEntry[], until: number) => void, - pending: PerformanceEntry[] + pending: PerformanceEntry[], + collect: ((entries: readonly PerformanceEntry[]) => void) | null ): PerformanceObserver | null => { try { const observer = new PerformanceObserver((list) => { + collect?.(list.getEntries()); if (state.final) return; if (state.terminal !== null) { pending.push(...list.getEntries()); @@ -272,23 +327,85 @@ export function journeyRendererProbeScript( const layoutShiftObserver = observe( 'layout-shift', acceptLayoutShift, - pendingLayoutShifts + pendingLayoutShifts, + collectSettleShifts ); const longTaskObserver = observe( 'longtask', acceptLongTasks, - pendingLongTasks + pendingLongTasks, + null ); state.capabilities.layoutShift = layoutShiftObserver !== null; state.capabilities.longTask = longTaskObserver !== null; + const endSettle = (status: 'cap' | 'quiet', untilEpochMs: number) => { + if (layoutShiftObserver) { + collectSettleShifts(layoutShiftObserver.takeRecords()); + layoutShiftObserver.disconnect(); + } + let score = 0; + for (const entry of settleLayoutShifts) { + const shift = entry as PerformanceEntry & { + hadRecentInput?: boolean; + value?: number; + }; + if ( + typeof shift.value === 'number' && + shift.hadRecentInput !== true && + inWindow(entry, untilEpochMs) + ) { + score += shift.value; + } + } + state.counters.layoutShiftScoreSettled = score; + state.settle.epochMs = untilEpochMs; + state.settle.status = status; + }; + // Starts at the first-card cutoff. Every mutation record under the root + // restarts the quiet timer; the cap timer never moves. + const startSettle = (settle: JourneyRendererProbeSettleOptions) => { + const root = document.querySelector(settle.rootSelector); + state.settle.observedTarget = + root === null ? 'documentElement' : 'root'; + let quietTimer: ReturnType | undefined; + const capTimer = setTimeout(() => end('cap'), settle.capMs); + const settleObserver = new MutationObserver((records) => { + if (state.settle.status !== 'pending') return; + state.settle.domMutations += records.length; + state.settle.lastMutationEpochMs = epoch(); + armQuiet(); + }); + const end = (status: 'cap' | 'quiet'): void => { + if (state.settle.status !== 'pending') return; + clearTimeout(quietTimer); + clearTimeout(capTimer); + state.settle.domMutations += settleObserver.takeRecords().length; + settleObserver.disconnect(); + endSettle(status, epoch()); + }; + const armQuiet = (): void => { + clearTimeout(quietTimer); + quietTimer = setTimeout(() => end('quiet'), settle.quietMs); + }; + settleObserver.observe(root ?? document.documentElement ?? document, { + attributes: true, + characterData: true, + childList: true, + subtree: true, + }); + armQuiet(); + }; + const finalize = (untilEpochMs: number): void => { if (layoutShiftObserver) { + const records = layoutShiftObserver.takeRecords(); + collectSettleShifts(records); acceptLayoutShift( - [...pendingLayoutShifts, ...layoutShiftObserver.takeRecords()], + [...pendingLayoutShifts, ...records], untilEpochMs ); - layoutShiftObserver.disconnect(); + if (settleOptions === null) layoutShiftObserver.disconnect(); } if (longTaskObserver) { acceptLongTasks( @@ -299,6 +416,7 @@ export function journeyRendererProbeScript( } state.firstCardPaintEpochMs = untilEpochMs; state.final = true; + if (settleOptions !== null) startSettle(settleOptions); }; const callSentinel = (id: string): 'bridge-missing' | 'failed' | 'sent' => { const method = bridge?.[options.sentinelMethod]; @@ -441,6 +559,11 @@ export function createLaunchJourneyProbeOptions(): JourneyRendererProbeOptions { routeFragment: '/workspace', sentinelId: JOURNEY_IPC_SENTINEL_ID, sentinelMethod: JOURNEY_IPC_SENTINEL_METHOD, + settle: { + capMs: JOURNEY_SETTLE_CAP_MS, + quietMs: JOURNEY_SETTLE_QUIET_MS, + rootSelector: JOURNEY_SETTLE_ROOT_SELECTOR, + }, splashId: 'initial-splash', stateKey: JOURNEY_PROBE_STATE_KEY, }; @@ -501,10 +624,17 @@ export async function waitForJourneyRendererProbe( stateKey: string, timeoutMs: number ): Promise { + // A settle window, where enabled, ends after `final`. await page.waitForFunction( - (key) => - (globalThis as unknown as Record)[key] - ?.final === true, + (key) => { + const state = ( + globalThis as unknown as Record< + string, + { final?: boolean; settle?: { status?: string } } + > + )[key]; + return state?.final === true && state.settle?.status !== 'pending'; + }, stateKey, { polling: 50, timeout: timeoutMs } ); @@ -532,6 +662,9 @@ export function assertJourneyRendererProbeState( ) { throw new Error('journey-renderer-probe-incomplete'); } + if (state.settle.status === 'pending') { + throw new Error('journey-renderer-probe-settle-pending'); + } if (state.invalidReasons.length > 0) { throw new Error( `journey-renderer-probe-invalid: ${state.invalidReasons.join(', ')}` diff --git a/apps/electron-backend-e2e/src/performance/launch-journey-record.spec.ts b/apps/electron-backend-e2e/src/performance/launch-journey-record.spec.ts index 168b59348..94f3befbd 100644 --- a/apps/electron-backend-e2e/src/performance/launch-journey-record.spec.ts +++ b/apps/electron-backend-e2e/src/performance/launch-journey-record.spec.ts @@ -22,6 +22,7 @@ function measurement( counters: { domMutations: 480, layoutShiftScore: 0.123456789, + layoutShiftScoreSettled: 0.2304999, longTasks: 2, recentInputLayoutShiftScore: 0, }, @@ -44,6 +45,13 @@ function measurement( preStart: { domMutations: 0, lastMutationEpochMs: null }, schemaVersion: 1, sentinel: { epochMs: 2_601, status: 'sent' }, + settle: { + domMutations: 37, + epochMs: 3_180.06, + lastMutationEpochMs: 2_680, + observedTarget: 'root', + status: 'quiet', + }, start: null, terminal: { cardCount: 2, @@ -111,6 +119,7 @@ test('maps the probe, IPC capture and main counters to exact counters and spawn- 'renderer.domMutationsToFirstCard': 480, 'renderer.ipcCallsToFirstCard': 14, 'renderer.layoutShiftScore': 0.123, + 'renderer.layoutShiftScoreSettled': 0.23, 'renderer.longTasks': 2, }); assert.deepEqual(record.wallClock, { @@ -141,8 +150,15 @@ test('maps the probe, IPC capture and main counters to exact counters and spawn- rendererGateBlankLoaded: 1_050, rendererGateReleased: 1_150, rendererProbeInstalled: 1_200, + settled: 3_180.06, spawn: 1_000, }); + assert.deepEqual(record.evidence['settle'], { + domMutations: 37, + firstCardToSettledMs: 580, + observedTarget: 'root', + reason: 'quiet', + }); }); test('rejects measurements whose clocks or probes are inconsistent', () => { @@ -183,6 +199,50 @@ test('rejects measurements whose clocks or probes are inconsistent', () => { ); }); +test('refuses a launch whose settle window did not end after the first-card cutoff', () => { + const base = measurement(); + const withSettle = ( + settle: Partial + ): LaunchJourneyMeasurement => ({ + ...base, + renderer: { + ...base.renderer, + settle: { ...base.renderer.settle, ...settle }, + }, + }); + assert.throws( + () => + toLaunchIterationRecord( + 0, + false, + withSettle({ epochMs: null, status: 'pending' }) + ), + /settle-pending/ + ); + assert.throws( + () => + toLaunchIterationRecord( + 0, + false, + withSettle({ epochMs: null, status: 'disabled' }) + ), + /settle-disabled/ + ); + assert.throws( + () => toLaunchIterationRecord(0, false, withSettle({ epochMs: 2_640 })), + /settle-quiet/ + ); + const capped = toLaunchIterationRecord( + 0, + false, + withSettle({ epochMs: 5_650, status: 'cap' }) + ); + assert.equal( + (capped.evidence['settle'] as { reason: string }).reason, + 'cap' + ); +}); + test('names the counters the harness cannot measure yet', () => { assert.deepEqual(Object.keys(LAUNCH_JOURNEY_UNAVAILABLE_COUNTERS), [ 'renderer.cdTicksToFirstCard', diff --git a/apps/electron-backend-e2e/src/performance/launch-journey-record.ts b/apps/electron-backend-e2e/src/performance/launch-journey-record.ts index 2ebae4c26..7539473e4 100644 --- a/apps/electron-backend-e2e/src/performance/launch-journey-record.ts +++ b/apps/electron-backend-e2e/src/performance/launch-journey-record.ts @@ -22,6 +22,7 @@ export const LAUNCH_JOURNEY_COUNTER = { DOM_MUTATIONS: 'renderer.domMutationsToFirstCard', IPC_CALLS: 'renderer.ipcCallsToFirstCard', LAYOUT_SHIFT_SCORE: 'renderer.layoutShiftScore', + LAYOUT_SHIFT_SCORE_SETTLED: 'renderer.layoutShiftScoreSettled', LONG_TASKS: 'renderer.longTasks', } as const; @@ -56,6 +57,11 @@ function roundTenth(value: number): number { return Math.round(value * 10) / 10; } +/** Layout-shift scores keep three decimals; see performance-journeys.md. */ +function roundThousandth(value: number): number { + return Math.round(value * 1_000) / 1_000; +} + export function toLaunchIterationRecord( index: number, warmup: boolean, @@ -77,6 +83,15 @@ export function toLaunchIterationRecord( ) { throw new Error('launch-journey-record-clock-order'); } + const { settle } = renderer; + if ( + (settle.status !== 'quiet' && settle.status !== 'cap') || + settle.epochMs === null || + renderer.firstCardPaintEpochMs === null || + settle.epochMs < renderer.firstCardPaintEpochMs + ) { + throw new Error(`launch-journey-record-settle-${settle.status}`); + } if ( renderer.capabilities.changeDetectionTicks !== 'unavailable-ng-global-not-published' @@ -98,8 +113,11 @@ export function toLaunchIterationRecord( [LAUNCH_JOURNEY_COUNTER.DOM_MUTATIONS]: renderer.counters.domMutations, [LAUNCH_JOURNEY_COUNTER.IPC_CALLS]: ipc.callsBeforeSentinel, - [LAUNCH_JOURNEY_COUNTER.LAYOUT_SHIFT_SCORE]: - Math.round(renderer.counters.layoutShiftScore * 1_000) / 1_000, + [LAUNCH_JOURNEY_COUNTER.LAYOUT_SHIFT_SCORE]: roundThousandth( + renderer.counters.layoutShiftScore + ), + [LAUNCH_JOURNEY_COUNTER.LAYOUT_SHIFT_SCORE_SETTLED]: + roundThousandth(renderer.counters.layoutShiftScoreSettled), [LAUNCH_JOURNEY_COUNTER.LONG_TASKS]: renderer.counters.longTasks, }), evidence: Object.freeze({ @@ -123,6 +141,7 @@ export function toLaunchIterationRecord( rendererGateBlankLoaded: measurement.gate.blankLoadedEpochMs, rendererGateReleased: measurement.gate.releasedEpochMs, rendererProbeInstalled: renderer.installed.epochMs, + settled: settle.epochMs, spawn: spawnEpochMs, }), firstCard: Object.freeze({ @@ -138,6 +157,14 @@ export function toLaunchIterationRecord( ipcCallsByMethod: ipc.callsByMethod, longTaskDurationsMs: renderer.longTaskDurationsMs.map(roundTenth), observedTarget: renderer.capabilities.observedTarget, + settle: Object.freeze({ + domMutations: settle.domMutations, + firstCardToSettledMs: roundTenth( + settle.epochMs - renderer.terminal.epochMs + ), + observedTarget: settle.observedTarget, + reason: settle.status, + }), }), index, pid: measurement.pid, diff --git a/apps/electron-backend-e2e/src/performance/open-source-journey-record.spec.ts b/apps/electron-backend-e2e/src/performance/open-source-journey-record.spec.ts index 656b60fac..52f86b1e9 100644 --- a/apps/electron-backend-e2e/src/performance/open-source-journey-record.spec.ts +++ b/apps/electron-backend-e2e/src/performance/open-source-journey-record.spec.ts @@ -30,6 +30,7 @@ function measurement( counters: { domMutations: 1_596, layoutShiftScore: 0.0004, + layoutShiftScoreSettled: 0, longTasks: 1, recentInputLayoutShiftScore: 0.22061, }, @@ -49,6 +50,13 @@ function measurement( preStart: { domMutations: 4, lastMutationEpochMs: 9_100 }, schemaVersion: 1, sentinel: { epochMs: 10_080.5, status: 'sent' }, + settle: { + domMutations: 0, + epochMs: null, + lastMutationEpochMs: null, + observedTarget: null, + status: 'disabled', + }, start: { epochMs: 10_000.2, listenerEpochMs: 10_001, diff --git a/docs/architecture/performance-journeys.md b/docs/architecture/performance-journeys.md index ac83bba1b..a09ca47d0 100644 --- a/docs/architecture/performance-journeys.md +++ b/docs/architecture/performance-journeys.md @@ -95,7 +95,8 @@ main-process counters below, which exist only with `IPTVNATOR_PERF_CAPTURE=1`: - `journey-renderer-probe.ts` is registered with `addInitScript` on that `about:blank` page, so it runs at the start of the real document. It records that it ran while the document was still `loading` with zero - scripts and emits one JSON blob under `window.__iptvnatorJourneyProbe`. + scripts and emits one JSON blob under `window.__iptvnatorJourneyProbe`, + complete once the [settle window](#settle-window) has closed. - `journey-main-ipc-capture.ts` subscribes to the preload's renderer-API trace channel (`IPTVNATOR_DEBUG_TRACE_EVENT`, enabled with `IPTVNATOR_TRACE_IPC=1`) through `electronApp.evaluate`, also before the @@ -109,8 +110,54 @@ main-process counters below, which exist only with `IPTVNATOR_PERF_CAPTURE=1`: | `renderer.ipcCallsToFirstCard` | `start` trace events the preload emits for every bridge invocation (listener registrations `on*`/`remove*` excluded, as in `wrapElectronApi`). The renderer probe fires one sentinel `cancelSourceProbe('__iptvnator-journey-sentinel__')` at the terminal moment; renderer-to-main IPC is ordered, so events before the sentinel are the exact count. The preload traces the call before forwarding it, and `SOURCE_HEALTH_CANCEL` only looks the id up in an in-memory map, so the sentinel never reaches the database worker. | | `renderer.domMutationsToFirstCard` | `MutationRecord`s (not callback batches) from a `MutationObserver` on the document element with `childList`, `attributes`, `characterData` and `subtree`. When the init script runs before `` exists the observer watches `document`, which the blob reports in `capabilities.observedTarget`. | | `renderer.layoutShiftScore` | Sum of `layout-shift` entries with `hadRecentInput === false`, rounded to three decimals (a shift of 0.0001 flips in and out of the cutoff between runs; the CLS "good" threshold is 0.1, so three decimals keep the counter exact without hiding anything a user could see). The cutoff is sampled in a timer queued from the first `requestAnimationFrame` after the terminal batch, that is after the frame that paints the card has been committed; entries delivered live after the terminal batch are buffered and filtered by the same cutoff. | +| `renderer.layoutShiftScoreSettled` | The same filter from navigation start until the settle point after the first card (see [Settle window](#settle-window)), rounded to three decimals. It catches shifts that land after the cutoff, such as skeletons that collapse once their data resolves. | | `renderer.longTasks` | `longtask` entries over 50 ms up to that same cutoff, which includes the task that rendered the card. The count depends on machine speed, so it is evidence until a run shows it is stable on the CI runner. | +#### Settle window + +`renderer.layoutShiftScore` stops at the first-card cutoff, one frame after +the terminal batch. A shift that lands later is invisible to it: in #1738, +rail skeletons of rails that resolved empty collapsed about 15 ms after the +first card and pulled the rails below upwards, a shift of about 0.23 on every +relaunch with sources that the counter read as 0. +`renderer.layoutShiftScoreSettled` sums the same entries until the page has +settled. The first-card counter is unchanged, so its baselines and history +stay comparable. + +The settle window opens at the first-card cutoff. A second +`MutationObserver` watches `main.workspace-content`, the workspace shell's +content pane (the document element if it is missing, reported in +`evidence.settle.observedTarget`). The window closes when nothing in that +subtree has mutated for 500 ms, or 3 s after the cutoff, whichever comes +first. The settle point is sampled when the timer fires, and every entry +that starts before it counts, including entries still queued in the +observer. Why this point: + +- A DOM change in the content pane is what causes the shifts this counter + is after (data resolving, skeletons swapped for content), so quiet in that + subtree is a condition the page reaches, not a guess at a delay. The rail + and header stay outside the watched subtree, so their own updates neither + keep the window open nor hide a shift in the content, which still counts + wherever it happens. +- 500 ms is longer than any frame and any local round trip to the mock in + the J1 profile, so data that is already on its way lands inside the window. + The window does not wait for idle timers and polling, which a user would + not see as part of the launch either. +- The 3 s cap bounds each iteration when something keeps mutating (an + animation, a ticking label). A capped window can end in the middle of that + activity, so `evidence.settle.reason` (`quiet` or `cap`) is recorded for + every iteration, together with `firstCardToSettledMs` and the mutation + records seen (`domMutations`). If iterations close for different reasons, + the counter is not deterministic and will show `stable: false`. + +Entries with `hadRecentInput === true` are excluded, as for the first-card +counter; J1 has no input. The probe keeps its layout-shift observer open +only for this window: `final` still marks the first-card counters as +frozen, `settle.status` moves from `pending` to `quiet` or `cap`, and the +test waits for both. The record refuses an iteration whose window never +closed or closed before the cutoff. J2's probe has no settle window +(`settle.status` is `disabled`) and its counters are unchanged. + #### Main-process counters With `IPTVNATOR_PERF_CAPTURE=1`, which the journey sets, @@ -231,11 +278,18 @@ serial-depth counter is a better guardrail candidate than a raw call count. }, "journeys": { "launch": { - "counters": { "renderer.ipcCallsToFirstCard": 12 }, + "counters": { + "renderer.ipcCallsToFirstCard": 12, + "renderer.layoutShiftScoreSettled": 0 + }, "counterStability": { "renderer.ipcCallsToFirstCard": { "stable": true, "values": [12, 12, 12, 12, 12] + }, + "renderer.layoutShiftScoreSettled": { + "stable": true, + "values": [0, 0, 0, 0, 0] } }, "wallClock": { @@ -250,7 +304,14 @@ serial-depth counter is a better guardrail candidate than a raw call count. "pid": 1, "counters": {}, "wallClock": {}, - "evidence": {} + "evidence": { + "settle": { + "domMutations": 42, + "firstCardToSettledMs": 612.4, + "observedTarget": "root", + "reason": "quiet" + } + } } ] } @@ -260,7 +321,9 @@ serial-depth counter is a better guardrail candidate than a raw call count. `journeys..counters.` and `journeys..wallClock.` are plain numbers so `tools/performance/check-journey-ratchet.mjs` can compare them with -`tools/performance/journey-baselines.json`. A J1 runtime baseline is added +`tools/performance/journey-baselines.json`. The summary writer checks only +that every measured iteration reports the same counter names with finite +values, so a new counter needs no schema change. A J1 runtime baseline is added once its counter is deterministic on the CI runner; the launch counters are not yet (see [Ratchet](#ratchet)), so the summary is evidence only. @@ -272,8 +335,8 @@ iteration copies it and spawns a fresh process through `runLaunchJourney`, which measures J1 as usual (gate, probe, IPC capture) and then hands the running app to `measureOpenSourceJourney` in `src/journeys/open-source-journey-app.ts`. The click therefore happens after -J1's terminal condition and its counters are final, and the two journeys never -overlap. One warm-up and five measured iterations, as for J1; the J1 numbers +J1's terminal condition and its counters are final, and after J1's settle +window has closed, so the two journeys never overlap. One warm-up and five measured iterations, as for J1; the J1 numbers of these launches are not reported again. J2 does not read J1's main-process counters, so its launches run without `IPTVNATOR_PERF_CAPTURE` and `IPTVNATOR_PERF_COUNT_SQL` (`runLaunchJourney` with