pcbjam/tests/kicad/utils/perf-utils.ts

417 lines
18 KiB
TypeScript
Raw Normal View History

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 });
}
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
/**
* 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.
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
*
* @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)}`);
}