diff --git a/.changeset/renderer-frame-timing.md b/.changeset/renderer-frame-timing.md new file mode 100644 index 000000000..2af6db798 --- /dev/null +++ b/.changeset/renderer-frame-timing.md @@ -0,0 +1,23 @@ +--- +"@ifc-lite/renderer": minor +--- + +Add opt-in frame/pass GPU timing instrumentation, so a perf-sensitive rendering feature (e.g. the sun-shadow work gated on an end-to-end perf verdict) can actually be measured instead of eyeballed. + +The renderer had no frame-time or pass-time instrumentation at all — the existing `tests/benchmark/*` suite measures load and streaming KPIs, not per-frame GPU cost. `GpuFrameTimingRecorder` wraps WebGPU timestamp queries (`GPUQuerySet` of type `'timestamp'`, `timestampWrites` on a render pass, resolved into a buffer and read back) to time individual passes and whole frames. Timestamp queries require the `'timestamp-query'` adapter feature, which is not always available: `WebGPUDevice` now requests it opportunistically (only when the adapter already advertises it — never as a hard requirement) and exposes `hasTimestampQueryFeature()`, and `decideTimingMode()` degrades cleanly to a CPU-side frame-delta fallback (`createCpuFrameTicker`, explicitly labelled `'cpu-fallback'` so it is never confused with a GPU number) or to `'disabled'`, rather than throwing or reporting a silent zero. + +Statistics (`computeDurationStats`: min/median/p95/max/mean, with an explicit `count: 0` / all-`null` shape for an empty sample) and aggregation (`aggregateFrameTimings`, `passDurationsMs`, `frameTotalMs`) are pure functions with no GPU or clock dependency, so they are fully unit-testable; only query-set creation, pass attachment, and buffer readback touch the GPU, and that surface is kept as thin as possible. + +Nothing in the renderer constructs a recorder or requests the feature as required — this is entirely opt-in. A caller creates `GpuFrameTimingRecorder.create(device.getDevice())` (returns `null` when unsupported), attaches `recorder.beginPass(label)` to each render pass's `timestampWrites`, calls `recorder.endFrame(encoder)` before `queue.submit`, and awaits `recorder.readback()` for that frame's samples — see `frame-timing-gpu.ts`'s module doc for the full pattern. Sampling every frame is not recommended for a shipped build (query resolution and the readback have their own cost); sample intermittently. + +Producing an actual perf verdict for #2670 still needs a WebGPU-capable test harness with the `'timestamp-query'` feature (this repo's current Chromium test environment exposes no WebGPU adapter at all), a representative model, and a defined shadows-off-vs-on comparison at a stated shadow-map resolution — none of that is included here. + +`nsToMs` now clamps a negative `(endNs - startNs)` delta to `0` instead of returning a physically impossible negative duration — GPU timestamps are not guaranteed monotonic across a device reset, and one such sample used to be able to drag `min`/`mean` negative across an otherwise-healthy stat window. `aggregateFrameTimings`'s `FrameTimingReport` gains an `invalidSampleCount` field so a caller can see when that clamp fired instead of a clamped-0 reading as an ordinary fast frame; `isNegativeDelta` is exported alongside `nsToMs` for callers that want the same check. `frame-timing-gpu.ts`'s query-index allocation, buffer-size arithmetic, and readback timestamp/label pairing — the parts of that file decidable without a live device — are now extracted as pure, unit-tested functions (`queryBufferSizeBytes`, `allocatePassQueryIndices`, `pairTimestampsWithLabels`); only `GpuFrameTimingRecorder`'s actual WebGPU calls remain unverified in this environment. + +`pairTimestampsWithLabels` now guards against a `timestamps` buffer shorter than `labels.length * 2` — not reachable through `GpuFrameTimingRecorder.readback()` today (it sizes the readback slice from the same cursor `beginPass` pushed each label against), but the function is exported to be called standalone, and a short buffer used to produce a sample with an `undefined` `startNs`/`endNs` where the type says `bigint`: summing it in `frameTotalMs` either threw a `TypeError` mixing `BigInt` and `undefined`, or silently computed `NaN`, depending on exactly how short the buffer was. A label whose pair does not fully fit is now dropped instead, so the function holds the same "never throws, never fabricates" contract as its siblings for any input shape. + +`WebGPUDevice.init()` degrades its `requestDevice()` call in stages rather than surrendering everything at once. The request carries two asks that are not equally important: `requiredLimits` raises `maxBufferSize`/`maxStorageBufferBindingSize` to what the adapter advertises, without which a large model's vertex buffer exceeds the 256 MiB default and nothing renders at all, while `requiredFeatures` asks for the purely opt-in `'timestamp-query'` diagnostic. Sharing one `try`/`catch` between them meant a rejection caused by the newly-requested feature also silently gave up the buffer limits — an opt-in diagnostic costing a user their render. A rejection of the full request is now retried with the limits alone, and only a rejection of *that* reaches the bare `requestDevice()` last resort (still reachable, for the drivers that reject limits they nominally advertise); each degradation is logged rather than silent. The retry is skipped when no feature was requested, where it would be identical to the request that just failed. Covered by tests in both directions against a stubbed adapter: one that accepts everything must still receive both asks, and one that rejects the feature must still end up with the limits. + +`passDurationsMs` and `aggregateFrameTimings`'s `report.passes` accumulate into null-prototype maps. Pass labels are caller-chosen free text used directly as keys, so on a plain object literal a label of `__proto__` was silently dropped (the assignment hit the prototype setter and created no own property, losing the pass from the report) and a label of `constructor` read the inherited `Object` function as its running total, string-concatenating instead of summing. + +`computeDurationStats([])`'s empty-sample result is frozen. It is a module-level constant returned by reference to every caller, so one caller mutating the object it received would have rewritten what every later empty result reported — turning an honest "nothing was measured" into a fabricated number for the rest of the process. diff --git a/packages/renderer/src/device-request-fallback.test.ts b/packages/renderer/src/device-request-fallback.test.ts new file mode 100644 index 000000000..2528fe5d2 --- /dev/null +++ b/packages/renderer/src/device-request-fallback.test.ts @@ -0,0 +1,262 @@ +/* This Source Code Form is subject to the terms of the Mozilla Public + * License, v. 2.0. If a copy of the MPL was not distributed with this + * file, You can obtain one at https://mozilla.org/MPL/2.0/. */ + +/** + * `WebGPUDevice.init()`'s staged `requestDevice()` degradation. + * + * Two asks go into the request and they are not equally important: + * `requiredLimits` raises `maxBufferSize`/`maxStorageBufferBindingSize` to + * what the adapter advertises, without which a large IFC's vertex buffer + * exceeds the 256 MiB default and "nothing renders"; `requiredFeatures` asks + * for `'timestamp-query'`, a purely opt-in diagnostic (issue #2670) that + * does nothing at all unless a caller constructs a `GpuFrameTimingRecorder`. + * + * A single try/catch around both surrenders them together, so a rejection + * caused by the diagnostic feature would silently cost a user the buffer + * limits their model needs. These tests pin the staged behaviour in BOTH + * directions — an adapter that accepts everything must still receive both + * asks, and an adapter that rejects the feature must still end up with the + * limits — plus that the bare last-resort request is still reachable. + * + * Same hand-stubbed `navigator.gpu` approach as device-adapter-info.test.ts. + */ + +import { describe, it, afterEach } from 'node:test'; +import assert from 'node:assert/strict'; +import { WebGPUDevice } from './device.js'; + +// `configureContext()` reads GPUTextureUsage.RENDER_ATTACHMENT, which node +// does not define. Same stub as device-adapter-info.test.ts. +(globalThis as Record).GPUTextureUsage ??= { RENDER_ATTACHMENT: 0x10 }; + +const savedNavigator = Object.getOwnPropertyDescriptor(globalThis, 'navigator'); + +afterEach(() => { + if (savedNavigator) { + Object.defineProperty(globalThis, 'navigator', savedNavigator); + } else { + delete (globalThis as { navigator?: unknown }).navigator; + } +}); + +const ADAPTER_MAX_BUFFER = 1 << 30; +const ADAPTER_MAX_STORAGE = 1 << 29; + +/** A device whose `lost` promise stays pending, carrying `grantedFeatures`. */ +function makeFakeDevice(grantedFeatures: readonly string[]): unknown { + return { + lost: new Promise(() => { /* never settles */ }), + limits: { maxTextureDimension2D: 8192 }, + features: new Set(grantedFeatures), + }; +} + +function installNavigator(adapter: unknown): void { + Object.defineProperty(globalThis, 'navigator', { + value: { + gpu: { + requestAdapter: async () => adapter, + getPreferredCanvasFormat: () => 'bgra8unorm', + }, + }, + configurable: true, + }); +} + +function makeCanvas(): HTMLCanvasElement { + return { + width: 256, + height: 256, + getContext: () => ({ configure: () => { /* accepted */ } }), + } as unknown as HTMLCanvasElement; +} + +type Descriptor = { requiredLimits?: Record; requiredFeatures?: string[] } | undefined; + +interface RecordingAdapter { + adapter: unknown; + /** Every descriptor `init()` passed to requestDevice, in call order. */ + calls: Descriptor[]; +} + +/** + * An adapter recording each `requestDevice()` descriptor. `decide` returns the + * feature list to grant, or throws to reject that particular request — which + * is how a driver's rejection of one specific ask is modelled. + */ +function makeRecordingAdapter( + advertisedFeatures: readonly string[], + decide: (descriptor: Descriptor) => readonly string[], +): RecordingAdapter { + const calls: Descriptor[] = []; + const adapter = { + info: { vendor: 'testvendor', architecture: 'testarch' }, + features: new Set(advertisedFeatures), + limits: { + maxBufferSize: ADAPTER_MAX_BUFFER, + maxStorageBufferBindingSize: ADAPTER_MAX_STORAGE, + }, + requestDevice: async (descriptor?: Descriptor) => { + calls.push(descriptor); + return makeFakeDevice(decide(descriptor)); + }, + }; + return { adapter, calls }; +} + +/** Runs `fn` with console.warn captured, returning the lines it emitted. */ +async function withCapturedWarnings(fn: () => Promise): Promise { + const lines: string[] = []; + const realWarn = console.warn; + console.warn = (...args: unknown[]) => { + lines.push(args.map((a) => (typeof a === 'string' ? a : String(a))).join(' ')); + }; + try { + await fn(); + } finally { + console.warn = realWarn; + } + return lines; +} + +describe('WebGPUDevice requestDevice staging — an adapter that accepts everything', () => { + it('asks for the raised buffer limits AND the timestamp-query feature in one request', async () => { + const { adapter, calls } = makeRecordingAdapter(['timestamp-query'], (d) => d?.requiredFeatures ?? []); + installNavigator(adapter); + + const device = new WebGPUDevice(); + await device.init(makeCanvas()); + + assert.equal(calls.length, 1, 'a fully-accepted request must not be retried'); + // Both asks, together: dropping either on the happy path would be the + // regression this staging exists to make impossible. + assert.deepEqual(calls[0]?.requiredLimits, { + maxBufferSize: ADAPTER_MAX_BUFFER, + maxStorageBufferBindingSize: ADAPTER_MAX_STORAGE, + }); + assert.deepEqual(calls[0]?.requiredFeatures, ['timestamp-query']); + assert.equal(device.hasTimestampQueryFeature(), true, 'the granted feature must be reported'); + }); + + it('does not request timestamp-query at all when the adapter does not advertise it', async () => { + // Asking for a feature the adapter lacks makes requestDevice() reject + // outright — so the feature must never appear in the request. + const { adapter, calls } = makeRecordingAdapter([], (d) => d?.requiredFeatures ?? []); + installNavigator(adapter); + + const device = new WebGPUDevice(); + await device.init(makeCanvas()); + + assert.equal(calls.length, 1); + assert.deepEqual(calls[0]?.requiredFeatures, [], 'an unadvertised feature must not be requested'); + assert.equal(device.hasTimestampQueryFeature(), false); + // The limits are still asked for — the feature's absence must not cost them. + assert.equal(calls[0]?.requiredLimits?.maxBufferSize, ADAPTER_MAX_BUFFER); + }); +}); + +describe('WebGPUDevice requestDevice staging — an adapter that rejects the feature', () => { + it('retries with the limits ALONE and keeps them, rather than dropping to a bare device', async () => { + // The defect this pins: a driver that advertises 'timestamp-query' but + // rejects a device request carrying it. Surrendering both asks at once + // would give this user a 256 MiB-capped device — no render for a large + // model — in exchange for a diagnostic they never opted into. + const { adapter, calls } = makeRecordingAdapter(['timestamp-query'], (d) => { + if ((d?.requiredFeatures?.length ?? 0) > 0) throw new Error('feature rejected by driver'); + return []; + }); + installNavigator(adapter); + + const device = new WebGPUDevice(); + const warnings = await withCapturedWarnings(() => device.init(makeCanvas())); + + assert.equal(device.isInitialized(), true, 'init must still succeed'); + assert.equal(calls.length, 2, 'exactly one retry: full request, then limits-only'); + // The retry must carry the limits and NOT be a bare request. + assert.deepEqual(calls[1]?.requiredLimits, { + maxBufferSize: ADAPTER_MAX_BUFFER, + maxStorageBufferBindingSize: ADAPTER_MAX_STORAGE, + }); + assert.equal( + calls[1]?.requiredFeatures, + undefined, + 'the retry must drop the optional feature, not carry it again', + ); + assert.equal(device.hasTimestampQueryFeature(), false, 'no feature was granted on the retry'); + assert.ok( + warnings.some((w) => w.includes('requiredFeatures')), + 'the dropped feature must be logged, not silently swallowed', + ); + assert.ok( + !warnings.some((w) => w.includes('maxBufferSize')), + 'the limits survived, so the limits-lost warning must NOT be emitted', + ); + }); +}); + +describe('WebGPUDevice requestDevice staging — the bare last-resort request', () => { + it('is still reached when even the limits-only request is rejected', async () => { + // The pre-existing reason this fallback exists: drivers that reject + // requiredLimits they nominally advertise. Splitting the fallback must + // not make the bare request unreachable. + const { adapter, calls } = makeRecordingAdapter(['timestamp-query'], (d) => { + if (d !== undefined) throw new Error('any descriptor rejected by driver'); + return []; + }); + installNavigator(adapter); + + const device = new WebGPUDevice(); + const warnings = await withCapturedWarnings(() => device.init(makeCanvas())); + + assert.equal(device.isInitialized(), true, 'init must still succeed on a default device'); + assert.equal(calls.length, 3, 'full request, limits-only retry, then bare'); + assert.equal(calls[2], undefined, 'the last resort must be a bare requestDevice() with no descriptor'); + assert.ok( + warnings.some((w) => w.includes('maxBufferSize')), + 'losing the raised limits is the damaging degradation and must be logged', + ); + }); + + it('skips the limits-only retry when no feature was requested — the pre-feature behaviour', async () => { + // With requiredFeatures empty, a limits-only retry would be byte-identical + // to the request that just failed. This adapter advertises no feature, so + // a rejection must go straight to the bare request: two calls, not three. + const { adapter, calls } = makeRecordingAdapter([], (d) => { + if (d !== undefined) throw new Error('limits rejected by driver'); + return []; + }); + installNavigator(adapter); + + const device = new WebGPUDevice(); + await withCapturedWarnings(() => device.init(makeCanvas())); + + assert.equal(device.isInitialized(), true); + assert.equal(calls.length, 2, 'no pointless identical retry when no feature was asked for'); + assert.equal(calls[1], undefined, 'the second call is the bare last resort'); + }); +}); + +describe('WebGPUDevice.hasTimestampQueryFeature', () => { + it('reports what the DEVICE granted, not what the adapter advertised', async () => { + // An adapter can advertise the feature while the granted device does not + // carry it (the limits-only retry, or a driver granting less than asked). + // The getter must reflect the device, or a caller would create a query set + // the device cannot support. + const { adapter } = makeRecordingAdapter(['timestamp-query'], () => []); + installNavigator(adapter); + + const device = new WebGPUDevice(); + await device.init(makeCanvas()); + + assert.equal( + device.hasTimestampQueryFeature(), + false, + 'an advertised-but-not-granted feature must read as absent', + ); + }); + + it('is false before init() has run', async () => { + assert.equal(new WebGPUDevice().hasTimestampQueryFeature(), false); + }); +}); diff --git a/packages/renderer/src/device.ts b/packages/renderer/src/device.ts index 5cecb3756..253bca215 100644 --- a/packages/renderer/src/device.ts +++ b/packages/renderer/src/device.ts @@ -109,13 +109,76 @@ export class WebGPUDevice { if (limits?.maxStorageBufferBindingSize) { requiredLimits.maxStorageBufferBindingSize = limits.maxStorageBufferBindingSize; } + + // Request 'timestamp-query' when the adapter advertises it (issue #2670 + // perf-verdict gate — see frame-timing-gpu.ts). It is an OPTIONAL feature + // per the WebGPU spec, not all adapters/backends support it, so it is + // only added to requiredFeatures when already present in + // adapter.features — asking for a feature the adapter doesn't have would + // make requestDevice() reject outright. this.hasTimestampQueryFeature() + // reports the outcome; nothing in the renderer requests query sets + // unless a caller opts into GpuFrameTimingRecorder.create(). + const requiredFeatures: GPUFeatureName[] = []; + if (this.adapter.features?.has('timestamp-query')) { + requiredFeatures.push('timestamp-query'); + } + + // Degrade one ask at a time, most-wanted first. The two asks are NOT + // equally important and must not be surrendered together: + // + // - `requiredLimits` is load-bearing for rendering at all. Without the + // raise, a large IFC's vertex buffer exceeds the 256 MiB default and + // "nothing renders" (see the comment on `requiredLimits` above). + // - `requiredFeatures` is pure opt-in diagnostics ('timestamp-query', + // which only does anything once a caller constructs a + // GpuFrameTimingRecorder). + // + // A single try/catch around both would let a feature-caused rejection + // cost the user their render for a diagnostic they never asked for. So a + // rejection of the full request is retried with the LIMITS ALONE, and + // only a rejection of that reaches the bare request. + // `hasTimestampQueryFeature()` reports which stage was reached. + let device: GPUDevice | null = null; + + // Stage 1: everything we want. try { - this.device = await this.adapter.requestDevice({ requiredLimits }); - } catch { - // Some drivers reject requiredLimits they nominally advertise — fall back to a - // default device rather than failing to initialise the renderer entirely. - this.device = await this.adapter.requestDevice(); + device = await this.adapter.requestDevice({ requiredLimits, requiredFeatures }); + } catch (e) { + if (requiredFeatures.length > 0) { + console.warn( + '[WebGPU] requestDevice() rejected the request carrying requiredFeatures; ' + + 'retrying with the buffer limits alone (GPU timestamp queries unavailable):', + e, + ); + } + } + + // Stage 2: drop the optional diagnostic feature, KEEP the limits. Skipped + // when no feature was requested — the request would then be identical to + // the one that just failed, so that case degrades exactly as it did + // before 'timestamp-query' was ever asked for. + if (!device && requiredFeatures.length > 0) { + try { + device = await this.adapter.requestDevice({ requiredLimits }); + } catch (e) { + console.warn('[WebGPU] requestDevice() also rejected the limits-only request:', e); + } } + + // Stage 3, last resort: some drivers reject requiredLimits they nominally + // advertise — fall back to a default device rather than failing to + // initialise the renderer entirely. This degradation is the damaging one, + // so it is logged rather than silent: without the raised limits a large + // model's geometry upload can exceed the default maxBufferSize. + if (!device) { + console.warn( + '[WebGPU] falling back to a default device with no required limits — ' + + 'a large model may exceed the default maxBufferSize and fail to render.', + ); + device = await this.adapter.requestDevice(); + } + + this.device = device; this.format = navigator.gpu.getPreferredCanvasFormat(); this.canvas = canvas; @@ -267,6 +330,20 @@ export class WebGPUDevice { return this.adapterInfoSnapshot; } + /** + * Whether this device's adapter supports GPU timestamp queries (issue + * #2670 perf-verdict gate — see frame-timing-gpu.ts). Reflects what was + * actually granted on `this.device`, not merely what the adapter + * advertised, so it stays correct on the rare path where `requestDevice()` + * with `requiredFeatures` was rejected and `init()` degraded to one of the + * later stages (limits-only, or the bare request) with the feature never + * granted. False before `init()` has run, same as every other + * device-derived getter here. + */ + hasTimestampQueryFeature(): boolean { + return this.device?.features?.has('timestamp-query') ?? false; + } + getContext(): GPUCanvasContext { if (!this.context) { throw new Error('Context not initialized'); diff --git a/packages/renderer/src/frame-timing-cpu.test.ts b/packages/renderer/src/frame-timing-cpu.test.ts new file mode 100644 index 000000000..34c67ff34 --- /dev/null +++ b/packages/renderer/src/frame-timing-cpu.test.ts @@ -0,0 +1,48 @@ +/* This Source Code Form is subject to the terms of the Mozilla Public + * License, v. 2.0. If a copy of the MPL was not distributed with this + * file, You can obtain one at https://mozilla.org/MPL/2.0/. */ + +import { describe, it } from 'node:test'; +import assert from 'node:assert'; + +import { createCpuFrameTicker } from './frame-timing-cpu.js'; +import { computeDurationStats } from './frame-timing-stats.js'; + +describe('createCpuFrameTicker', () => { + it('records no deltas after a single tick (needs a boundary on both sides)', () => { + const ticker = createCpuFrameTicker(); + ticker.tick(1000); + assert.deepStrictEqual(ticker.deltasMs(), []); + }); + + it('computes exact, non-round, asymmetric inter-frame deltas from synthetic timestamps', () => { + // Values chosen exactly representable in binary floating point (eighths + // of a millisecond) so the subtraction is exact — no epsilon fuzz needed + // to tell a correct delta from a wrong one. + const ticker = createCpuFrameTicker(); + ticker.tick(1000.25); + ticker.tick(1008.375); // +8.125 + ticker.tick(1013.125); // +4.75 + ticker.tick(1054.375); // +41.25 + assert.deepStrictEqual(ticker.deltasMs(), [8.125, 4.75, 41.25]); + }); + + it('feeds straight into the shared stats primitive (same DurationStats shape as GPU-queries mode)', () => { + const ticker = createCpuFrameTicker(); + // Eighths of a millisecond again, for exact subtraction: deltas are + // 8.125, 4.75, 41.25. + for (const t of [0, 8.125, 12.875, 54.125]) ticker.tick(t); + const stats = computeDurationStats(ticker.deltasMs()); + assert.strictEqual(stats.count, 3); + assert.strictEqual(stats.max, 41.25); + }); + + it('deltasMs() returns a snapshot — mutating the returned array does not affect the ticker', () => { + const ticker = createCpuFrameTicker(); + ticker.tick(0); + ticker.tick(5); + const snapshot = ticker.deltasMs(); + snapshot.push(999); + assert.deepStrictEqual(ticker.deltasMs(), [5]); + }); +}); diff --git a/packages/renderer/src/frame-timing-cpu.ts b/packages/renderer/src/frame-timing-cpu.ts new file mode 100644 index 000000000..99328d3f8 --- /dev/null +++ b/packages/renderer/src/frame-timing-cpu.ts @@ -0,0 +1,49 @@ +/* This Source Code Form is subject to the terms of the Mozilla Public + * License, v. 2.0. If a copy of the MPL was not distributed with this + * file, You can obtain one at https://mozilla.org/MPL/2.0/. */ + +/** + * CPU-side frame-delta fallback for when the `'timestamp-query'` adapter + * feature is unavailable (see `decideTimingMode` in `frame-timing.ts`). + * + * This measures a DIFFERENT thing than GPU timestamp queries: the wall-clock + * gap between successive `tick()` calls on the CPU, which includes JS work, + * any main-thread contention, and the browser's own frame pacing — not just + * GPU pass execution. It is reported through the same `TimingMode === + * 'cpu-fallback'` label everywhere (see `frame-timing.ts`'s `TimingMode` + * doc) specifically so it is never mistaken for a `gpu-queries` number. + * + * Thin on purpose: the only thing here that touches a clock is `tick()`. + * The accumulated deltas are plain numbers fed straight into + * `computeDurationStats` (`frame-timing-stats.ts`), the same pure statistics + * GPU-queries mode uses. + */ + +export interface CpuFrameTicker { + /** Records one frame boundary. Call once per frame, at the same point each time (e.g. the top of `render()`). */ + tick(nowMs: number): void; + /** Every recorded inter-frame delta (ms), oldest first. Empty until at least two `tick()` calls have been made. */ + deltasMs(): number[]; +} + +/** + * Creates a `CpuFrameTicker`. The clock read (`performance.now()` in a real + * caller) happens OUTSIDE this module — `tick(nowMs)` takes the timestamp as + * a parameter rather than reading a clock itself, so this module has no + * dependency on real elapsed time and its own tests (see + * `frame-timing-cpu.test.ts`) can feed synthetic values deterministically. + */ +export function createCpuFrameTicker(): CpuFrameTicker { + let lastMs: number | null = null; + const deltas: number[] = []; + + return { + tick(nowMs: number): void { + if (lastMs !== null) deltas.push(nowMs - lastMs); + lastMs = nowMs; + }, + deltasMs(): number[] { + return deltas.slice(); + }, + }; +} diff --git a/packages/renderer/src/frame-timing-gpu.test.ts b/packages/renderer/src/frame-timing-gpu.test.ts new file mode 100644 index 000000000..39d697069 --- /dev/null +++ b/packages/renderer/src/frame-timing-gpu.test.ts @@ -0,0 +1,194 @@ +/* This Source Code Form is subject to the terms of the Mozilla Public + * License, v. 2.0. If a copy of the MPL was not distributed with this + * file, You can obtain one at https://mozilla.org/MPL/2.0/. */ + +/** + * Tests for the parts of `frame-timing-gpu.ts` that are decidable without a + * device: feature detection, query-set sizing, query-index allocation, and + * the resolve/readback-buffer pairing arithmetic. `GpuFrameTimingRecorder` + * itself is not instantiated here — it calls `device.createQuerySet` etc. + * directly and has no test file, by design (see that class's doc). + */ + +import { describe, it } from 'node:test'; +import assert from 'node:assert'; + +import { + hasTimestampQueryFeature, + queryBufferSizeBytes, + allocatePassQueryIndices, + pairTimestampsWithLabels, +} from './frame-timing-gpu.js'; + +describe('hasTimestampQueryFeature', () => { + it('is true when the adapter feature set reports it', () => { + assert.strictEqual(hasTimestampQueryFeature({ has: (name) => name === 'timestamp-query' }), true); + }); + + it('is false when the adapter feature set does not report it', () => { + assert.strictEqual(hasTimestampQueryFeature({ has: () => false }), false); + }); + + it('is false, not throwing, for a null or undefined feature set', () => { + assert.strictEqual(hasTimestampQueryFeature(null), false); + assert.strictEqual(hasTimestampQueryFeature(undefined), false); + }); +}); + +describe('queryBufferSizeBytes', () => { + it('is 2 timestamps (8 bytes each) per pass', () => { + // 1 pass -> 2 queries (begin+end) -> 16 bytes. + assert.strictEqual(queryBufferSizeBytes(1), 16); + }); + + it('scales linearly with an asymmetric, non-round pass count', () => { + // 13 passes -> 26 queries -> 208 bytes. + assert.strictEqual(queryBufferSizeBytes(13), 208); + }); + + it('is 0 for zero passes', () => { + assert.strictEqual(queryBufferSizeBytes(0), 0); + }); +}); + +describe('allocatePassQueryIndices', () => { + it('allocates the first pair (0, 1) and advances the cursor to 2', () => { + const result = allocatePassQueryIndices(0, 8); + assert.deepStrictEqual(result, { + beginningOfPassWriteIndex: 0, + endOfPassWriteIndex: 1, + nextQueryIndex: 2, + }); + }); + + it('allocates a later pair from a non-zero cursor', () => { + // Third pass in a session allowing up to 8: cursor starts at 4. + const result = allocatePassQueryIndices(4, 8); + assert.deepStrictEqual(result, { + beginningOfPassWriteIndex: 4, + endOfPassWriteIndex: 5, + nextQueryIndex: 6, + }); + }); + + it('allocates the last available pair exactly at the maxPasses boundary', () => { + // maxPasses=8 -> 16 query slots (indices 0..15). The 8th pass starts at + // cursor 14 and must still succeed (14+1 = 15 < 16). + const result = allocatePassQueryIndices(14, 8); + assert.deepStrictEqual(result, { + beginningOfPassWriteIndex: 14, + endOfPassWriteIndex: 15, + nextQueryIndex: 16, + }); + }); + + it('returns null once maxPasses passes have already been begun this frame', () => { + // cursor=16 with maxPasses=8 (16 slots) -> exhausted. + assert.strictEqual(allocatePassQueryIndices(16, 8), null); + }); + + it('returns null for a small, asymmetric maxPasses at its exact boundary', () => { + // maxPasses=3 -> 6 slots (0..5). cursor=4 -> 4+1=5, not >= 6 -> still allowed. + assert.deepStrictEqual(allocatePassQueryIndices(4, 3), { + beginningOfPassWriteIndex: 4, + endOfPassWriteIndex: 5, + nextQueryIndex: 6, + }); + // cursor=6 -> exhausted. + assert.strictEqual(allocatePassQueryIndices(6, 3), null); + }); + + it('refuses an ODD cursor whose END index would fall outside the query set', () => { + // Every case above feeds an EVEN cursor, because that is all + // `beginPass` can produce — it advances by 2. On even cursors + // `nextQueryIndex + 1 >= maxPasses * 2` and `nextQueryIndex >= + // maxPasses * 2` agree, so the `+ 1` — the whole point of the guard — + // is invisible to them: deleting it leaves every test above green. + // + // But this function is exported precisely so it can be driven with + // synthetic cursors rather than only from inside a live recording + // session, and an odd cursor is where the two differ. maxPasses=8 is + // 16 slots (0..15): cursor 15 leaves room for a BEGIN at 15 and + // nothing for its END, and handing WebGPU an `endOfPassWriteIndex` + // of 16 against a count-16 query set is a validation error, not a + // truncated measurement. Exhaustion is the only correct answer. + assert.strictEqual(allocatePassQueryIndices(15, 8), null); + // ...and the odd cursor one step below still has room for both, so + // this pins the boundary rather than just refusing odd cursors. + assert.deepStrictEqual(allocatePassQueryIndices(13, 8), { + beginningOfPassWriteIndex: 13, + endOfPassWriteIndex: 14, + nextQueryIndex: 15, + }); + }); +}); + +describe('pairTimestampsWithLabels', () => { + it('pairs each label with its (start, end) timestamps at index i*2 / i*2+1', () => { + const labels = ['shadow', 'main', 'sky']; + const timestamps = new BigInt64Array([10n, 25n, 25n, 900n, 900n, 950n]); + assert.deepStrictEqual(pairTimestampsWithLabels(labels, timestamps), [ + { label: 'shadow', startNs: 10n, endNs: 25n }, + { label: 'main', startNs: 25n, endNs: 900n }, + { label: 'sky', startNs: 900n, endNs: 950n }, + ]); + }); + + it('returns an empty array for no labels, even with a non-empty buffer', () => { + assert.deepStrictEqual(pairTimestampsWithLabels([], new BigInt64Array([1n, 2n])), []); + }); + + it('only reads as many pairs as there are labels, ignoring any trailing unused buffer slots', () => { + // Buffer sized for maxPasses=4 (8 slots) but only 2 passes were actually + // begun this frame — the trailing slots must not become phantom samples. + const labels = ['main', 'shadow']; + const timestamps = new BigInt64Array([100n, 108n, 108n, 111n, 0n, 0n, 0n, 0n]); + assert.deepStrictEqual(pairTimestampsWithLabels(labels, timestamps), [ + { label: 'main', startNs: 100n, endNs: 108n }, + { label: 'shadow', startNs: 108n, endNs: 111n }, + ]); + }); + + describe('a malformed (short) timestamps buffer — not reachable via GpuFrameTimingRecorder.readback() today, but this function is exported to be called standalone', () => { + it('drops a pair one element short instead of returning an undefined endNs (which crashes frameTotalMs downstream: "Cannot mix BigInt and other types")', () => { + const labels = ['a', 'b']; + const timestamps = new BigInt64Array([1n, 2n, 3n]); // b's endNs (index 3) is missing + const result = pairTimestampsWithLabels(labels, timestamps); + assert.deepStrictEqual(result, [{ label: 'a', startNs: 1n, endNs: 2n }]); + // Every returned sample must be safe to sum in frameTotalMs without throwing. + for (const sample of result) { + assert.strictEqual(typeof sample.startNs, 'bigint'); + assert.strictEqual(typeof sample.endNs, 'bigint'); + } + }); + + it('drops a pair two elements short instead of silently producing NaN', () => { + const labels = ['a', 'b']; + const timestamps = new BigInt64Array([1n, 2n]); // b has no timestamps at all + const result = pairTimestampsWithLabels(labels, timestamps); + assert.deepStrictEqual(result, [{ label: 'a', startNs: 1n, endNs: 2n }]); + }); + + it('returns an empty array when there are no timestamps at all', () => { + const labels = ['a', 'b']; + const timestamps = new BigInt64Array([]); + assert.deepStrictEqual(pairTimestampsWithLabels(labels, timestamps), []); + }); + + it('drops every label when the timestamps buffer is shorter than even the first pair', () => { + const labels = ['a', 'b', 'c']; + const timestamps = new BigInt64Array([1n]); + assert.deepStrictEqual(pairTimestampsWithLabels(labels, timestamps), []); + }); + + it('the exact-length case (labels.length * 2 === timestamps.length) is unaffected: byte-identical to the pre-guard result', () => { + const labels = ['shadow', 'main', 'sky']; + const timestamps = new BigInt64Array([10n, 25n, 25n, 900n, 900n, 950n]); + assert.deepStrictEqual(pairTimestampsWithLabels(labels, timestamps), [ + { label: 'shadow', startNs: 10n, endNs: 25n }, + { label: 'main', startNs: 25n, endNs: 900n }, + { label: 'sky', startNs: 900n, endNs: 950n }, + ]); + }); + }); +}); diff --git a/packages/renderer/src/frame-timing-gpu.ts b/packages/renderer/src/frame-timing-gpu.ts new file mode 100644 index 000000000..4d6bfcde0 --- /dev/null +++ b/packages/renderer/src/frame-timing-gpu.ts @@ -0,0 +1,228 @@ +/* This Source Code Form is subject to the terms of the Mozilla Public + * License, v. 2.0. If a copy of the MPL was not distributed with this + * file, You can obtain one at https://mozilla.org/MPL/2.0/. */ + +/** + * Thin GPU-facing half of frame/pass timing (issue #2670 perf-verdict gate). + * Everything with judgement — statistics, unit conversion, mode selection — + * lives in `frame-timing.ts` / `frame-timing-stats.ts`, which are pure and + * fully covered by synthetic-value tests. This file is deliberately as small + * as it can be: it only creates the `GPUQuerySet`, writes `timestampWrites` + * into pass descriptors, resolves the query set into a readback buffer, and + * hands the raw nanosecond pairs to the pure aggregator. None of it runs in + * this environment (`navigator.gpu` is absent here, so there is no test file + * for this module — a mock `GPUDevice` would only prove the mock is + * internally consistent, not that the real WebGPU calls are correct) and + * none of it should be trusted without exercising it on a real + * `'timestamp-query'`-capable adapter. + * + * OPT-IN, NOT WIRED BY DEFAULT: nothing in this codebase constructs a + * `GpuFrameTimingRecorder` today. A caller enables it explicitly: + * + * ```ts + * const recorder = GpuFrameTimingRecorder.create(device); // null if unsupported + * if (recorder) { + * const pass = encoder.beginRenderPass({ + * ...descriptor, + * timestampWrites: recorder.beginPass('main'), + * }); + * // ...draw calls... + * pass.end(); + * recorder.endFrame(encoder); + * device.queue.submit([encoder.finish()]); + * const samples = await recorder.readback(); // PassTimingSample[] | null + * } + * ``` + * + * Measuring every frame changes what you're measuring (query resolution and + * the readback `mapAsync` are not free), so a caller should sample + * intermittently (e.g. every Nth frame) rather than every frame in a + * shipped build — this module does not impose that policy, it only makes + * one frame's measurement cheap and correct. + */ + +import type { PassTimingSample } from './frame-timing.js'; + +/** Feature-detects `'timestamp-query'` on an already-created `GPUDevice`'s adapter features, without touching mode-decision logic (see `decideTimingMode` in `frame-timing.ts`, which consumes this boolean). */ +export function hasTimestampQueryFeature(features: { has(name: string): boolean } | null | undefined): boolean { + return features?.has('timestamp-query') ?? false; +} + +const BYTES_PER_TIMESTAMP = 8; // GPUQuerySet resolves each timestamp query to one 64-bit (BigInt64) value. + +/** + * Byte size of the resolve/readback buffers needed for `passCount` passes — + * 2 timestamp queries (begin + end) per pass, `BYTES_PER_TIMESTAMP` each. + * Pure arithmetic, decidable without a device: extracted out of `create()` + * so the sizing formula itself is unit-tested rather than only ever + * exercised as a side effect of a real `device.createBuffer` call. + */ +export function queryBufferSizeBytes(passCount: number): number { + return passCount * 2 * BYTES_PER_TIMESTAMP; +} + +/** + * Allocates the next pair of query-set write indices for one pass, or + * `null` if `maxPasses` passes have already been begun this frame. Pure: + * given the current cursor and the frame's pass budget, the next + * (begin, end, cursor) triple — or exhaustion — is fully determined; no + * `GPUQuerySet` is touched to decide it. Extracted out of + * `GpuFrameTimingRecorder.beginPass` so this index bookkeeping (the part + * most likely to hide an off-by-one — see the exhaustion boundary test) is + * checked with synthetic cursor/maxPasses values instead of only ever + * running inside a live recording session. + */ +export function allocatePassQueryIndices( + nextQueryIndex: number, + maxPasses: number, +): { beginningOfPassWriteIndex: number; endOfPassWriteIndex: number; nextQueryIndex: number } | null { + if (nextQueryIndex + 1 >= maxPasses * 2) return null; + return { + beginningOfPassWriteIndex: nextQueryIndex, + endOfPassWriteIndex: nextQueryIndex + 1, + nextQueryIndex: nextQueryIndex + 2, + }; +} + +/** + * Pairs each recorded pass `label` (in recording order) with its + * (start, end) nanosecond timestamps at `timestamps[i*2]` / + * `timestamps[i*2+1]` — the layout `GpuFrameTimingRecorder` writes via + * `timestampWrites`. Pure: given a labels array and a `BigInt64Array`, the + * resulting `PassTimingSample[]` is fully determined; no `GPUBuffer` + * mapping is involved. Extracted out of `readback()` so this pairing + * arithmetic — the part that would silently mis-attribute a duration to + * the wrong label on an off-by-one — is checked directly. + * + * `GpuFrameTimingRecorder.readback()` always calls this with + * `timestamps.length === labels.length * 2` (it sizes the readback slice + * from the same `nextQueryIndex` cursor that `beginPass` pushed each label + * against — see `readback()`'s call site), so a short buffer cannot occur + * on that path today. But this function is exported precisely so it can be + * exercised standalone, and a caller passing a corrupted or hand-built + * buffer must not get back a sample whose `startNs`/`endNs` is `undefined` + * where the type says `bigint`: that silently propagates into + * `frameTotalMs`/`passDurationsMs` (`frame-timing.ts`), which throws a + * `TypeError` mixing `BigInt` and `undefined` for a one-short buffer, or + * silently computes `NaN` for a two-short buffer — two different failure + * shapes for what is really the same input error, and neither is the + * "never throws, never fabricates" contract the rest of this module's + * siblings hold themselves to. A label whose (start, end) pair does not + * fully fit in `timestamps` is dropped rather than pushed with a missing + * field. + */ +export function pairTimestampsWithLabels(labels: readonly string[], timestamps: BigInt64Array): PassTimingSample[] { + const samples: PassTimingSample[] = []; + for (let i = 0; i < labels.length; i++) { + if (i * 2 + 1 >= timestamps.length) break; // buffer shorter than this (and every later) label needs — stop rather than fabricate a partial pair. + samples.push({ label: labels[i], startNs: timestamps[i * 2], endNs: timestamps[i * 2 + 1] }); + } + return samples; +} + +/** + * Records GPU timestamp queries for the passes of one frame and resolves + * them into `PassTimingSample[]` (nanosecond pairs; see `frame-timing.ts` + * for what happens to them next). One instance is good for one frame's + * worth of passes up to `maxPasses`, then must be recreated (or reset via + * `beginFrame()`) for the next — this keeps the query-set/readback-buffer + * lifetime unambiguous rather than trying to make it silently reusable + * across frames while a previous frame's readback might still be pending. + */ +export class GpuFrameTimingRecorder { + private readonly maxPasses: number; + private readonly querySet: GPUQuerySet; + private readonly resolveBuffer: GPUBuffer; + private readonly readbackBuffer: GPUBuffer; + private labels: string[] = []; + private nextQueryIndex = 0; + private resolved = false; + + private constructor(maxPasses: number, querySet: GPUQuerySet, resolveBuffer: GPUBuffer, readbackBuffer: GPUBuffer) { + this.maxPasses = maxPasses; + this.querySet = querySet; + this.resolveBuffer = resolveBuffer; + this.readbackBuffer = readbackBuffer; + } + + /** + * Returns a recorder, or `null` if the device's adapter did not advertise + * `'timestamp-query'` — callers must treat `null` as "cannot measure this + * way" and either fall back to CPU-side timing (`decideTimingMode` in + * `frame-timing.ts`) or skip measurement, never throw. + */ + static create(device: GPUDevice, maxPasses = 8): GpuFrameTimingRecorder | null { + if (!hasTimestampQueryFeature(device.features)) return null; + + const querySet = device.createQuerySet({ type: 'timestamp', count: maxPasses * 2, label: 'frame-timing-queries' }); + const resolveBuffer = device.createBuffer({ + size: queryBufferSizeBytes(maxPasses), + usage: GPUBufferUsage.QUERY_RESOLVE | GPUBufferUsage.COPY_SRC, + label: 'frame-timing-resolve', + }); + const readbackBuffer = device.createBuffer({ + size: queryBufferSizeBytes(maxPasses), + usage: GPUBufferUsage.COPY_DST | GPUBufferUsage.MAP_READ, + label: 'frame-timing-readback', + }); + return new GpuFrameTimingRecorder(maxPasses, querySet, resolveBuffer, readbackBuffer); + } + + /** + * Returns the `timestampWrites` object for the next pass, labelled + * `label`. Pass it straight into `beginRenderPass`'s descriptor. Returns + * `null` once `maxPasses` passes have been begun this frame — a caller + * that hits this should raise `maxPasses` at construction, not retry. + */ + beginPass(label: string): GPURenderPassTimestampWrites | null { + const allocation = allocatePassQueryIndices(this.nextQueryIndex, this.maxPasses); + if (allocation === null) return null; + this.nextQueryIndex = allocation.nextQueryIndex; + this.labels.push(label); + return { + querySet: this.querySet, + beginningOfPassWriteIndex: allocation.beginningOfPassWriteIndex, + endOfPassWriteIndex: allocation.endOfPassWriteIndex, + }; + } + + /** Resolves every query written this frame into the readback buffer. Call once, after every pass has been `.end()`-ed, before `queue.submit`. */ + endFrame(encoder: GPUCommandEncoder): void { + if (this.nextQueryIndex === 0) return; // no passes recorded — nothing to resolve + encoder.resolveQuerySet(this.querySet, 0, this.nextQueryIndex, this.resolveBuffer, 0); + encoder.copyBufferToBuffer(this.resolveBuffer, 0, this.readbackBuffer, 0, this.nextQueryIndex * BYTES_PER_TIMESTAMP); + this.resolved = true; + } + + /** + * Maps the readback buffer and returns this frame's `PassTimingSample[]`, + * or `null` if `endFrame` was never called (nothing was recorded, or the + * caller forgot). Async because `mapAsync` is: the caller's queue submit + * must have completed first for the buffer to contain real data — WebGPU + * enforces this by making `mapAsync` wait for pending GPU work that + * touches the buffer. + */ + async readback(): Promise { + if (!this.resolved) return null; + await this.readbackBuffer.mapAsync(GPUMapMode.READ); + const raw = this.readbackBuffer.getMappedRange(0, this.nextQueryIndex * BYTES_PER_TIMESTAMP); + const timestamps = new BigInt64Array(raw.slice(0)); // copy out before unmap invalidates the ArrayBuffer + this.readbackBuffer.unmap(); + + return pairTimestampsWithLabels(this.labels, timestamps); + } + + /** Resets for the next frame's recording. Does not reallocate the query set or buffers — they are sized once at `create()` and reused. */ + beginFrame(): void { + this.labels = []; + this.nextQueryIndex = 0; + this.resolved = false; + } + + /** Releases the GPU query set and buffers. Call when timing is turned off. */ + destroy(): void { + this.querySet.destroy(); + this.resolveBuffer.destroy(); + this.readbackBuffer.destroy(); + } +} diff --git a/packages/renderer/src/frame-timing-stats.test.ts b/packages/renderer/src/frame-timing-stats.test.ts new file mode 100644 index 000000000..c60ddc147 --- /dev/null +++ b/packages/renderer/src/frame-timing-stats.test.ts @@ -0,0 +1,170 @@ +/* This Source Code Form is subject to the terms of the Mozilla Public + * License, v. 2.0. If a copy of the MPL was not distributed with this + * file, You can obtain one at https://mozilla.org/MPL/2.0/. */ + +import { describe, it } from 'node:test'; +import assert from 'node:assert'; + +import { nsToMs, isNegativeDelta, computeDurationStats } from './frame-timing-stats.js'; + +describe('nsToMs', () => { + it('converts an exact 1ms span', () => { + assert.strictEqual(nsToMs(0n, 1_000_000n), 1); + }); + + it('converts a non-round, asymmetric span (catches a dropped /1e6 or a swapped operand order)', () => { + // 12_345_678 ns = 12.345678 ms. Non-round and asymmetric: an off-by-one + // in the divisor (e.g. /1e3 or /1e9) or a start/end swap both produce a + // visibly wrong number, not a coincidentally-passing one. + assert.strictEqual(nsToMs(1_000_000_000n, 1_012_345_678n), 12.345678); + }); + + it('uses (end - start), not the raw start value', () => { + // A large absolute start timestamp (as a real GPU clock produces) must + // not leak into the result — only the delta (3_500_000 ns = 3.5 ms) + // matters, even though the start value alone is ~500 seconds. + const start = 500_000_000_000_000n; + const end = start + 3_500_000n; + assert.strictEqual(nsToMs(start, end), 3.5); + }); + + it('clamps a negative delta to 0 instead of returning a physically impossible negative duration', () => { + // The module's own doc notes GPU timestamps "are not guaranteed + // monotonic across a device reset" — end < start is reachable. A + // negative duration must never leak downstream (it would poison + // frameTotalMs's raw summation before computeDurationStats ever sees + // it), so this is the one choke point where the clamp belongs. + assert.strictEqual(nsToMs(1_000_000n, 500_000n), 0); + }); + + it('clamps a large negative delta (asymmetric, non-round) to exactly 0, not a scaled-down negative', () => { + assert.strictEqual(nsToMs(9_876_543_210n, 1_234_567n), 0); + }); + + it('treats a zero delta as a legitimate, unclamped 0 — a pass can measure zero', () => { + assert.strictEqual(nsToMs(42n, 42n), 0); + }); + + it('reports whether a (startNs, endNs) pair is a monotonicity violation', () => { + assert.strictEqual(isNegativeDelta(1_000_000n, 500_000n), true); + assert.strictEqual(isNegativeDelta(42n, 42n), false); + assert.strictEqual(isNegativeDelta(500_000n, 1_000_000n), false); + }); +}); + +describe('computeDurationStats', () => { + it('returns the explicit empty-sample shape for zero frames, not zeros', () => { + const stats = computeDurationStats([]); + assert.deepStrictEqual(stats, { + count: 0, + min: null, + median: null, + p95: null, + max: null, + mean: null, + }); + }); + + // The empty-sample result is a module-level constant handed back by + // reference to every caller, so one caller writing to the object it got + // would rewrite what every LATER empty result reports — a "nothing was + // measured" verdict silently turning into a fabricated number for everyone + // else in the process. Freezing it makes the write a no-op (and a throw in + // strict mode, which every ES module is), so the shared reference stays + // honest no matter what a caller does with it. + it('an empty result cannot be mutated to poison the next empty result', () => { + const first = computeDurationStats([]); + // A caller doing exactly what a caller might do: patching the nulls to + // zeros for its own display code, in place. + assert.throws( + () => { + (first as { count: number }).count = 99; + }, + TypeError, + 'the shared empty-sample object must reject a write, not absorb it', + ); + + const second = computeDurationStats([]); + assert.strictEqual(second.count, 0, 'a later empty result must still report count 0'); + assert.deepStrictEqual(second, { + count: 0, + min: null, + median: null, + p95: null, + max: null, + mean: null, + }); + }); + + it('the empty result is frozen, including against added and deleted fields', () => { + const stats = computeDurationStats([]); + assert.ok(Object.isFrozen(stats), 'the empty-sample constant must be frozen'); + assert.throws(() => { + (stats as unknown as Record).injected = 1; + }, TypeError); + assert.throws(() => { + delete (stats as unknown as Record).count; + }, TypeError); + }); + + it('a non-empty result is a fresh object, unaffected by the empty-sample constant', () => { + const empty = computeDurationStats([]); + const real = computeDurationStats([1, 2, 3]); + assert.notStrictEqual(real, empty); + assert.strictEqual(real.count, 3); + }); + + it('computes min/median/p95/max/mean for a single sample', () => { + const stats = computeDurationStats([7.25]); + assert.deepStrictEqual(stats, { + count: 1, + min: 7.25, + median: 7.25, + p95: 7.25, + max: 7.25, + mean: 7.25, + }); + }); + + it('computes exact statistics over a known, non-round, asymmetric sample', () => { + // 11 values, deliberately unsorted, non-round, no two equal — every + // statistic below has exactly one correct value, so a wrong coefficient + // or an off-by-one rank shows up as a wrong number, not a coincidence. + const durations = [8.1, 41.7, 3.3, 12.9, 6.6, 22.4, 5.05, 9.9, 15.15, 4.4, 30.3]; + const stats = computeDurationStats(durations); + + // sorted: 3.3, 4.4, 5.05, 6.6, 8.1, 9.9, 12.9, 15.15, 22.4, 30.3, 41.7 + assert.strictEqual(stats.count, 11); + assert.strictEqual(stats.min, 3.3); + assert.strictEqual(stats.max, 41.7); + // median: nearest-rank(0.5) over 11 -> ceil(0.5*11)-1 = 5 -> index 5 -> 9.9 + assert.strictEqual(stats.median, 9.9); + // p95: ceil(0.95*11)-1 = ceil(10.45)-1 = 11-1 = 10 -> index 10 -> 41.7 + assert.strictEqual(stats.p95, 41.7); + const sum = 8.1 + 41.7 + 3.3 + 12.9 + 6.6 + 22.4 + 5.05 + 9.9 + 15.15 + 4.4 + 30.3; + assert.ok(Math.abs((stats.mean ?? NaN) - sum / 11) < 1e-9); + }); + + it('p95 picks a mid-sample rank (not always the max) for a larger, unevenly spread sample', () => { + // 20 samples: 19 tightly clustered "normal" frames and 1 extreme + // outlier. p95's rank (ceil(0.95*20)-1 = 18, i.e. the 19th of 20 sorted + // values) lands on the second-highest value, NOT the max outlier — this + // is exactly the case that would silently break if p95 were + // accidentally implemented as "always index length-1". + const normal = [8.0, 8.1, 8.05, 7.95, 8.2, 7.9, 8.15, 8.0, 8.05, 7.85, 8.25, 8.1, 7.9, 8.05, 8.0, 8.1, 7.95, 8.2, 8.0]; + const outlier = 250.0; + const stats = computeDurationStats([...normal, outlier]); + assert.strictEqual(stats.count, 20); + assert.strictEqual(stats.max, 250.0); + // second-highest normal value is 8.25 + assert.strictEqual(stats.p95, 8.25); + assert.notStrictEqual(stats.p95, stats.max); + }); + + it('does not mutate the input array (sorts a copy)', () => { + const input = [3.3, 1.1, 2.2]; + const originalOrder = [...input]; + computeDurationStats(input); + assert.deepStrictEqual(input, originalOrder); + }); +}); diff --git a/packages/renderer/src/frame-timing-stats.ts b/packages/renderer/src/frame-timing-stats.ts new file mode 100644 index 000000000..68d3d9c2a --- /dev/null +++ b/packages/renderer/src/frame-timing-stats.ts @@ -0,0 +1,158 @@ +/* This Source Code Form is subject to the terms of the Mozilla Public + * License, v. 2.0. If a copy of the MPL was not distributed with this + * file, You can obtain one at https://mozilla.org/MPL/2.0/. */ + +/** + * Pure statistics for frame/pass GPU timing (issue #2670 perf-verdict gate). + * + * Everything in this file is arithmetic over plain numbers/bigints — no + * `GPUQuerySet`, no `performance.now()`, nothing that touches a clock or a + * device. That split is deliberate: the thin GPU-facing code in + * `frame-timing-gpu.ts` cannot be exercised without a WebGPU adapter with the + * `timestamp-query` feature (which this environment's Chromium does not + * expose — `navigator.gpu` itself is absent), so every number it produces is + * pushed through here, where it CAN be tested with synthetic values. + */ + +/** + * Summary statistics over a sample of frame or pass durations, in + * milliseconds. + * + * A mean hides exactly the stutter a perf verdict cares about — one frame + * that spikes to 40 ms among fifty at 8 ms barely moves a mean, but it is + * the one a user notices. `p95` (and `max`, its worst case) are the + * statistics this module treats as the headline; `mean` and `median` are + * kept for context, not as the number to gate on. + * + * `count === 0` is the explicit empty-sample marker: every other field is + * `null` rather than `0`, because a real all-zero sample and "nothing was + * measured" must never be indistinguishable to a caller reading this object. + */ +export interface DurationStats { + /** Number of samples the statistics below were computed over. */ + count: number; + min: number | null; + /** 50th percentile (nearest-rank on the sorted sample). */ + median: number | null; + /** 95th percentile (nearest-rank on the sorted sample) — see class doc. */ + p95: number | null; + max: number | null; + /** Arithmetic mean. Context only — do not gate a perf verdict on this. */ + mean: number | null; +} + +/** + * The one empty-sample result, handed back BY REFERENCE to every caller of + * `computeDurationStats([])`. Frozen for exactly that reason: an unfrozen + * shared constant lets one caller's in-place edit (e.g. patching the nulls to + * zeros for its own display code) rewrite what every LATER empty result + * reports, turning an honest "nothing was measured" into a fabricated number + * process-wide. Frozen, such a write is a no-op — a `TypeError` under the + * strict mode every ES module runs in — and the constant stays honest. + */ +const EMPTY_STATS: DurationStats = Object.freeze({ + count: 0, + min: null, + median: null, + p95: null, + max: null, + mean: null, +}); + +/** + * WebGPU timestamp queries resolve to nanoseconds (`BigInt64Array` values + * read back from the resolve buffer). The renderer's budgets and every other + * timing surface in this codebase (`FrameStats.timestamp` via + * `performance.now()`) are in milliseconds, so every raw pair gets converted + * through this one function. + * + * Takes `bigint` (the actual readback type) so a caller cannot accidentally + * pass an already-lossy `Number(timestamp)` of a value that may exceed + * `Number.MAX_SAFE_INTEGER` (a query set can hold timestamps for a + * long-running session; ~104 days of nanoseconds overflows a JS number). + * The subtraction happens in `bigint` space and only the final, small + * (sub-second, in practice sub-100ms) millisecond duration is converted to + * `number`. + * + * Clamps a negative delta (`endNs < startNs`) to `0` rather than returning + * a physically impossible negative duration. This is reachable: GPU + * timestamps are not guaranteed monotonic across a device reset (see this + * module's own doc above). `0` is the honest floor — a duration cannot be + * negative, and unlike a raw negative number it cannot silently drag a + * `min`/`mean` computed downstream into nonsense. This is the guard's one + * choke point: `frameTotalMs`/`passDurationsMs` (`frame-timing.ts`) sum + * this function's output directly, without ever routing it through + * `computeDurationStats`, so a guard placed only in `computeDurationStats` + * would miss that summation entirely. Use `isNegativeDelta` alongside this + * function where the caller wants to know a clamp happened. + */ +export function nsToMs(startNs: bigint, endNs: bigint): number { + const deltaNs = endNs - startNs; + if (deltaNs < 0n) return 0; + return Number(deltaNs) / 1_000_000; +} + +/** + * Reports whether `(startNs, endNs)` is a monotonicity violation (`endNs < + * startNs`) — the only case the module's own doc calls out as reachable: + * GPU timestamps "are not guaranteed monotonic across a device reset". + * + * This is the guard's true origin point: `nsToMs` alone cannot both return a + * single honest millisecond number for every downstream summation (see + * `frameTotalMs`/`passDurationsMs` in `frame-timing.ts`, which add its + * output directly into a running total and never pass through + * `computeDurationStats`) AND separately expose "this one was bad" — a + * plain `number` return has no second channel for that. Callers that want + * to surface an invalid-sample count (rather than let a clamped-to-0 value + * pass as an unremarkable real zero) call this predicate on the same raw + * pair alongside `nsToMs`. `computeDurationStats` is deliberately NOT where + * this lives: by the time a caller has an array of plain millisecond + * numbers, it has no way to tell a clamped GPU-reset zero apart from a + * genuine fast pass or a CPU-fallback delta (which is never negative — it + * comes from `performance.now()`, spec-guaranteed non-decreasing) — see + * that function's doc. + */ +export function isNegativeDelta(startNs: bigint, endNs: bigint): boolean { + return endNs - startNs < 0n; +} + +/** + * Nearest-rank percentile over `sorted` (must already be sorted ascending). + * `p` is a fraction in `[0, 1]`. Rounds the rank rather than interpolating — + * cheap, deterministic, and matches how `p95`/`median` are colloquially read + * off a sorted sample in perf work. + */ +function percentile(sorted: readonly number[], p: number): number { + if (sorted.length === 1) return sorted[0]; + const rank = Math.ceil(p * sorted.length) - 1; + const clamped = Math.min(Math.max(rank, 0), sorted.length - 1); + return sorted[clamped]; +} + +/** + * Reduces a sample of durations (milliseconds) to summary statistics. Pure: + * no side effects, no clock reads — the durations are supplied by the + * caller, whether they came from GPU timestamp queries or the CPU + * frame-delta fallback (see `frame-timing.ts`). + * + * `durationsMs.length === 0` returns `EMPTY_STATS` (`count: 0`, every other + * field `null`) rather than computing `0`s — a percentile or a mean over an + * empty array is either `NaN` (misreported as a real "instant" frame) or a + * divide-by-zero, and either would read as "this was fast" instead of "this + * was never measured". + */ +export function computeDurationStats(durationsMs: readonly number[]): DurationStats { + if (durationsMs.length === 0) return EMPTY_STATS; + + const sorted = [...durationsMs].sort((a, b) => a - b); + const sum = sorted.reduce((acc, v) => acc + v, 0); + + return { + count: sorted.length, + min: sorted[0], + median: percentile(sorted, 0.5), + p95: percentile(sorted, 0.95), + max: sorted[sorted.length - 1], + mean: sum / sorted.length, + }; +} diff --git a/packages/renderer/src/frame-timing.test.ts b/packages/renderer/src/frame-timing.test.ts new file mode 100644 index 000000000..b56b1328b --- /dev/null +++ b/packages/renderer/src/frame-timing.test.ts @@ -0,0 +1,293 @@ +/* This Source Code Form is subject to the terms of the Mozilla Public + * License, v. 2.0. If a copy of the MPL was not distributed with this + * file, You can obtain one at https://mozilla.org/MPL/2.0/. */ + +import { describe, it } from 'node:test'; +import assert from 'node:assert'; + +import { + decideTimingMode, + passDurationsMs, + frameTotalMs, + aggregateFrameTimings, + type PassTimingSample, +} from './frame-timing.js'; + +describe('decideTimingMode', () => { + it('is disabled when not enabled, regardless of feature support', () => { + assert.strictEqual(decideTimingMode({ enabled: false, hasTimestampQueryFeature: true }), 'disabled'); + assert.strictEqual(decideTimingMode({ enabled: false, hasTimestampQueryFeature: false }), 'disabled'); + }); + + it('uses GPU queries when enabled and the feature is present', () => { + assert.strictEqual(decideTimingMode({ enabled: true, hasTimestampQueryFeature: true }), 'gpu-queries'); + }); + + it('falls back to CPU timing when enabled, feature absent, fallback allowed (default)', () => { + assert.strictEqual(decideTimingMode({ enabled: true, hasTimestampQueryFeature: false }), 'cpu-fallback'); + assert.strictEqual( + decideTimingMode({ enabled: true, hasTimestampQueryFeature: false, allowCpuFallback: true }), + 'cpu-fallback', + ); + }); + + it('is disabled (not silently reporting anything) when enabled, feature absent, fallback explicitly refused', () => { + assert.strictEqual( + decideTimingMode({ enabled: true, hasTimestampQueryFeature: false, allowCpuFallback: false }), + 'disabled', + ); + }); + + it('the feature-absent path never throws', () => { + assert.doesNotThrow(() => decideTimingMode({ enabled: true, hasTimestampQueryFeature: false })); + }); +}); + +/** + * `assert.deepStrictEqual` compares prototypes, and the by-label accumulators + * are deliberately null-prototype (see `passDurationsMs`), so an expectation + * written as a plain `{}` literal would not match. Building the expectation + * the same way keeps the comparison exactly as strict — and additionally pins + * that the null prototype is still there. + */ +function bareMap(entries: Record): Record { + return Object.assign(Object.create(null) as Record, entries); +} + +describe('passDurationsMs — single pass', () => { + it('converts one pass to its millisecond duration under its label', () => { + const samples: PassTimingSample[] = [{ label: 'main', startNs: 1_000_000n, endNs: 5_500_000n }]; + assert.deepStrictEqual(passDurationsMs(samples), bareMap({ main: 4.5 })); + }); +}); + +describe('passDurationsMs — multiple passes in one frame', () => { + it('keeps distinct labels separate', () => { + const samples: PassTimingSample[] = [ + { label: 'shadow', startNs: 0n, endNs: 2_100_000n }, + { label: 'main', startNs: 2_100_000n, endNs: 9_800_000n }, + { label: 'sky', startNs: 9_800_000n, endNs: 10_050_000n }, + ]; + assert.deepStrictEqual(passDurationsMs(samples), bareMap({ shadow: 2.1, main: 7.7, sky: 0.25 })); + }); + + it('sums two passes sharing one label (e.g. repeated shadow cascades)', () => { + const samples: PassTimingSample[] = [ + { label: 'shadow', startNs: 0n, endNs: 1_250_000n }, // 1.25ms + { label: 'shadow', startNs: 1_250_000n, endNs: 3_400_000n }, // 2.15ms + ]; + assert.deepStrictEqual(passDurationsMs(samples), bareMap({ shadow: 3.4 })); + }); +}); + +describe('frameTotalMs', () => { + it('sums every pass duration for the frame total', () => { + const samples: PassTimingSample[] = [ + { label: 'shadow', startNs: 0n, endNs: 2_100_000n }, + { label: 'main', startNs: 2_100_000n, endNs: 9_800_000n }, + { label: 'sky', startNs: 9_800_000n, endNs: 10_050_000n }, + ]; + // 2.1 + 7.7 + 0.25 + assert.strictEqual(frameTotalMs(samples), 10.05); + }); + + it('is 0 for a frame with zero recorded passes (not an empty-sample marker — a real frame that measured nothing)', () => { + assert.strictEqual(frameTotalMs([]), 0); + }); + + it('a non-monotonic (end < start) pass contributes 0, not a negative amount, to the frame total', () => { + // A GPU clock reset (see nsToMs's doc) can produce end < start for one + // pass among otherwise-valid ones. frameTotalMs sums nsToMs's raw + // output directly (it never routes through computeDurationStats), so + // this is the exact path that a guard placed only in + // computeDurationStats would miss. + const samples: PassTimingSample[] = [ + { label: 'shadow', startNs: 0n, endNs: 2_100_000n }, // 2.1ms + { label: 'main', startNs: 9_800_000n, endNs: 3_400_000n }, // corrupted: end < start + { label: 'sky', startNs: 9_800_000n, endNs: 10_050_000n }, // 0.25ms + ]; + // 2.1 + 0 (clamped) + 0.25, not 2.1 + (-6.4) + 0.25 + assert.strictEqual(frameTotalMs(samples), 2.35); + }); +}); + +describe('aggregateFrameTimings — feature-absent / disabled path', () => { + it('reports mode disabled with empty-sample stats when there is no history', () => { + const report = aggregateFrameTimings('disabled', []); + assert.strictEqual(report.mode, 'disabled'); + assert.strictEqual(report.frame.count, 0); + assert.deepStrictEqual(report.passes, bareMap({})); + }); +}); + +describe('aggregateFrameTimings — zero frames with a mode set', () => { + it('does not divide by zero or report a misleading 0 for gpu-queries mode with no recorded frames', () => { + const report = aggregateFrameTimings('gpu-queries', []); + assert.strictEqual(report.mode, 'gpu-queries'); + assert.deepStrictEqual(report.frame, { + count: 0, + min: null, + median: null, + p95: null, + max: null, + mean: null, + }); + }); +}); + +describe('aggregateFrameTimings — multiple frames', () => { + it('aggregates per-frame totals and per-label stats across frames, including a label missing from one frame', () => { + const frames: PassTimingSample[][] = [ + [ + { label: 'shadow', startNs: 0n, endNs: 2_000_000n }, // 2ms + { label: 'main', startNs: 2_000_000n, endNs: 10_000_000n }, // 8ms + ], + [ + // 'shadow' absent this frame (e.g. shadows disabled mid-session) — + // must not be treated as a 0ms sample for the 'shadow' label. + { label: 'main', startNs: 0n, endNs: 12_500_000n }, // 12.5ms + ], + [ + { label: 'shadow', startNs: 0n, endNs: 3_400_000n }, // 3.4ms + { label: 'main', startNs: 3_400_000n, endNs: 9_900_000n }, // 6.5ms + ], + ]; + const report = aggregateFrameTimings('gpu-queries', frames); + + assert.strictEqual(report.frame.count, 3); + // frame totals: 10, 12.5, 9.9 + assert.strictEqual(report.frame.min, 9.9); + assert.strictEqual(report.frame.max, 12.5); + + assert.strictEqual(report.passes.shadow.count, 2); // only 2 frames had a shadow pass + assert.strictEqual(report.passes.shadow.min, 2); + assert.strictEqual(report.passes.shadow.max, 3.4); + + assert.strictEqual(report.passes.main.count, 3); + assert.strictEqual(report.passes.main.max, 12.5); + // No monotonicity violations anywhere in this fixture. + assert.strictEqual(report.invalidSampleCount, 0); + }); +}); + +describe('aggregateFrameTimings — invalidSampleCount (non-monotonic GPU timestamp pairs)', () => { + it('counts a single negative-delta sample among otherwise-valid frames, and still clamps its contribution to 0 rather than poisoning min/mean', () => { + const frames: PassTimingSample[][] = [ + [ + { label: 'shadow', startNs: 0n, endNs: 2_000_000n }, // 2ms, valid + { label: 'main', startNs: 8_000_000n, endNs: 1_500_000n }, // corrupted: end < start + ], + [{ label: 'shadow', startNs: 0n, endNs: 3_150_000n }], // 3.15ms, valid + ]; + const report = aggregateFrameTimings('gpu-queries', frames); + + assert.strictEqual(report.invalidSampleCount, 1); + // frame totals: (2 + 0 clamped) = 2, and 3.15 — never a negative min. + assert.strictEqual(report.frame.min, 2); + assert.strictEqual(report.frame.max, 3.15); + assert.ok((report.frame.mean ?? NaN) >= 0); + }); + + it('counts every sample when all are non-monotonic, and reports clamped-0 stats rather than a fabricated negative verdict', () => { + const frames: PassTimingSample[][] = [ + [{ label: 'main', startNs: 5_000_000n, endNs: 1_000_000n }], // corrupted + [{ label: 'main', startNs: 9_876_543n, endNs: 1_234_567n }], // corrupted, non-round + ]; + const report = aggregateFrameTimings('gpu-queries', frames); + + assert.strictEqual(report.invalidSampleCount, 2); + assert.strictEqual(report.frame.min, 0); + assert.strictEqual(report.frame.max, 0); + assert.strictEqual(report.frame.mean, 0); + }); + + it('a legitimate zero-delta pass is not counted as invalid', () => { + const frames: PassTimingSample[][] = [[{ label: 'main', startNs: 42n, endNs: 42n }]]; + const report = aggregateFrameTimings('gpu-queries', frames); + assert.strictEqual(report.invalidSampleCount, 0); + assert.strictEqual(report.frame.min, 0); + }); + + it('the empty-history case is unaffected: invalidSampleCount is 0 and stats stay the explicit EMPTY_STATS shape', () => { + const report = aggregateFrameTimings('disabled', []); + assert.strictEqual(report.invalidSampleCount, 0); + assert.deepStrictEqual(report.frame, { + count: 0, + min: null, + median: null, + p95: null, + max: null, + mean: null, + }); + }); +}); + +// A pass label is caller-chosen free text (`PassTimingSample.label`), and the +// per-label accumulators are keyed by it directly. On a plain `{}` the +// inherited `Object.prototype` names are live: `totals['__proto__'] = n` is a +// setter call that is silently DROPPED (no own property is created, so the +// label vanishes from the report), and `totals['constructor'] ?? 0` reads the +// inherited `Object` function, so `+ ms` string-concatenates into +// `"function Object() { [native code] }4.5"` instead of summing. This is a +// correctness boundary, not a security one: a report that silently loses or +// corrupts a pass is worse than one that omits it loudly. `Object.create(null)` +// removes the inherited names entirely, so every label is just a key. +describe('passDurationsMs — labels that collide with Object.prototype', () => { + it('records a __proto__ pass as an own key instead of silently dropping it', () => { + const totals = passDurationsMs([{ label: '__proto__', startNs: 1_000_000n, endNs: 5_500_000n }]); + assert.ok( + Object.hasOwn(totals, '__proto__'), + 'a __proto__-labelled pass must be an own key, not a swallowed prototype assignment', + ); + assert.strictEqual(totals['__proto__'], 4.5); + // And it must be a real entry in the enumerable shape — that is what + // aggregateFrameTimings' `Object.entries()` walk actually consumes. + assert.deepStrictEqual(Object.entries(totals), [['__proto__', 4.5]]); + }); + + it('sums two __proto__ passes rather than losing both', () => { + const totals = passDurationsMs([ + { label: '__proto__', startNs: 0n, endNs: 1_250_000n }, + { label: '__proto__', startNs: 1_250_000n, endNs: 3_400_000n }, + ]); + assert.strictEqual(totals['__proto__'], 3.4); + }); + + it('sums a constructor-labelled pass as a number, not a concatenated function source', () => { + const totals = passDurationsMs([{ label: 'constructor', startNs: 0n, endNs: 2_000_000n }]); + assert.strictEqual( + totals.constructor, + 2, + 'the inherited Object constructor must not be read as the running total', + ); + }); + + it('leaves ordinary labels untouched alongside a hostile one', () => { + const totals = passDurationsMs([ + { label: 'main', startNs: 0n, endNs: 8_000_000n }, + { label: '__proto__', startNs: 8_000_000n, endNs: 10_000_000n }, + ]); + assert.strictEqual(totals.main, 8); + assert.strictEqual(totals['__proto__'], 2); + }); +}); + +describe('aggregateFrameTimings — labels that collide with Object.prototype', () => { + // `report.passes` is accumulated by the same by-label-key pattern, so it + // carries the same defect INDEPENDENTLY of passDurationsMs': + // `passes['__proto__'] = stats` on a plain object sets the PROTOTYPE (the + // value is an object, so the setter accepts it) and creates no own key at + // all — the pass disappears from the aggregated report even once + // passDurationsMs itself is fixed. + it('keeps a __proto__ pass label in report.passes', () => { + const report = aggregateFrameTimings('gpu-queries', [ + [{ label: '__proto__', startNs: 0n, endNs: 2_000_000n }], + [{ label: '__proto__', startNs: 0n, endNs: 4_000_000n }], + ]); + assert.ok(Object.hasOwn(report.passes, '__proto__'), 'the label must survive into report.passes'); + assert.strictEqual(report.passes['__proto__'].count, 2); + assert.strictEqual(report.passes['__proto__'].min, 2); + assert.strictEqual(report.passes['__proto__'].max, 4); + assert.strictEqual(report.frame.count, 2, 'the frame totals are unaffected either way'); + }); +}); diff --git a/packages/renderer/src/frame-timing.ts b/packages/renderer/src/frame-timing.ts new file mode 100644 index 000000000..3eb0b63f5 --- /dev/null +++ b/packages/renderer/src/frame-timing.ts @@ -0,0 +1,174 @@ +/* This Source Code Form is subject to the terms of the Mozilla Public + * License, v. 2.0. If a copy of the MPL was not distributed with this + * file, You can obtain one at https://mozilla.org/MPL/2.0/. */ + +/** + * Frame/pass timing: mode selection and multi-frame aggregation (issue #2670 + * perf-verdict gate). Pure — see `frame-timing-stats.ts` for the statistics + * primitives this builds on, and `frame-timing-gpu.ts` for the thin + * GPU-facing code that produces the raw samples consumed here. + * + * Timestamp queries (`GPUQuerySet` of type `'timestamp'`) require the + * `'timestamp-query'` adapter feature, which is NOT always available — this + * module's job is to decide, from a plain boolean feature flag, what mode to + * run in, and to turn raw per-pass nanosecond pairs into the millisecond + * statistics a caller reads. None of that requires a live device. + */ + +import { computeDurationStats, nsToMs, isNegativeDelta, type DurationStats } from './frame-timing-stats.js'; + +/** + * How frame timing is actually running, after feature detection: + * - `'gpu-queries'` — real GPU timestamp queries (most accurate; includes + * time the CPU never sees, e.g. queued/overlapping work on the GPU). + * - `'cpu-fallback'` — wall-clock deltas around `render()` on the CPU side. + * Labelled explicitly wherever it is reported: it measures a DIFFERENT + * thing (CPU-observed frame cadence, inflated by anything that blocks the + * main thread) and must never be presented next to a GPU-queries number + * as if the two were comparable. + * - `'disabled'` — not measuring. The default; see `decideTimingMode`. + */ +export type TimingMode = 'gpu-queries' | 'cpu-fallback' | 'disabled'; + +export interface TimingModeRequest { + /** Instrumentation is opt-in (see module doc on the renderer entry point). Defaults to not enabled by every caller in this codebase. */ + enabled: boolean; + /** Whether the adapter this session got advertises the `'timestamp-query'` feature. */ + hasTimestampQueryFeature: boolean; + /** + * When GPU queries are unavailable, fall back to CPU-side frame-delta + * timing instead of measuring nothing. Defaults to `true` when omitted — + * pass `false` for a caller that only ever wants labelled GPU numbers, or + * silence. + */ + allowCpuFallback?: boolean; +} + +/** + * Decides which timing mode to run in. Pure decision table: + * + * | enabled | hasTimestampQueryFeature | allowCpuFallback | → mode | + * |---------|--------------------------|------------------|-----------------| + * | false | * | * | disabled | + * | true | true | * | gpu-queries | + * | true | false | true (default) | cpu-fallback | + * | true | false | false | disabled | + * + * Never throws: an absent feature degrades to a labelled fallback (or to + * `disabled`), it never crashes the caller for asking. + */ +export function decideTimingMode(request: TimingModeRequest): TimingMode { + if (!request.enabled) return 'disabled'; + if (request.hasTimestampQueryFeature) return 'gpu-queries'; + const allowCpuFallback = request.allowCpuFallback ?? true; + return allowCpuFallback ? 'cpu-fallback' : 'disabled'; +} + +/** One resolved GPU timestamp-query pair for a single pass within one frame. */ +export interface PassTimingSample { + /** Caller-chosen label, e.g. `'shadow'`, `'main'`, `'sky'`. Passes sharing a label within one frame are summed (see `passDurationsMs`) — useful for e.g. multiple shadow cascades rendered as repeated passes under one logical name. */ + label: string; + startNs: bigint; + endNs: bigint; +} + +/** + * Per-pass durations (ms) for ONE frame, summed by label. A frame with two + * `'shadow'` passes and one `'main'` pass returns `{ shadow: , + * main: }` — the frame's per-pass breakdown, not a list + * of raw pairs. + */ +export function passDurationsMs(samples: readonly PassTimingSample[]): Record { + // Null-prototype: labels are caller-chosen free text, and on a plain `{}` the + // inherited `Object.prototype` names are live. `totals['__proto__'] = ms` + // invokes the prototype setter and is silently dropped (the pass vanishes), + // and `totals['constructor'] ?? 0` reads the inherited `Object` function, so + // `+ ms` string-concatenates instead of summing. A bare map has no inherited + // names, so every label is only ever a key. + const totals: Record = Object.create(null) as Record; + for (const sample of samples) { + const ms = nsToMs(sample.startNs, sample.endNs); + totals[sample.label] = (totals[sample.label] ?? 0) + ms; + } + return totals; +} + +/** + * Total GPU time (ms) for one frame: the sum of every pass's duration. + * WebGPU passes on one queue do not overlap, so summing durations is the + * frame total — there is no separate "frame envelope" timestamp pair to + * reconcile against. + */ +export function frameTotalMs(samples: readonly PassTimingSample[]): number { + let total = 0; + for (const sample of samples) { + total += nsToMs(sample.startNs, sample.endNs); + } + return total; +} + +/** Aggregated statistics across many recorded frames. */ +export interface FrameTimingReport { + mode: TimingMode; + /** Statistics over each frame's total GPU (or CPU-fallback) time. */ + frame: DurationStats; + /** Statistics over each pass label's per-frame duration, keyed by label. A label absent from a given frame simply contributes no sample to its stats that frame — it is not treated as a 0ms sample. */ + passes: Record; + /** + * Count of raw `(startNs, endNs)` pairs across every frame/pass where + * `endNs < startNs` — a GPU clock non-monotonicity (see `nsToMs`'s doc). + * Each such sample is clamped to a 0ms contribution in `frame`/`passes` + * above rather than dragging `min`/`mean` negative, but a clamped 0 reads + * identically to a genuine zero-duration pass unless this count is + * checked — surfaced explicitly here for the same reason `DurationStats` + * gives empty samples their own explicit shape instead of a silent `0`: + * this API does not report a number it cannot stand behind without also + * saying when it had to make one up. + */ + invalidSampleCount: number; +} + +/** + * Reduces a history of per-frame pass samples into a `FrameTimingReport`. + * `frames` is empty for a session where nothing was ever recorded (or the + * mode is `'disabled'`) — `computeDurationStats([])` already returns the + * explicit `count: 0` / all-`null` shape for that case, so no special + * handling is needed here beyond passing `mode` through. + */ +export function aggregateFrameTimings( + mode: TimingMode, + frames: readonly (readonly PassTimingSample[])[], +): FrameTimingReport { + const frameDurations = frames.map((f) => frameTotalMs(f)); + + const perLabelDurations = new Map(); + let invalidSampleCount = 0; + for (const frame of frames) { + const perLabel = passDurationsMs(frame); + for (const [label, ms] of Object.entries(perLabel)) { + const list = perLabelDurations.get(label); + if (list) list.push(ms); + else perLabelDurations.set(label, [ms]); + } + for (const sample of frame) { + if (isNegativeDelta(sample.startNs, sample.endNs)) invalidSampleCount++; + } + } + + // Same null-prototype reason as `passDurationsMs` above, and it is a + // SEPARATE accumulator: `passes['__proto__'] = stats` on a plain object + // assigns the prototype (the value is an object, so the setter takes it) and + // creates no own key, dropping the label from the report even when + // `passDurationsMs` handed it over correctly. + const passes: Record = Object.create(null) as Record; + for (const [label, durations] of perLabelDurations) { + passes[label] = computeDurationStats(durations); + } + + return { + mode, + frame: computeDurationStats(frameDurations), + passes, + invalidSampleCount, + }; +} diff --git a/packages/renderer/src/index.ts b/packages/renderer/src/index.ts index a33c9717f..c5120f8e4 100644 --- a/packages/renderer/src/index.ts +++ b/packages/renderer/src/index.ts @@ -84,6 +84,18 @@ export { isEntityVisible } from './entity-visibility.js'; export { DEFAULT_GHOST_ALPHA, OPAQUE_ALPHA_CUTOFF } from './overlay-routing.js'; export { VisibilityEpochTracker } from './visibility-epoch.js'; export type { FrameStats, ResidentGpuBytes } from './render-stats.js'; +// Frame/pass GPU timing (issue #2670 perf-verdict gate). Opt-in and NOT wired +// into `Renderer` by default — a caller constructs `GpuFrameTimingRecorder` +// itself and attaches its `timestampWrites` to the passes it wants measured; +// see `frame-timing-gpu.ts`'s module doc for the usage pattern, and +// `decideTimingMode` for choosing GPU queries vs. the CPU fallback vs. off. +export { decideTimingMode, passDurationsMs, frameTotalMs, aggregateFrameTimings } from './frame-timing.js'; +export type { TimingMode, TimingModeRequest, PassTimingSample, FrameTimingReport } from './frame-timing.js'; +export { computeDurationStats, nsToMs, isNegativeDelta } from './frame-timing-stats.js'; +export type { DurationStats } from './frame-timing-stats.js'; +export { GpuFrameTimingRecorder, hasTimestampQueryFeature } from './frame-timing-gpu.js'; +export { createCpuFrameTicker } from './frame-timing-cpu.js'; +export type { CpuFrameTicker } from './frame-timing-cpu.js'; export { RaycastEngine } from './raycast-engine.js'; export type { RenderDegradationInfo } from './render-degradation.js'; export { PointPicker, decodePickSample } from './point-picker.js'; diff --git a/packages/renderer/src/webgpu-types.d.ts b/packages/renderer/src/webgpu-types.d.ts index 6c61bb4a8..16014ffd1 100644 --- a/packages/renderer/src/webgpu-types.d.ts +++ b/packages/renderer/src/webgpu-types.d.ts @@ -78,6 +78,7 @@ interface GPUDevice extends EventTarget { createTexture(descriptor: GPUTextureDescriptor): GPUTexture; createBindGroup(descriptor: GPUBindGroupDescriptor): GPUBindGroup; createBindGroupLayout(descriptor: GPUBindGroupLayoutDescriptor): GPUBindGroupLayout; + createQuerySet(descriptor: GPUQuerySetDescriptor): GPUQuerySet; pushErrorScope(filter: GPUErrorFilter): void; popErrorScope(): Promise<{ readonly message: string } | null>; onuncapturederror: ((this: GPUDevice, event: GPUUncapturedErrorEvent) => void) | null; @@ -134,6 +135,7 @@ interface GPUCommandEncoder { finish(): GPUCommandBuffer; copyBufferToBuffer(source: GPUBuffer, sourceOffset: number, destination: GPUBuffer, destinationOffset: number, size: number): void; copyTextureToBuffer(source: GPUImageCopyTexture, destination: GPUImageCopyBuffer, copySize: GPUExtent3D): void; + resolveQuerySet(querySet: GPUQuerySet, firstQuery: number, queryCount: number, destination: GPUBuffer, destinationOffset: number): void; } interface GPURenderPassEncoder { @@ -376,6 +378,17 @@ interface GPUPipelineLayoutDescriptor { interface GPUQuerySet { readonly label?: string; + readonly type?: GPUQueryType; + readonly count?: number; + destroy(): void; +} + +type GPUQueryType = 'occlusion' | 'timestamp'; + +interface GPUQuerySetDescriptor { + type: GPUQueryType; + count: number; + label?: string; } interface GPURenderPassTimestampWrites { diff --git a/scripts/api-surface.json b/scripts/api-surface.json index 569c734a0..99dfbf3e8 100644 --- a/scripts/api-surface.json +++ b/scripts/api-surface.json @@ -3788,6 +3788,7 @@ "ColdGeometryProvider: interface", "ContactShadingQuality: type", "ContributionCullOptions: interface", + "CpuFrameTicker: interface", "CullCameraState: interface", "CutPolygon2D: interface", "DEFAULT_CAP_STYLE: const", @@ -3795,13 +3796,16 @@ "DEFAULT_GHOST_ALPHA: const", "DecodedPickSample: interface", "DrawingLine2D: interface", + "DurationStats: interface", "ENVIRONMENT_UNIFORM_SIZE: const", "EdgeLockInput: interface", "FederationRegistry: class", "FitPolicy: interface", "FitPolicyKind: type", "FrameStats: interface", + "FrameTimingReport: interface", "GlobalIdLookup: interface", + "GpuFrameTimingRecorder: class", "HATCH_PATTERN_IDS: const", "HatchPatternId: type", "Intersection: interface", @@ -3817,6 +3821,7 @@ "Mesh: interface", "ModelRange: interface", "OPAQUE_ALPHA_CUTOFF: const", + "PassTimingSample: interface", "PickClipState: interface", "PickFitPolicyOptions: interface", "PickOptions: interface", @@ -3874,23 +3879,34 @@ "SymbolicTextAtlas: class", "SymbolicTextInput: interface", "SymbolicTextPipeline: class", + "TimingMode: type", + "TimingModeRequest: interface", "Vec3: interface", "Vec3Color: type", "Vec3Tuple: type", "VisibilityEpochTracker: class", "VisualEnhancementOptions: interface", "WebGPUDevice: class", + "aggregateFrameTimings: function", "bucketBaseKeyFor: function", "chunkCellKey: function", + "computeDurationStats: function", + "createCpuFrameTicker: function", + "decideTimingMode: function", "decodePickSample: function", "deriveSkyGradient: function", "federationRegistry: const", + "frameTotalMs: function", + "hasTimestampQueryFeature: function", "isEntityVisible: function", + "isNegativeDelta: function", "lodCellSizeForBounds: function", "nearestCardinalAxis: function", + "nsToMs: function", "octDecode: function", "octEncode: function", "packEnvironmentUniforms: function", + "passDurationsMs: function", "pickFitPolicy: function", "planeBasis: function", "projectedAabbRadiusPx: function",