pcbjam/tests/kicad/utils/perf-utils.ts
Viktor Vaczi f419a1fedd build+perf: wasm-opt the shipped wasm, and measure real frames in CI
emcc only runs Binaryen at link -O2+ (link.py: should_run_binaryen_optimizer
returns OPT_LEVEL >= 2) and we link at -O1, so the shipped module had never seen
wasm-opt at all — it kept its entire 19.56 MB name section, ~20% of the editor
(-sJSPI sets ASYNCIFY=2, which suppresses wasm-ld's --strip-debug, leaving
wasm-opt as the only thing that would drop it). Step 8.2 runs it post-link and
in-container, so CI's cached compile phase covers it and the host post-process
stays pure-host.

Default -O2, picked by measuring every level on the same module: -O0 already
captures 27% of the raw win (it is mostly the name section), -O2 costs 23 s and
gives the best frame rate, and -O3/-O4/-Os/-Oz cost 48-132 s for at most 1.5%
more brotli — -O4 is not even smaller than -O3. Targets that already link -O2/-Oz
(occ_service, kicad_tools) are skipped by testing for the target_features
section, which emcc strips whenever it ran the optimizer itself, so there is no
hard-coded target list to drift. Feature flags come from the module's own
target_features section and so cannot diverge from the link.

The perf specs reported requestAnimationFrame ticks as "FPS". That is not a frame
rate: rAF fires on the compositor's schedule whether or not the GAL redrew, and
it read 120/s on a board where the renderer completed zero frames in six seconds.
measureInteractionFps now counts completed GAL frames — runs of draws to the
default framebuffer, exactly one per frame in every AA mode — and drives a pure
middle-drag pan after a zoom-to-fit. Mixing wheel zoom into the drive made the
result depend on where the wheel left the view: +-20% across identical repeats,
against +-2% for pan alone. The report gains a GAL fps column with a regression
flag on the 1x number; rAF is kept so historical runs stay comparable.

CI has no GPU, so its number is a software-rasteriser redraw rate — a regression
signal, not a user-facing frame rate. Method and measurements in the bench report.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_016X9eh1s5sTx1o9Em9KBuwR
2026-08-22 12:53:00 +02:00

417 lines
18 KiB
TypeScript
Raw Permalink Blame History

This file contains ambiguous Unicode characters

This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.

import * as fs from 'fs';
import * as path from 'path';
import type { Page, CDPSession } from '@playwright/test';
import { injectFileIntoMemfs } from './fs-inject';
import { waitForBoardLoaded } from './board-ready';
/**
* Runtime-perf helpers for the track-only perf specs (eeschema-perf, pcbnew-perf).
*
* Measures the CURRENT build (whatever setup:kicad staged into tests/apps/kicad/):
* cold load, open+render time, and interaction FPS. No version A/B, no gating —
* results are logged and written to tests/test-results/perf-<app>.json (gitignored,
* uploaded by CI). The measurement logic (the #canvas real-input FPS driver, the
* ready-signal, CDP throttling) is lifted from the validated native-vs-JS-EH
* benchmark harness — see docs/features/wasm-exceptions/12-native-vs-jseh-benchmark.md.
*/
const MAIN_CANVAS = '#canvas';
const RESULTS_DIR = path.join(__dirname, '..', '..', 'test-results');
type KicadModule = { kicadOpenFile(p: string): unknown };
/** Fully booted editor: visible canvas + wx registry + kicadOpenFile hook + a top-level *Frame. */
export async function waitForReady(page: Page, timeout = 120000): Promise<void> {
await page.locator(MAIN_CANVAS).waitFor({ state: 'visible', timeout });
await page.waitForFunction(() => !!window.wxElementRegistry, null, { timeout });
await page.waitForFunction(
() =>
typeof (window as unknown as { Module?: KicadModule }).Module?.kicadOpenFile === 'function',
null,
{ timeout },
);
await page.waitForFunction(
() =>
!!window.wxElementRegistry &&
window.wxElementRegistry
.findAll({ visible: true })
.some((e) => /Frame$/.test(e.typeName) || (e.name || '').endsWith('Frame')),
null,
{ timeout },
);
}
/** Cold load: navigate then wait until fully ready. Returns ms. */
export async function measureLoad(page: Page, url: string, timeout = 120000): Promise<number> {
const t0 = Date.now();
await page.goto(url, { waitUntil: 'commit', timeout });
await waitForReady(page, timeout);
return Date.now() - t0;
}
/**
* Open a document via Module.kicadOpenFile and wait until it's loaded+rendered.
* 'schematic' polls the editor title; 'board' uses the pcbnew progress-dialog signal.
* Returns ms.
*/
export async function measureOpenRender(
page: Page,
hostPath: string,
kind: 'schematic' | 'board',
logger: { consoleLogs: string[]; errors: string[] },
timeout = 120000,
): Promise<number> {
const ext = kind === 'board' ? 'kicad_pcb' : 'kicad_sch';
const memfsPath = `/home/kicad/documents/perf-demo.${ext}`;
await injectFileIntoMemfs(page, hostPath, memfsPath);
return openAndWait(page, memfsPath, kind, logger, timeout);
}
/**
* Open an ALREADY-INJECTED memfs document and wait until loaded+rendered.
* Split out of measureOpenRender so large fixtures can arrive via
* fetchIntoMemfs (or any other route) and still get the same timed open.
*/
export async function openAndWait(
page: Page,
memfsPath: string,
kind: 'schematic' | 'board',
logger: { consoleLogs: string[]; errors: string[] },
timeout = 120000,
): Promise<number> {
const stem = memfsPath.replace(/^.*\//, '').replace(/\.[^.]+$/, '');
const t0 = Date.now();
await page.evaluate((p) => {
(window as unknown as { Module: KicadModule }).Module.kicadOpenFile(p);
}, memfsPath);
if (kind === 'board') {
await waitForBoardLoaded(page, logger, timeout);
} else {
const deadline = Date.now() + timeout;
while (Date.now() < deadline) {
if (new RegExp(stem, 'i').test(await page.title())) break;
await page.waitForTimeout(200);
}
}
return Date.now() - t0;
}
export interface MemorySample {
/** WebAssembly linear memory size (Module.HEAPU8.byteLength). */
wasmHeapBytes: number;
/** Chromium-only usedJSHeapSize; 0 elsewhere. */
jsHeapBytes: number;
}
/** One-shot memory census — portable across builds (HEAPU8 verified reachable in both). */
export async function sampleMemory(page: Page): Promise<MemorySample> {
return await page.evaluate(() => {
const w = window as unknown as {
Module?: { HEAPU8?: { byteLength: number }; wasmMemory?: { buffer: ArrayBuffer } };
};
const perf = performance as unknown as { memory?: { usedJSHeapSize: number } };
return {
wasmHeapBytes:
w.Module?.wasmMemory?.buffer?.byteLength ?? w.Module?.HEAPU8?.byteLength ?? 0,
jsHeapBytes: perf.memory?.usedJSHeapSize ?? 0,
};
});
}
/**
* In-page wasm-heap peak sampler (250 ms). Start before a heavy operation
* (board open), stop after — returns the max linear-memory size observed.
*/
export async function startHeapPeakSampler(page: Page): Promise<void> {
await page.evaluate(() => {
const w = window as unknown as {
Module?: { HEAPU8?: { byteLength: number }; wasmMemory?: { buffer: ArrayBuffer } };
__heapPeak?: number;
__heapPeakTimer?: number;
};
if (w.__heapPeakTimer !== undefined) clearInterval(w.__heapPeakTimer);
w.__heapPeak = 0;
w.__heapPeakTimer = setInterval(() => {
const b =
w.Module?.wasmMemory?.buffer?.byteLength ?? w.Module?.HEAPU8?.byteLength ?? 0;
if (b > (w.__heapPeak ?? 0)) w.__heapPeak = b;
}, 250) as unknown as number;
});
}
export async function stopHeapPeakSampler(page: Page): Promise<number> {
return await page.evaluate(() => {
const w = window as unknown as { __heapPeak?: number; __heapPeakTimer?: number };
if (w.__heapPeakTimer !== undefined) clearInterval(w.__heapPeakTimer);
w.__heapPeakTimer = undefined;
return w.__heapPeak ?? 0;
});
}
/** Resource-timing attribution for the main wasm fetch (download share of loadMs). */
export async function getWasmResourceTiming(
page: Page,
): Promise<{ durationMs: number; transferSize: number } | null> {
return await page.evaluate(() => {
const e = performance
.getEntriesByType('resource')
.find((r) => r.name.includes('kicad_editor.wasm')) as PerformanceResourceTiming | undefined;
return e ? { durationMs: Math.round(e.duration), transferSize: e.transferSize } : null;
});
}
/** CDP CPU throttling (Chromium only): 1 = none, N = N× slower. */
export async function setThrottle(cdp: CDPSession, rate: number): Promise<void> {
await cdp.send('Emulation.setCPUThrottlingRate', { rate });
}
/**
* Count completed GAL frames instead of rAF ticks.
*
* A GAL frame ends with the compositor blitting to the DEFAULT framebuffer, so a
* run of draws issued while no framebuffer is bound is exactly one frame. The run
* has to be collapsed: the number of present draws per frame depends on the AA
* mode (1 under supersampling, 2 under AA_NONE, +1 when the crosshair is drawn),
* but a run *boundary* happens once per frame in every mode — so no divisor.
*
* Wrapping the prototypes works even though the context already exists: methods
* resolve on the prototype at call time, not at context creation. The initial
* framebuffer binding is assumed to be the default and self-corrects on the first
* bindFramebuffer, which the GAL issues several times per frame.
*/
async function installGalFrameCounter(page: Page): Promise<void> {
await page.evaluate(() => {
const w = window as unknown as { __galFrames?: number; __galHooked?: boolean };
w.__galFrames = 0;
if (w.__galHooked) return;
w.__galHooked = true;
const protos = [
(window as unknown as { WebGL2RenderingContext?: { prototype: object } }).WebGL2RenderingContext,
(window as unknown as { WebGLRenderingContext?: { prototype: object } }).WebGLRenderingContext,
].filter(Boolean) as Array<{ prototype: Record<string, unknown> }>;
const state = new WeakMap<object, { fb: unknown; inPresent: boolean }>();
const st = (ctx: object) => {
let s = state.get(ctx);
if (!s) { s = { fb: null, inPresent: false }; state.set(ctx, s); }
return s;
};
const DRAWS = ['drawArrays', 'drawElements', 'drawArraysInstanced', 'drawElementsInstanced', 'drawRangeElements'];
for (const proto of protos) {
for (const name of ['bindFramebuffer', ...DRAWS]) {
const orig = proto.prototype[name] as ((...a: unknown[]) => unknown) | undefined;
if (typeof orig !== 'function') continue;
const isDraw = DRAWS.indexOf(name) >= 0;
proto.prototype[name] = function (this: object, ...args: unknown[]) {
const s = st(this);
if (!isDraw) {
s.fb = args[1];
if (args[1]) s.inPresent = false;
} else if (s.fb === null || s.fb === undefined) {
if (!s.inPresent) { s.inPresent = true; w.__galFrames = (w.__galFrames ?? 0) + 1; }
} else {
s.inPresent = false;
}
return orig.apply(this, args);
};
}
}
});
}
/** Zoom-to-fit, so every measurement starts from the same visible geometry. */
async function resetViewToFit(page: Page, cx: number, cy: number): Promise<void> {
await page.mouse.move(cx, cy);
await page.keyboard.press('Escape').catch(() => {}); // eslint-disable-line -- best-effort
await page.keyboard.press('Home').catch(() => {}); // eslint-disable-line -- best-effort
await page.waitForFunction(() => true, null, { timeout: 5000 });
}
/**
* Sustained interaction FPS, reported two ways.
*
* `galFps` is the real one: completed GAL frames per second (see
* installGalFrameCounter). `rafFps` is the legacy main-thread requestAnimationFrame
* count, kept only so historical CI numbers stay comparable — it is NOT a frame
* rate. rAF ticks on the compositor's schedule whether or not the GAL redrew, so
* it can read 120 while the renderer is completely stalled (measured: the 80 MB
* jetson board on a software rasteriser renders 0 frames while rAF reports 120).
*
* The drive is a pure middle-drag PAN. Wheel zoom used to be mixed into the same
* loop, and it makes the metric unusable: zooming continuously changes how much
* geometry is on screen, so the result depends on where the wheel happens to
* leave the view. Measured spread across three identical repeats was ±20%
* (34.7 / 42.1 / 27.1 fps) with zoom in the loop, versus ±2% (19.9 / 19.0 / 19.6)
* for pan alone. Pan also keeps the workload honest — it continuously reveals
* geometry that has to be cached, which is the expensive path.
*
* The view is zoomed to fit first, so every run starts from the same visible
* geometry (the whole board — the worst case) rather than inheriting whatever
* zoom level the previous measurement left behind.
*/
export async function measureInteractionFps(
page: Page,
seconds: number,
): Promise<{ rafFps: number; galFps: number }> {
const box = await page.locator(MAIN_CANVAS).boundingBox();
if (!box) return { rafFps: 0, galFps: 0 };
const cx = box.x + box.width / 2;
const cy = box.y + box.height / 2;
await resetViewToFit(page, cx, cy);
await installGalFrameCounter(page);
type W = { __perfFrames: number; __perfRAF?: number; __galFrames?: number };
await page.evaluate(() => {
const w = window as unknown as W;
if (w.__perfRAF !== undefined) cancelAnimationFrame(w.__perfRAF);
w.__perfFrames = 0;
w.__galFrames = 0;
const loop = () => {
w.__perfFrames++;
w.__perfRAF = requestAnimationFrame(loop);
};
w.__perfRAF = requestAnimationFrame(loop);
});
const start = Date.now();
let k = 0;
await page.mouse.move(cx, cy);
await page.mouse.down({ button: 'middle' });
while (Date.now() - start < seconds * 1000) {
await page.mouse.move(cx + Math.round(140 * Math.sin(k / 6)), cy + Math.round(90 * Math.cos(k / 7)));
k++;
}
await page.mouse.up({ button: 'middle' });
const elapsed = Date.now() - start;
const counts = await page.evaluate(() => {
const w = window as unknown as W;
if (w.__perfRAF !== undefined) cancelAnimationFrame(w.__perfRAF);
return { raf: w.__perfFrames, gal: w.__galFrames ?? 0 };
});
const secs = elapsed / 1000;
return { rafFps: +(counts.raf / secs).toFixed(1), galFps: +(counts.gal / secs).toFixed(1) };
}
/**
* Sustained interaction FPS: drive real pan/zoom on #canvas (the emscripten input
* surface — glcanvas-* can be display:none) for `seconds`, counting main-thread rAF
* frames. Whatever throttle is currently set applies.
*
* @deprecated rAF ticks are not GAL frames — use measureInteractionFps().galFps.
*/
export async function measureFps(page: Page, seconds: number): Promise<number> {
const box = await page.locator(MAIN_CANVAS).boundingBox();
if (!box) return 0;
type W = { __perfFrames: number; __perfRAF?: number };
// Start ONE rAF frame counter, cancelling any loop left over from a prior call
// (otherwise loops accumulate across a throttle sweep and inflate the count).
await page.evaluate(() => {
const w = window as unknown as W;
if (w.__perfRAF !== undefined) cancelAnimationFrame(w.__perfRAF);
w.__perfFrames = 0;
const loop = () => {
w.__perfFrames++;
w.__perfRAF = requestAnimationFrame(loop);
};
w.__perfRAF = requestAnimationFrame(loop);
});
const cx = box.x + box.width / 2;
const cy = box.y + box.height / 2;
const start = Date.now();
let k = 0;
await page.mouse.move(cx, cy);
while (Date.now() - start < seconds * 1000) {
await page.mouse.move(cx + Math.round(120 * Math.sin(k / 3)), cy + Math.round(80 * Math.cos(k / 4)));
if (k % 3 === 0) await page.mouse.wheel(0, k % 6 < 3 ? -120 : 120);
k++;
}
const elapsed = Date.now() - start;
const frames = await page.evaluate(() => {
const w = window as unknown as W;
if (w.__perfRAF !== undefined) cancelAnimationFrame(w.__perfRAF);
return w.__perfFrames;
});
return +(frames / (elapsed / 1000)).toFixed(1);
}
/**
* measureFps plus a DISTINCT-frame counter: rAF keeps ticking at vsync even
* when the GAL skips redraws (draw_panel_gal enforces a min redraw period and
* re-arms a timer when it can't keep up), so under load the rAF number can
* decouple from real render throughput. Alongside the rAF loop this samples
* the largest visible canvas at ~30 Hz (48×48 downscale hash — the
* waitForCanvasStable technique; GAL sets preserveDrawingBuffer) and counts
* samples whose content changed. distinctFps is capped by the ~30 Hz sample
* rate; read it as "real redraws per second, up to 30".
*/
export async function measureFpsDetailed(
page: Page,
seconds: number,
): Promise<{ rafFps: number; distinctFps: number }> {
await page.evaluate(() => {
const w = window as unknown as {
__dfPrev?: string;
__dfCount?: number;
__dfSamples?: number;
__dfTimer?: number;
};
if (w.__dfTimer !== undefined) clearInterval(w.__dfTimer);
w.__dfPrev = undefined;
w.__dfCount = 0;
w.__dfSamples = 0;
const scratch = document.createElement('canvas');
scratch.width = 48;
scratch.height = 48;
const ctx = scratch.getContext('2d', { willReadFrequently: true })!;
w.__dfTimer = setInterval(() => {
const canvases = Array.from(document.querySelectorAll('canvas')).filter((c) => {
const r = c.getBoundingClientRect();
return r.width > 0 && r.height > 0 && c !== scratch;
});
if (!canvases.length) return;
// The GAL draws into a wxGLCanvas (id glcanvas-*), NOT the
// full-window emscripten #canvas — sample the GL surface where the
// board pixels actually change, falling back to the largest canvas.
const gl = canvases.filter((c) => /^glcanvas/.test(c.id));
const pool = gl.length ? gl : canvases;
const src = pool.reduce((a, b) => {
const ra = a.getBoundingClientRect();
const rb = b.getBoundingClientRect();
return ra.width * ra.height >= rb.width * rb.height ? a : b;
});
try {
ctx.drawImage(src, 0, 0, 48, 48);
const d = ctx.getImageData(0, 0, 48, 48).data;
let h = 0;
for (let i = 0; i < d.length; i += 16) h = ((h << 5) - h + d[i]) | 0;
const hs = String(h);
w.__dfSamples = (w.__dfSamples ?? 0) + 1;
if (w.__dfPrev !== undefined && hs !== w.__dfPrev) w.__dfCount = (w.__dfCount ?? 0) + 1;
w.__dfPrev = hs;
} catch {
/* tainted/zero-size canvas — skip the sample */
}
}, 33) as unknown as number;
});
const t0 = Date.now();
const rafFps = await measureFps(page, seconds);
const elapsed = (Date.now() - t0) / 1000;
const distinct = await page.evaluate(() => {
const w = window as unknown as { __dfCount?: number; __dfTimer?: number };
if (w.__dfTimer !== undefined) clearInterval(w.__dfTimer);
w.__dfTimer = undefined;
return w.__dfCount ?? 0;
});
return { rafFps, distinctFps: +(distinct / elapsed).toFixed(1) };
}
/** Write per-app results to tests/test-results/perf-<app>.json (gitignored, CI-uploaded). */
export function recordPerf(app: string, data: Record<string, unknown>): void {
fs.mkdirSync(RESULTS_DIR, { recursive: true });
const out = { app, when: new Date().toISOString(), ...data };
fs.writeFileSync(path.join(RESULTS_DIR, `perf-${app}.json`), JSON.stringify(out, null, 2));
// Also echo a compact line so it lands in the captured test log / CI output.
// eslint-disable-next-line no-console
console.log(`[perf] ${app}: ${JSON.stringify(data)}`);
}