test(perf): show J3's HTTP boundary margins and watch 1 s after playing

Review follow-up. renderer.httpRequestsToPlaying compares the ledger's
arrival stamps with the renderer's click and playing stamps, which come
from different processes on the same host clock. Each iteration now
records the distance of the nearest request on either side of both
boundaries, so a count a clock difference could flip is visible.

Requests after playing were a single snapshot taken right after the
probe; the test now watches the ledger for a fixed 1 s after playing.
A live stream never leaves the mock quiet, so J2's quiet wait does not
apply.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
4grayandClaude Opus 5.5 committed 2026-10-01 06:30:13 +02:00
1 parent 4d7ad9c120
commit 6f58e135dd
4 files changed
+77 -5

No files matched your search

@@ -1,7 +1,10 @@
import type { ElectronApplication, Page } from '@playwright/test';
import { configureLiveFormat } from '../xtream-live-format.fixture';
import { waitForJourneyClickQuiet } from '../performance/journey-click-settle';
import {
JOURNEY_CLICK_QUIET_MS,
waitForJourneyClickQuiet,
} from '../performance/journey-click-settle';
import {
detachJourneyMainIpcCapture,
installJourneyMainIpcCapture,
@@ -16,7 +19,10 @@ import {
JOURNEY_OPEN_SOURCE_START_SELECTOR,
waitForJourneyRendererProbe,
} from '../performance/journey-renderer-probe';
import type { PlaybackJourneyMeasurement } from '../performance/playback-journey-record';
import {
PLAYBACK_JOURNEY_AFTER_PLAYING_WINDOW_MS,
type PlaybackJourneyMeasurement,
} from '../performance/playback-journey-record';
import type {
LaunchJourneySeedOptions,
LaunchJourneySession,
@@ -174,8 +180,19 @@ export async function measurePlaybackJourney(
if (clickEpochMs === undefined || playingEpochMs === undefined) {
throw new Error('playback-journey-probe-incomplete');
}
// A live stream never leaves the mock quiet, so instead of J2's quiet
// wait the ledger is watched for a fixed window after `playing`.
const afterPlayingUntilEpochMs =
playingEpochMs + PLAYBACK_JOURNEY_AFTER_PLAYING_WINDOW_MS;
const remainingMs =
afterPlayingUntilEpochMs - (performance.timeOrigin + performance.now());
if (remainingMs > 0) {
await new Promise((resolve) => setTimeout(resolve, remainingMs));
}
// The ledger stamps arrivals with this process's clock, the probe with
// the renderer's; both read the same host clock (as in J2).
// the renderer's; both read the same host clock (as in J2). The record
// keeps the distance of the nearest request to each boundary, so a
// count that a small clock difference could flip is visible.
const sinceSpawn = ledger.since(spawnLedgerMark);
const beforeClick = sinceSpawn.filter(
(entry) => entry.epochMs < clickEpochMs
@@ -185,7 +202,9 @@ export async function measurePlaybackJourney(
await readCancelledExternalArtwork(electronApp),
http: {
afterPlaying: sinceSpawn.filter(
(entry) => entry.epochMs >= playingEpochMs
(entry) =>
entry.epochMs >= playingEpochMs &&
entry.epochMs < afterPlayingUntilEpochMs
),
afterSettleBeforeClick: beforeClick.filter(
(entry) => entry.sequence >= settledLedgerMark
@@ -193,6 +193,12 @@ test('maps the media-terminated probe, IPC window and mock ledger to exact count
mainIpcStart: 10_001,
playing: 10_349.84,
});
// Click 10,000: last request before at 8,000, first after at 10,020.
// Playing 10,349.84: last before at 10,030, first after at 10,400.
assert.deepEqual(record.evidence['httpBoundaryMarginsMs'], {
click: 20,
playing: 50.2,
});
assert.equal(record.evidence['externalArtworkCancelled'], 8);
assert.equal(record.evidence['ipcCallsAfterPlaying'], 3);
});
@@ -33,6 +33,9 @@ export const PLAYBACK_JOURNEY_WALL_CLOCK = {
CLICK_TO_PLAYING: 'clickToPlayingMs',
} as const;
/** How long requests after `playing` are observed, for evidence only. */
export const PLAYBACK_JOURNEY_AFTER_PLAYING_WINDOW_MS = 1_000;
export const PLAYBACK_JOURNEY_UNAVAILABLE_COUNTERS: Readonly<
Record<string, string>
> = Object.freeze({
@@ -46,7 +49,7 @@ export interface PlaybackJourneyMeasurement {
/** Logo requests to picsum.photos cancelled in the main process. */
readonly externalArtworkCancelled: number;
readonly http: {
/** Requests at or after `playing` seen when the ledger was read. */
/** Requests in the first second after `playing`. */
readonly afterPlaying: readonly JourneyMockRequest[];
/** Mock requests after the app settled but before the click stamp. */
readonly afterSettleBeforeClick: number;
@@ -64,6 +67,24 @@ export interface PlaybackJourneyMeasurement {
const ROUTE_FRAGMENT = '/workspace/xtreams/';
const LIVE_STREAM_ROUTE = /^\/live\/:username\/:password\/[^/]+\.ts$/;
/**
* Distance of the nearest ledger request to a boundary on either side
* (null when there is none). The ledger and the renderer stamp with
* different processes' clocks; a small margin flags a count that a clock
* difference could move across the boundary.
*/
function boundaryMarginMs(
before: readonly JourneyMockRequest[],
after: readonly JourneyMockRequest[],
boundaryEpochMs: number
): number | null {
const distances = [
...before.map((entry) => boundaryEpochMs - entry.epochMs),
...after.map((entry) => entry.epochMs - boundaryEpochMs),
];
return distances.length === 0 ? null : roundTenth(Math.min(...distances));
}
function roundTenth(value: number): number {
return Math.round(value * 10) / 10;
}
@@ -160,6 +181,18 @@ export function toPlaybackIterationRecord(
http.beforeClick
),
httpRequestsByRoute: countJourneyMockRoutes(http.toPlaying),
httpBoundaryMarginsMs: Object.freeze({
click: boundaryMarginMs(
http.beforeClick,
http.toPlaying,
start.epochMs
),
playing: boundaryMarginMs(
http.toPlaying,
http.afterPlaying,
terminal.epochMs
),
}),
ipcCallsAfterPlaying: ipc.callsAfterSentinel,
ipcCallsByMethod: ipc.callsByMethod,
layoutShift: Object.freeze({
+14
View File
@@ -552,6 +552,20 @@ ignored.
| `renderer.layoutShiftScore` | All `layout-shift` entries from the click until the `playing` event, including `hadRecentInput` ones (as J2), rounded to three decimals. Entries delivered up to the post-paint cutoff are read, but only those that started by the event count. |
| `renderer.longTasks` | `longtask` entries over 50 ms whose time range overlaps the window from the click to the `playing` event, so the task that dispatched the event counts. Evidence until shown to be stable on the runner. |
`renderer.httpRequestsToPlaying` compares the ledger's arrival stamps
(test process) with the renderer's click and `playing` stamps. Both are
`performance.timeOrigin + performance.now()` on the same host clock, but the
two processes' time origins can differ by a fraction of a millisecond, so
every iteration records `evidence.httpBoundaryMarginsMs`: the distance of
the nearest request on either side of the click and of `playing`. A margin
of a few milliseconds means a clock difference could move that request
across the boundary. Locally the first request after the click arrives 3-6
ms after its stamp (the click causes it, so it cannot precede the click) and
the nearest request to `playing` is more than 170 ms away; both are well
above a sub-millisecond origin difference. `evidence.httpRequestsAfterPlayingByRoute` covers a fixed
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.
Two counters are listed under `unavailable`. `renderer.cdTicksToPlaying` is
missing for the same reason as in J1 and J2.
`renderer.ipcSerialDepthToPlaying` is missing because the serial-depth