From b1f77c678ecfd68f9509a1c5456703f51eae261d Mon Sep 17 00:00:00 2001 From: 4gray <4gray@users.noreply.github.com> Date: Wed, 29 Jul 2026 13:58:44 +0200 Subject: [PATCH] test(performance): prevent renderer heartbeat omission (#1308) * test(performance): normalize sub-ms IPC clock skew * test(performance): prevent heartbeat coordinated omission --- .../m3u-import-renderer-capture.spec.ts | 39 ++- .../m3u-import-renderer-capture.ts | 61 +++-- ...mport-renderer-heartbeat-lifecycle.spec.ts | 227 ++++++++++++++++++ .../performance/m3u-import-renderer-probe.ts | 41 +--- .../renderer-heartbeat-fixed-grid.spec.ts | 115 +++++++++ .../renderer-heartbeat-fixed-grid.ts | 97 ++++++++ .../xtream-iteration-assembly-phases.ts | 21 +- .../xtream-legacy-ipc-clock-skew.spec.ts | 53 ++++ .../xtream-renderer-capture.spec.ts | 22 +- .../performance/xtream-renderer-capture.ts | 60 +++-- .../xtream-renderer-probe-control.ts | 40 +-- .../performance/xtream-renderer-probe.spec.ts | 59 ++++- docs/architecture/m3u-playlist-module.md | 15 +- docs/architecture/xtream-mock-server.md | 7 + 14 files changed, 707 insertions(+), 150 deletions(-) create mode 100644 apps/electron-backend-e2e/src/performance/m3u-import-renderer-heartbeat-lifecycle.spec.ts create mode 100644 apps/electron-backend-e2e/src/performance/renderer-heartbeat-fixed-grid.spec.ts create mode 100644 apps/electron-backend-e2e/src/performance/renderer-heartbeat-fixed-grid.ts create mode 100644 apps/electron-backend-e2e/src/performance/xtream-legacy-ipc-clock-skew.spec.ts diff --git a/apps/electron-backend-e2e/src/performance/m3u-import-renderer-capture.spec.ts b/apps/electron-backend-e2e/src/performance/m3u-import-renderer-capture.spec.ts index a409caf69..41feed196 100644 --- a/apps/electron-backend-e2e/src/performance/m3u-import-renderer-capture.spec.ts +++ b/apps/electron-backend-e2e/src/performance/m3u-import-renderer-capture.spec.ts @@ -18,10 +18,6 @@ interface ImportProbe { } interface RendererCaptureModule { - advanceM3uImportHeartbeatDeadline?: ( - deadlineEpochMs: number, - nowEpochMs: number - ) => number; assertCompleteM3uImportRendererProbe?: (probe: ImportProbe) => void; startM3uImportRendererCapture?: unknown; } @@ -32,7 +28,7 @@ interface RendererProbeModule { recordM3uImportHeartbeat?: ( page: unknown, deadlineEpochMs: number - ) => Promise; + ) => Promise; stopM3uImportRendererProbe?: (page: unknown) => Promise; } @@ -248,12 +244,14 @@ test('clips drained long tasks and heartbeat samples to the operation window', a ); browser.setNow(250); - await module.recordM3uImportHeartbeat?.(browser.page, 90); - await module.recordM3uImportHeartbeat?.(browser.page, 150); - await module.recordM3uImportHeartbeat?.(browser.page, 210); + const nextDeadline = await module.recordM3uImportHeartbeat?.( + browser.page, + 150 + ); const metrics = await module.stopM3uImportRendererProbe?.(browser.page); - assert.deepEqual(metrics?.heartbeatDelaysMs, [50]); + assert.equal(nextDeadline, 250); + assert.deepEqual(metrics?.heartbeatDelaysMs, [50, 0]); assert.deepEqual(metrics?.longTasksMs, [20, 10]); } finally { browser.cleanup(); @@ -287,17 +285,6 @@ test('records the terminal animation-frame gap exactly once', async () => { } }); -test('advances the external heartbeat on its fixed 50ms deadline grid', async () => { - const module = await captureModulePromise; - assert.ok(module); - const advance = module.advanceM3uImportHeartbeatDeadline; - assert.equal(typeof advance, 'function'); - - assert.equal(advance?.(1_000, 1_005), 1_050); - assert.equal(advance?.(1_000, 1_060), 1_100); - assert.equal(advance?.(1_000, 1_200), 1_250); -}); - test('installs the production renderer phase hook and returns its raw events', () => { const source = readSource(probeUrl); assert.ok(source); @@ -377,6 +364,15 @@ test('fails closed when any terminal proof or the probe itself is missing', asyn test('clears the harness heap sampler even when the renderer probe is missing', () => { const source = readSource(captureUrl); assert.ok(source); + const stopBackgroundWork = source.indexOf('const stopBackgroundWork'); + const stopScheduling = source.indexOf( + 'stopSchedulingBackgroundWork()', + stopBackgroundWork + ); + const finalHeartbeat = source.indexOf( + 'await flushHeartbeat()', + stopScheduling + ); const backgroundStop = source.indexOf( 'await stopBackgroundWork()', source.indexOf('const stopCapture') @@ -384,6 +380,9 @@ test('clears the harness heap sampler even when the renderer probe is missing', const probeStop = source.indexOf('probe = await stopProbe()', backgroundStop); assert.match(source, /clearInterval\(heapSampleTimer\)/); + assert.ok(stopScheduling >= 0); + assert.ok(finalHeartbeat > stopScheduling); assert.ok(backgroundStop >= 0); assert.ok(probeStop > backgroundStop); + assert.match(source, /assertFixedGridRendererHeartbeatCoverage\(/); }); diff --git a/apps/electron-backend-e2e/src/performance/m3u-import-renderer-capture.ts b/apps/electron-backend-e2e/src/performance/m3u-import-renderer-capture.ts index db5bd80bf..c64219a1a 100644 --- a/apps/electron-backend-e2e/src/performance/m3u-import-renderer-capture.ts +++ b/apps/electron-backend-e2e/src/performance/m3u-import-renderer-capture.ts @@ -19,8 +19,10 @@ import { waitForM3uImportTerminal, } from './m3u-import-renderer-probe'; import { summarizeNumbers } from './performance-statistics'; - -const HEARTBEAT_INTERVAL_MS = 50; +import { + assertFixedGridRendererHeartbeatCoverage, + RENDERER_HEARTBEAT_INTERVAL_MS, +} from './renderer-heartbeat-fixed-grid'; export interface M3uImportRendererCaptureStartOptions { readonly diagnostic: boolean; @@ -156,30 +158,49 @@ export async function startM3uImportRendererCapture( heartbeatTimer = setTimeout( () => { heartbeatTimer = null; + if (stopped) { + return; + } heartbeatInFlight = recordM3uImportHeartbeat(page, deadline) + .then((nextDeadlineEpochMs) => { + heartbeatDeadlineEpochMs = nextDeadlineEpochMs; + }) .catch((error: unknown) => { heartbeatError ??= error; }) .finally(() => { heartbeatInFlight = null; - if (stopped) { + const gridClosed = + heartbeatDeadlineEpochMs === deadline; + if (stopped || heartbeatError !== null || gridClosed) return; - } - heartbeatDeadlineEpochMs = - advanceM3uImportHeartbeatDeadline( - deadline, - Date.now() - ); scheduleHeartbeat(); }); }, Math.max(0, deadline - Date.now()) ); }; + const flushHeartbeat = async (): Promise => { + await heartbeatInFlight; + if ( + heartbeatError !== null || + heartbeatDeadlineEpochMs === null + ) { + return; + } + try { + heartbeatDeadlineEpochMs = await recordM3uImportHeartbeat( + page, + heartbeatDeadlineEpochMs + ); + } catch (error) { + heartbeatError ??= error; + } + }; const stopBackgroundWork = (): Promise => { backgroundStopPromise ??= (async () => { stopSchedulingBackgroundWork(); - await heartbeatInFlight; + await flushHeartbeat(); await heapSamplePromise; await sampleHeap(); })(); @@ -243,6 +264,11 @@ export async function startM3uImportRendererCapture( throwCaptureError(heartbeatError, 'Renderer heartbeat failed'); throwCaptureError(probeError, 'Renderer probe stop failed'); assertCompleteM3uImportRendererProbe(probe); + assertFixedGridRendererHeartbeatCoverage( + probe.heartbeatDelaysMs, + probe.operationStartEpochMs, + probe.terminalEpochMs + ); return Object.freeze({ cpuProfilePath: artifacts.cpuProfilePath, frameGap: summarizeNumbers(probe.frameGapsMs), @@ -292,7 +318,7 @@ export async function startM3uImportRendererCapture( triggerImport: async () => { const operationStartEpochMs = await triggerM3uImport(page); heartbeatDeadlineEpochMs = - operationStartEpochMs + HEARTBEAT_INTERVAL_MS; + operationStartEpochMs + RENDERER_HEARTBEAT_INTERVAL_MS; scheduleHeartbeat(); return operationStartEpochMs; }, @@ -300,19 +326,6 @@ export async function startM3uImportRendererCapture( }); } -export function advanceM3uImportHeartbeatDeadline( - deadlineEpochMs: number, - nowEpochMs: number -): number { - const nextDeadline = deadlineEpochMs + HEARTBEAT_INTERVAL_MS; - if (nextDeadline > nowEpochMs) { - return nextDeadline; - } - const missedIntervals = - Math.floor((nowEpochMs - nextDeadline) / HEARTBEAT_INTERVAL_MS) + 1; - return nextDeadline + missedIntervals * HEARTBEAT_INTERVAL_MS; -} - export function assertCompleteM3uImportRendererProbe( probe: M3uImportRendererProbeMetrics | null | undefined ): asserts probe is M3uImportRendererProbeMetrics & { diff --git a/apps/electron-backend-e2e/src/performance/m3u-import-renderer-heartbeat-lifecycle.spec.ts b/apps/electron-backend-e2e/src/performance/m3u-import-renderer-heartbeat-lifecycle.spec.ts new file mode 100644 index 000000000..fd4be42b1 --- /dev/null +++ b/apps/electron-backend-e2e/src/performance/m3u-import-renderer-heartbeat-lifecycle.spec.ts @@ -0,0 +1,227 @@ +/* eslint-disable playwright/expect-expect -- This is a Node assertion-based lifecycle test. */ +import { RENDERER_PERFORMANCE_PHASE_HOOK_KEY } from '@iptvnator/shared/logging'; +import assert from 'node:assert/strict'; +import { EventEmitter } from 'node:events'; +import { mkdtemp, rm } from 'node:fs/promises'; +import { tmpdir } from 'node:os'; +import { join } from 'node:path'; +import test from 'node:test'; + +import { startM3uImportRendererCapture } from './m3u-import-renderer-capture'; +import { M3U_IMPORT_RENDERER_STATE_KEY } from './m3u-import-renderer-probe'; + +test('waits for an in-flight heartbeat and flushes its next deadline once', async () => { + const browser = installFakeBrowser(); + const outputDirectory = await mkdtemp( + join(tmpdir(), 'iptvnator-renderer-heartbeat-stop-') + ); + const session = new FakeCdpSession(); + const timerToken = Object.freeze({}); + const descriptors = snapshotGlobals([ + 'setTimeout', + 'clearTimeout', + 'document', + 'HTMLButtonElement', + ]); + let scheduledHeartbeat: (() => void) | null = null; + let releaseHeartbeat!: () => void; + const heartbeatGate = new Promise((resolve) => { + releaseHeartbeat = resolve; + }); + const deliveredDeadlines: number[] = []; + class FakeButton { + readonly disabled = false; + readonly textContent = 'Add playlist'; + click(): undefined { + return undefined; + } + } + const button = new FakeButton(); + replaceGlobal('HTMLButtonElement', FakeButton); + replaceGlobal('document', { + querySelector: () => null, + querySelectorAll: () => [ + { querySelectorAll: () => [button] }, + ], + }); + replaceGlobal('setTimeout', (callback: () => void) => { + scheduledHeartbeat = callback; + return timerToken; + }); + replaceGlobal('clearTimeout', () => undefined); + const page = createFakePage( + browser, + session, + async (callback, argument) => { + const heartbeat = argument as unknown as { + firstDeadlineEpochMs?: number; + }; + const result = await browser.page.evaluate(callback, argument); + if (typeof heartbeat.firstDeadlineEpochMs === 'number') { + deliveredDeadlines.push(heartbeat.firstDeadlineEpochMs); + if (deliveredDeadlines.length === 1) { + await heartbeatGate; + } + } + return result; + } + ); + + try { + const capture = await startM3uImportRendererCapture(page as never, { + diagnostic: false, + outputDirectory, + playlistTitle: 'Synthetic', + playlistUrl: + 'http://127.0.0.1:43210/synthetic-performance.m3u', + }); + browser.setNow(100); + await capture.triggerImport(); + browser.setNow(150); + assert.ok(scheduledHeartbeat); + scheduledHeartbeat(); + Object.assign(browser.readState() as object, { + firstChannelVisibleEpochMs: 220, + playlistId: 'synthetic-id', + routeReadyEpochMs: 200, + terminalEpochMs: 251, + uiPaintedEpochMs: 251, + }); + browser.setNow(300); + const stopPromise = capture.stop(); + await Promise.resolve(); + releaseHeartbeat(); + const metrics = await stopPromise; + + assert.deepEqual(deliveredDeadlines, [150, 200]); + assert.deepEqual(metrics.probe.heartbeatDelaysMs, [0, 51, 1]); + } finally { + restoreGlobals(descriptors); + browser.cleanup(); + await rm(outputDirectory, { force: true, recursive: true }); + } +}); + +class FakeCdpSession extends EventEmitter { + async detach(): Promise { + return undefined; + } + + async send(method: string): Promise> { + return method === 'Runtime.getHeapUsage' + ? { usedSize: 1_024 } + : {}; + } +} + +function installFakeBrowser() { + const descriptors = snapshotGlobals([ + 'performance', + 'PerformanceObserver', + 'cancelAnimationFrame', + 'requestAnimationFrame', + 'location', + 'document', + ]); + let nextFrameId = 1; + let nowMs = 0; + class FakePerformanceObserver { + static readonly supportedEntryTypes = ['longtask']; + disconnect(): undefined { + return undefined; + } + observe(): undefined { + return undefined; + } + takeRecords(): PerformanceEntry[] { + return []; + } + } + replaceGlobal('performance', { now: () => nowMs, timeOrigin: 0 }); + replaceGlobal('PerformanceObserver', FakePerformanceObserver); + replaceGlobal('cancelAnimationFrame', () => undefined); + replaceGlobal('requestAnimationFrame', () => nextFrameId++); + replaceGlobal('location', { pathname: '/' }); + replaceGlobal('document', { querySelector: () => null }); + + return { + cleanup: () => { + restoreGlobals(descriptors); + Reflect.deleteProperty( + globalThis, + Symbol.for(RENDERER_PERFORMANCE_PHASE_HOOK_KEY) + ); + Reflect.deleteProperty( + globalThis, + M3U_IMPORT_RENDERER_STATE_KEY + ); + }, + page: { + evaluate: async ( + callback: (argument: never) => unknown, + argument: never + ) => callback(argument), + }, + readState: () => + (globalThis as Record)[ + M3U_IMPORT_RENDERER_STATE_KEY + ], + setNow: (value: number) => { + nowMs = value; + }, + }; +} + +function createFakePage( + browser: ReturnType, + session: FakeCdpSession, + evaluate = browser.page.evaluate +) { + const control = { + click: async () => undefined, + fill: async () => undefined, + first: () => control, + getByRole: () => control, + isDisabled: async () => false, + last: () => control, + waitFor: async () => undefined, + }; + return { + ...browser.page, + context: () => ({ newCDPSession: async () => session }), + evaluate, + getByRole: () => control, + locator: () => control, + }; +} + +function snapshotGlobals( + keys: readonly string[] +): Map { + return new Map( + keys.map((key) => [ + key, + Object.getOwnPropertyDescriptor(globalThis, key), + ]) + ); +} + +function replaceGlobal(key: string, value: unknown): void { + Object.defineProperty(globalThis, key, { + configurable: true, + value, + writable: true, + }); +} + +function restoreGlobals( + descriptors: ReadonlyMap +): void { + for (const [key, descriptor] of descriptors) { + if (descriptor) { + Object.defineProperty(globalThis, key, descriptor); + } else { + Reflect.deleteProperty(globalThis, key); + } + } +} diff --git a/apps/electron-backend-e2e/src/performance/m3u-import-renderer-probe.ts b/apps/electron-backend-e2e/src/performance/m3u-import-renderer-probe.ts index 599abb88a..360a71cd9 100644 --- a/apps/electron-backend-e2e/src/performance/m3u-import-renderer-probe.ts +++ b/apps/electron-backend-e2e/src/performance/m3u-import-renderer-probe.ts @@ -5,6 +5,10 @@ import { type RendererPerformancePhaseHook, } from '@iptvnator/shared/logging'; +import { + recordFixedGridRendererHeartbeats, +} from './renderer-heartbeat-fixed-grid'; + export const M3U_IMPORT_RENDERER_STATE_KEY = '__iptvnatorM3uImportRendererCapture'; @@ -267,37 +271,12 @@ export async function triggerM3uImport(page: Page): Promise { export async function recordM3uImportHeartbeat( page: Page, deadlineEpochMs: number -): Promise { - await page.evaluate( - ({ deadlineEpochMs, stateKey }) => { - const target = globalThis as unknown as Record; - const state = target[stateKey] as - | { - heartbeatDelaysMs: number[]; - operationStartEpochMs: number; - terminalEpochMs: number | null; - } - | undefined; - if (!state || state.operationStartEpochMs <= 0) { - throw new Error('m3u-import-renderer-probe-unavailable'); - } - if ( - deadlineEpochMs >= state.operationStartEpochMs && - (state.terminalEpochMs === null || - deadlineEpochMs <= state.terminalEpochMs) - ) { - const receivedEpochMs = - performance.timeOrigin + performance.now(); - const measuredEpochMs = - state.terminalEpochMs === null - ? receivedEpochMs - : Math.min(receivedEpochMs, state.terminalEpochMs); - state.heartbeatDelaysMs.push( - Math.max(0, measuredEpochMs - deadlineEpochMs) - ); - } - }, - { deadlineEpochMs, stateKey: M3U_IMPORT_RENDERER_STATE_KEY } +): Promise { + return recordFixedGridRendererHeartbeats( + page, + M3U_IMPORT_RENDERER_STATE_KEY, + deadlineEpochMs, + 'm3u-import-renderer-probe-unavailable' ); } diff --git a/apps/electron-backend-e2e/src/performance/renderer-heartbeat-fixed-grid.spec.ts b/apps/electron-backend-e2e/src/performance/renderer-heartbeat-fixed-grid.spec.ts new file mode 100644 index 000000000..8c1611696 --- /dev/null +++ b/apps/electron-backend-e2e/src/performance/renderer-heartbeat-fixed-grid.spec.ts @@ -0,0 +1,115 @@ +/* eslint-disable playwright/expect-expect -- These are Node assertion-based performance contract tests. */ +import assert from 'node:assert/strict'; +import test from 'node:test'; + +interface HeartbeatModule { + assertFixedGridRendererHeartbeatCoverage?: ( + heartbeatDelaysMs: readonly number[], + operationStartEpochMs: number, + terminalEpochMs: number + ) => void; + recordFixedGridRendererHeartbeats?: ( + page: unknown, + stateKey: string, + firstDeadlineEpochMs: number, + unavailableError: string + ) => Promise; +} + +const moduleUrl = new URL( + './renderer-heartbeat-fixed-grid.ts', + import.meta.url +); +const modulePromise = import(moduleUrl.href) + .then((module) => module as HeartbeatModule) + .catch(() => null); + +test('fails closed when a fixed-grid renderer heartbeat deadline is omitted', async () => { + const module = await modulePromise; + assert.ok(module?.assertFixedGridRendererHeartbeatCoverage); + + assert.doesNotThrow(() => + module.assertFixedGridRendererHeartbeatCoverage?.( + [101, 51, 1], + 100, + 251 + ) + ); + assert.throws( + () => + module.assertFixedGridRendererHeartbeatCoverage?.( + [101, 1], + 100, + 251 + ), + /renderer-heartbeat-grid-incomplete:2\/3/ + ); + assert.throws( + () => + module.assertFixedGridRendererHeartbeatCoverage?.( + [101, 51, 1, 0], + 100, + 251 + ), + /renderer-heartbeat-grid-incomplete:4\/3/ + ); +}); + +test('keeps the first deadline unrecorded when the operation ends before it', async () => { + const module = await modulePromise; + assert.ok(module?.recordFixedGridRendererHeartbeats); + const stateKey = '__fixedGridShortOperation'; + const target = globalThis as unknown as Record; + const performanceDescriptor = Object.getOwnPropertyDescriptor( + globalThis, + 'performance' + ); + target[stateKey] = { + heartbeatDelaysMs: [], + operationStartEpochMs: 100, + terminalEpochMs: 149, + }; + Object.defineProperty(globalThis, 'performance', { + configurable: true, + value: { now: () => 200, timeOrigin: 0 }, + }); + const page = { + evaluate: async ( + callback: (argument: unknown) => unknown, + argument: unknown + ) => callback(argument), + }; + + try { + const nextDeadline = + await module.recordFixedGridRendererHeartbeats( + page, + stateKey, + 150, + 'synthetic-unavailable' + ); + assert.equal(nextDeadline, 150); + assert.deepEqual( + ( + target[stateKey] as { + heartbeatDelaysMs: number[]; + } + ).heartbeatDelaysMs, + [] + ); + } finally { + delete target[stateKey]; + restoreGlobal('performance', performanceDescriptor); + } +}); + +function restoreGlobal( + key: string, + descriptor: PropertyDescriptor | undefined +): void { + if (descriptor) { + Object.defineProperty(globalThis, key, descriptor); + } else { + Reflect.deleteProperty(globalThis, key); + } +} diff --git a/apps/electron-backend-e2e/src/performance/renderer-heartbeat-fixed-grid.ts b/apps/electron-backend-e2e/src/performance/renderer-heartbeat-fixed-grid.ts new file mode 100644 index 000000000..f17404080 --- /dev/null +++ b/apps/electron-backend-e2e/src/performance/renderer-heartbeat-fixed-grid.ts @@ -0,0 +1,97 @@ +import type { Page } from '@playwright/test'; + +export const RENDERER_HEARTBEAT_INTERVAL_MS = 50; + +interface RendererHeartbeatState { + readonly heartbeatDelaysMs: number[]; + readonly operationStartEpochMs: number; + readonly terminalEpochMs: number | null; +} + +export async function recordFixedGridRendererHeartbeats( + page: Page, + stateKey: string, + firstDeadlineEpochMs: number, + unavailableError: string +): Promise { + return page.evaluate( + ({ + firstDeadlineEpochMs, + intervalMs, + stateKey, + unavailableError, + }) => { + const state = (globalThis as unknown as Record)[ + stateKey + ] as RendererHeartbeatState | undefined; + if ( + !state || + !Number.isFinite(firstDeadlineEpochMs) || + state.operationStartEpochMs <= 0 || + firstDeadlineEpochMs < state.operationStartEpochMs + ) { + throw new Error(unavailableError); + } + const receivedEpochMs = + performance.timeOrigin + performance.now(); + const effectiveReceivedEpochMs = Math.max( + receivedEpochMs, + firstDeadlineEpochMs + ); + const captureEpochMs = + state.terminalEpochMs === null + ? effectiveReceivedEpochMs + : Math.min( + effectiveReceivedEpochMs, + state.terminalEpochMs + ); + if (captureEpochMs < firstDeadlineEpochMs) { + return firstDeadlineEpochMs; + } + const elapsedDeadlineCount = + Math.floor( + (captureEpochMs - firstDeadlineEpochMs) / intervalMs + ) + 1; + for (let index = 0; index < elapsedDeadlineCount; index += 1) { + const deadlineEpochMs = + firstDeadlineEpochMs + index * intervalMs; + state.heartbeatDelaysMs.push( + Math.max(0, captureEpochMs - deadlineEpochMs) + ); + } + return ( + firstDeadlineEpochMs + + elapsedDeadlineCount * intervalMs + ); + }, + { + firstDeadlineEpochMs, + intervalMs: RENDERER_HEARTBEAT_INTERVAL_MS, + stateKey, + unavailableError, + } + ); +} + +export function assertFixedGridRendererHeartbeatCoverage( + heartbeatDelaysMs: readonly number[], + operationStartEpochMs: number, + terminalEpochMs: number +): void { + if ( + !Number.isFinite(operationStartEpochMs) || + !Number.isFinite(terminalEpochMs) || + terminalEpochMs < operationStartEpochMs + ) { + throw new Error('renderer-heartbeat-grid-window-invalid'); + } + const expectedCount = Math.floor( + (terminalEpochMs - operationStartEpochMs) / + RENDERER_HEARTBEAT_INTERVAL_MS + ); + if (heartbeatDelaysMs.length !== expectedCount) { + throw new Error( + `renderer-heartbeat-grid-incomplete:${heartbeatDelaysMs.length}/${expectedCount}` + ); + } +} diff --git a/apps/electron-backend-e2e/src/performance/xtream-iteration-assembly-phases.ts b/apps/electron-backend-e2e/src/performance/xtream-iteration-assembly-phases.ts index 80191208b..866ab424c 100644 --- a/apps/electron-backend-e2e/src/performance/xtream-iteration-assembly-phases.ts +++ b/apps/electron-backend-e2e/src/performance/xtream-iteration-assembly-phases.ts @@ -35,6 +35,7 @@ const LEGACY_METHODS = Object.freeze({ DB_GET_APP_PLAYLIST: 'dbGetAppPlaylist', DB_UPSERT_APP_PLAYLIST: 'dbUpsertAppPlaylist', }); +const LEGACY_RESPONSE_CLOCK_SKEW_TOLERANCE_MS = 1; export function deriveXtreamPhaseCapture( scenarioId: XtreamPhaseAttributionInput['scenarioId'], @@ -263,6 +264,10 @@ function legacyIpcPair( const requestTimeline = oneTimeline(main, request, 'db-request'); const success = oneTimeline(main, request, 'preload-performance-success'); const responseStartEpochMs = requireEpoch(request.responseEpochMs); + const responseEndEpochMs = normalizeLegacyResponseEndEpochMs( + requireEpoch(success.sourceEpochMs), + responseStartEpochMs + ); const correlationId = xtreamIpcProducerIdentityKey( XTREAM_IPC_PRODUCER_NAMESPACE.LEGACY_PRELOAD, ipcCallId @@ -281,7 +286,7 @@ function legacyIpcPair( { boundary: 'response', correlationId, - endEpochMs: requireEpoch(success.sourceEpochMs), + endEpochMs: responseEndEpochMs, ipcCallId, method, outcome: 'success', @@ -291,6 +296,20 @@ function legacyIpcPair( ]; } +function normalizeLegacyResponseEndEpochMs( + endEpochMs: number, + startEpochMs: number +): number { + if (endEpochMs >= startEpochMs) return endEpochMs; + if ( + startEpochMs - endEpochMs >= + LEGACY_RESPONSE_CLOCK_SKEW_TOLERANCE_MS + ) { + invalid(); + } + return startEpochMs; +} + function oneTimeline( main: XtreamMainCaptureResult, request: WorkerRequestPerformanceMetrics, diff --git a/apps/electron-backend-e2e/src/performance/xtream-legacy-ipc-clock-skew.spec.ts b/apps/electron-backend-e2e/src/performance/xtream-legacy-ipc-clock-skew.spec.ts new file mode 100644 index 000000000..ad9a99ab8 --- /dev/null +++ b/apps/electron-backend-e2e/src/performance/xtream-legacy-ipc-clock-skew.spec.ts @@ -0,0 +1,53 @@ +import assert from 'node:assert/strict'; +import { describe, it } from 'node:test'; + +import { XTREAM_SCENARIO_ID } from './xtream-benchmark-contract'; +import { assembleXtreamRawIteration } from './xtream-iteration-assembler'; +import { createXtreamAssemblerFixture } from './xtream-iteration-assembler.fixture'; + +describe('Xtream legacy IPC clock skew', () => { + it('normalizes sub-millisecond response skew and rejects larger reversals', () => { + const input = createXtreamAssemblerFixture( + XTREAM_SCENARIO_ID.REFRESH_LARGE + ); + const request = input.mainCapture.requests.find( + ({ operation }) => operation === 'DB_UPSERT_APP_PLAYLIST' + ); + assert.equal(typeof request?.responseEpochMs, 'number'); + const updateSuccessEpoch = (sourceEpochMs: number) => ({ + ...input, + mainCapture: { + ...input.mainCapture, + capture: { + ...input.mainCapture.capture, + timeline: input.mainCapture.capture.timeline.map((record) => + record.type === 'preload-performance-success' && + record.ipcCallId === request?.ipcCallId && + record.operation === request.operation + ? { ...record, sourceEpochMs } + : record + ), + }, + }, + }); + + const normalized = assembleXtreamRawIteration( + updateSuccessEpoch(Number(request?.responseEpochMs) - 0.25) + ); + const response = normalized.phaseCapture.ipcSpans.find( + ({ boundary, method }) => + boundary === 'response' && + method === 'dbUpsertAppPlaylist' + ); + assert.ok(response); + assert.equal(response.endEpochMs, response.startEpochMs); + + assert.throws( + () => + assembleXtreamRawIteration( + updateSuccessEpoch(Number(request?.responseEpochMs) - 1) + ), + /xtream-iteration-assembly-invalid/ + ); + }); +}); diff --git a/apps/electron-backend-e2e/src/performance/xtream-renderer-capture.spec.ts b/apps/electron-backend-e2e/src/performance/xtream-renderer-capture.spec.ts index 3ef5503ec..4b8d9ff01 100644 --- a/apps/electron-backend-e2e/src/performance/xtream-renderer-capture.spec.ts +++ b/apps/electron-backend-e2e/src/performance/xtream-renderer-capture.spec.ts @@ -3,10 +3,6 @@ import { readFileSync } from 'node:fs'; import test from 'node:test'; interface CaptureModule { - advanceXtreamRendererHeartbeatDeadline?: ( - deadlineEpochMs: number, - nowEpochMs: number - ) => number; selectXtreamRendererTarget?: (session: FakeSession) => Promise; startXtreamRendererCapture?: unknown; } @@ -122,7 +118,7 @@ test('arms the renderer without sampling heap or starting diagnostics before the assert.ok(diagnosticStart > operationBoundary); assert.ok(heapTimerStart > operationBoundary); assert.equal(source.match(/await sampleHeap\(\)/g)?.length, 1); - assert.match(source, /HEARTBEAT_INTERVAL_MS\s*=\s*50/); + assert.match(source, /RENDERER_HEARTBEAT_INTERVAL_MS/); assert.match(source, /Runtime\.getHeapUsage/); assert.match(source, /HeapProfiler\.collectGarbage/); assert.match(source, /createRendererArtifactCapture/); @@ -202,6 +198,10 @@ test('cuts off scheduling and diagnostics before forced GC and snapshot work', ( const source = readFileSync(captureUrl, 'utf8'); const stopCapture = source.indexOf('const stopCapture'); const stopScheduling = source.indexOf('stopScheduling()', stopCapture); + const finalHeartbeat = source.indexOf( + 'await flushHeartbeat()', + stopScheduling + ); const diagnosticStop = source.indexOf( 'await stopRendererDiagnosticCapture(session, artifacts)', stopCapture @@ -217,9 +217,11 @@ test('cuts off scheduling and diagnostics before forced GC and snapshot work', ( assert.ok(stopCapture >= 0); assert.ok(stopScheduling > stopCapture); - assert.ok(diagnosticStop > stopScheduling); + assert.ok(finalHeartbeat > stopScheduling); + assert.ok(diagnosticStop > finalHeartbeat); assert.ok(forcedGc > diagnosticStop); assert.ok(heapSnapshot > forcedGc); + assert.match(source, /assertFixedGridRendererHeartbeatCoverage\(/); }); test('persists only error counts and cleans up listeners/session idempotently', () => { @@ -232,11 +234,3 @@ test('persists only error counts and cleans up listeners/session idempotently', assert.match(source, /page\.off\('pageerror'/); assert.match(source, /disposePromise/); }); - -test('uses deadline-based heartbeat catch-up without accumulating drift', async () => { - const module = await modulePromise; - assert.ok(module?.advanceXtreamRendererHeartbeatDeadline); - - assert.equal(module.advanceXtreamRendererHeartbeatDeadline(150, 149), 200); - assert.equal(module.advanceXtreamRendererHeartbeatDeadline(150, 251), 300); -}); diff --git a/apps/electron-backend-e2e/src/performance/xtream-renderer-capture.ts b/apps/electron-backend-e2e/src/performance/xtream-renderer-capture.ts index 71aa99b8a..cdc0519a3 100644 --- a/apps/electron-backend-e2e/src/performance/xtream-renderer-capture.ts +++ b/apps/electron-backend-e2e/src/performance/xtream-renderer-capture.ts @@ -30,8 +30,10 @@ import { recordXtreamRendererConsoleError, type XtreamRendererConsoleErrorBreakdown, } from './xtream-renderer-console-errors'; - -const HEARTBEAT_INTERVAL_MS = 50; +import { + assertFixedGridRendererHeartbeatCoverage, + RENDERER_HEARTBEAT_INTERVAL_MS, +} from './renderer-heartbeat-fixed-grid'; export interface XtreamRendererCaptureOptions { readonly diagnostic: boolean; @@ -210,27 +212,46 @@ export async function startXtreamRendererCapture( heartbeatTimer = setTimeout( () => { heartbeatTimer = null; + if (stopped) return; heartbeatInFlight = recordXtreamRendererHeartbeat( page, deadline ) + .then((nextDeadlineEpochMs) => { + heartbeatDeadlineEpochMs = nextDeadlineEpochMs; + }) .catch((error: unknown) => { heartbeatError ??= error; }) .finally(() => { heartbeatInFlight = null; - if (stopped) return; - heartbeatDeadlineEpochMs = - advanceXtreamRendererHeartbeatDeadline( - deadline, - Date.now() - ); + const gridClosed = + heartbeatDeadlineEpochMs === deadline; + if (stopped || heartbeatError !== null || gridClosed) + return; scheduleHeartbeat(); }); }, Math.max(0, deadline - Date.now()) ); }; + const flushHeartbeat = async (): Promise => { + await heartbeatInFlight; + if ( + heartbeatError !== null || + heartbeatDeadlineEpochMs === null + ) { + return; + } + try { + heartbeatDeadlineEpochMs = await recordXtreamRendererHeartbeat( + page, + heartbeatDeadlineEpochMs + ); + } catch (error) { + heartbeatError ??= error; + } + }; const stopCapture = async (): Promise => { try { stopScheduling(); @@ -238,10 +259,10 @@ export async function startXtreamRendererCapture( if (measurementStartEpochMs === null) { throw new Error('xtream-renderer-operation-not-started'); } + await flushHeartbeat(); if (options.diagnostic) { await stopRendererDiagnosticCapture(session, artifacts); } - await heartbeatInFlight; await heapInFlight; const probe = await stopXtreamRendererProbe(page); await session.send('HeapProfiler.enable'); @@ -260,6 +281,11 @@ export async function startXtreamRendererCapture( throwIfError(heapError, 'xtream-renderer-heap-sampling-failed'); throwIfError(heartbeatError, 'xtream-renderer-heartbeat-failed'); assertCompleteXtreamRendererProbe(probe); + assertFixedGridRendererHeartbeatCoverage( + probe.heartbeatDelaysMs, + probe.operationStartEpochMs, + probe.terminalEpochMs + ); assertRendererMeasurementWindow({ captureCutoffEpochMs, measurementStartEpochMs, @@ -328,7 +354,8 @@ export async function startXtreamRendererCapture( await sampleHeap(); throwIfError(heapError, 'xtream-renderer-heap-sampling-failed'); heapTimer = setInterval(() => void sampleHeap(), 20); - heartbeatDeadlineEpochMs = startedAt + HEARTBEAT_INTERVAL_MS; + heartbeatDeadlineEpochMs = + startedAt + RENDERER_HEARTBEAT_INTERVAL_MS; scheduleHeartbeat(); return startedAt; }, @@ -348,19 +375,6 @@ export async function startXtreamRendererCapture( }); } -export function advanceXtreamRendererHeartbeatDeadline( - deadlineEpochMs: number, - nowEpochMs: number -): number { - const next = deadlineEpochMs + HEARTBEAT_INTERVAL_MS; - if (next > nowEpochMs) return next; - return ( - next + - (Math.floor((nowEpochMs - next) / HEARTBEAT_INTERVAL_MS) + 1) * - HEARTBEAT_INTERVAL_MS - ); -} - function removePageErrorListeners( page: Page, onConsole: (message: ConsoleMessage) => void, diff --git a/apps/electron-backend-e2e/src/performance/xtream-renderer-probe-control.ts b/apps/electron-backend-e2e/src/performance/xtream-renderer-probe-control.ts index 5e6b73cfb..2b4e64bd8 100644 --- a/apps/electron-backend-e2e/src/performance/xtream-renderer-probe-control.ts +++ b/apps/electron-backend-e2e/src/performance/xtream-renderer-probe-control.ts @@ -7,6 +7,9 @@ import { XTREAM_RENDERER_STOPPED_KEY, type XtreamRendererProbeMetrics, } from './xtream-renderer-probe-contract'; +import { + recordFixedGridRendererHeartbeats, +} from './renderer-heartbeat-fixed-grid'; export async function beginXtreamRendererOperation( page: Page @@ -33,37 +36,12 @@ export async function beginXtreamRendererOperation( export async function recordXtreamRendererHeartbeat( page: Page, deadlineEpochMs: number -): Promise { - await page.evaluate( - ({ deadlineEpochMs, stateKey }) => { - const state = (globalThis as unknown as Record)[ - stateKey - ] as - | { - heartbeatDelaysMs: number[]; - operationStartEpochMs: number; - terminalEpochMs: number | null; - } - | undefined; - if (!state || state.operationStartEpochMs <= 0) { - throw new Error('xtream-renderer-probe-unavailable'); - } - if ( - deadlineEpochMs >= state.operationStartEpochMs && - (state.terminalEpochMs === null || - deadlineEpochMs <= state.terminalEpochMs) - ) { - const received = performance.timeOrigin + performance.now(); - state.heartbeatDelaysMs.push( - Math.max( - 0, - Math.min(received, state.terminalEpochMs ?? received) - - deadlineEpochMs - ) - ); - } - }, - { deadlineEpochMs, stateKey: XTREAM_RENDERER_STATE_KEY } +): Promise { + return recordFixedGridRendererHeartbeats( + page, + XTREAM_RENDERER_STATE_KEY, + deadlineEpochMs, + 'xtream-renderer-probe-unavailable' ); } diff --git a/apps/electron-backend-e2e/src/performance/xtream-renderer-probe.spec.ts b/apps/electron-backend-e2e/src/performance/xtream-renderer-probe.spec.ts index 99047cbba..1af2bc63a 100644 --- a/apps/electron-backend-e2e/src/performance/xtream-renderer-probe.spec.ts +++ b/apps/electron-backend-e2e/src/performance/xtream-renderer-probe.spec.ts @@ -26,7 +26,7 @@ interface ProbeModule { recordXtreamRendererHeartbeat?: ( page: unknown, deadlineEpochMs: number - ) => Promise; + ) => Promise; stopXtreamRendererProbe?: (page: unknown) => Promise; waitForXtreamRendererTerminal?: (page: unknown) => Promise; } @@ -81,6 +81,52 @@ test('requires a final store marker, DOM gate, and two rendered frames', () => { assert.match(source, />=\s*2/); }); +test('records every elapsed fixed-grid heartbeat deadline in one renderer delivery', async () => { + const module = await modulePromise; + assert.ok(module?.recordXtreamRendererHeartbeat); + assert.ok(module.XTREAM_RENDERER_STATE_KEY); + const performanceDescriptor = Object.getOwnPropertyDescriptor( + globalThis, + 'performance' + ); + const target = globalThis as unknown as Record; + const stateKey = module.XTREAM_RENDERER_STATE_KEY; + const page = { + evaluate: async ( + callback: (argument: unknown) => unknown, + argument: unknown + ) => callback(argument), + }; + target[stateKey] = { + heartbeatDelaysMs: [], + operationStartEpochMs: 100, + terminalEpochMs: null, + }; + Object.defineProperty(globalThis, 'performance', { + configurable: true, + value: { now: () => 251, timeOrigin: 0 }, + }); + + try { + const nextDeadline = await module.recordXtreamRendererHeartbeat( + page, + 150 + ); + assert.equal(nextDeadline, 300); + assert.deepEqual( + ( + target[stateKey] as { + heartbeatDelaysMs: number[]; + } + ).heartbeatDelaysMs, + [101, 51, 1] + ); + } finally { + delete target[stateKey]; + restoreGlobal('performance', performanceDescriptor); + } +}); + test('rejects incomplete and internally inconsistent terminal evidence', async () => { const module = await modulePromise; assert.ok(module?.assertCompleteXtreamRendererProbe); @@ -208,3 +254,14 @@ function backgroundRefreshState(identity: { terminalEpochMs: null, }; } + +function restoreGlobal( + key: string, + descriptor: PropertyDescriptor | undefined +): void { + if (descriptor) { + Object.defineProperty(globalThis, key, descriptor); + } else { + Reflect.deleteProperty(globalThis, key); + } +} diff --git a/docs/architecture/m3u-playlist-module.md b/docs/architecture/m3u-playlist-module.md index 6c177858f..fb21681d1 100644 --- a/docs/architecture/m3u-playlist-module.md +++ b/docs/architecture/m3u-playlist-module.md @@ -128,11 +128,16 @@ therefore `N/A` with Instrumentation is development-only, opt-in, fail-neutral, and count-only. It must not scan or log playlist payloads to generate metadata. Renderer long-task, frame-gap, and heartbeat samples are clipped to the measured -operation boundary. Main capture stops only after the upsert and route-reload -GET responses plus both asynchronous preload success markers have arrived, so -return-clone attribution cannot race capture shutdown. Formal comparison fails -closed after writing raw results if exact-window renderer RSS, database-worker -peak heap/external samples, or the database worker's explicit post-GC heap is +operation boundary. The external heartbeat uses a fixed 50 ms deadline grid: +each renderer delivery records every elapsed deadline, and successful shutdown +performs one terminal-clipped drain after any in-flight delivery. The capture +fails closed unless the final sample count matches the complete operation +grid, preventing coordinated omission when an import blocks several ticks. +Main capture stops only after the upsert and route-reload GET responses plus +both asynchronous preload success markers have arrived, so return-clone +attribution cannot race capture shutdown. Formal comparison fails closed after +writing raw results if exact-window renderer RSS, database-worker peak +heap/external samples, or the database worker's explicit post-GC heap is missing or incoherent. Both initial-import database requests in every measured run must also contain coherent event-loop delay, event-loop utilization, and thread-CPU metrics; the validity record exposes the exact expected and valid diff --git a/docs/architecture/xtream-mock-server.md b/docs/architecture/xtream-mock-server.md index 21450390d..8ca8141ba 100644 --- a/docs/architecture/xtream-mock-server.md +++ b/docs/architecture/xtream-mock-server.md @@ -488,6 +488,13 @@ installing main capture. Its result is discarded: this pre-arm only guarantees that the exact worker can be profiled and happens before seed or measured capture. +The renderer heartbeat is sampled on a fixed 50 ms deadline grid. One CDP +delivery records every elapsed grid point, and successful capture shutdown +waits for an in-flight delivery before performing one terminal-clipped drain. +The iteration fails closed if the resulting sample count does not cover the +complete operation window; this avoids coordinated omission when renderer work +delays multiple heartbeat deadlines. + Diagnostic profiles are evidence envelopes, not comparison totals. Starting Chromium tracing and the CPU profilers can add a short pre-trigger setup segment that contains no application workload; the raw boundary timestamps preserve