From e1796bd590393aeae088fa5f318ac9139d479b24 Mon Sep 17 00:00:00 2001 From: Bernard <63512176+BernardJen@users.noreply.github.com> Date: Fri, 21 Aug 2026 15:54:30 +0200 Subject: [PATCH] fix: report the frame rate each saver actually achieves The wall is laggy on the split-flap board and slow on some screensavers, and after the GPU report ruled out the obvious cause there was still no way to see the frame rate it was achieving. Two hypotheses have now been measured and refuted: software rendering fallback refuted -- the wall runs ANGLE on an RTX PRO 4000 Blackwell over D3D11, with gpu_compositing enabled and float targets available the unconditional Art-Net refuted as the cause -- real, but 4%. frame readback Measured against Mandelbrot at 6000x1200: 29.8 -> 28.5 fps. Invisible against Split Flap because both runs sit on the ~120 fps vsync cap, which is the trap #225 warned about What is left unexplained is ~6 of 32 cores busy continuously on that machine, with 57 GB of RAM free and a healthy GPU. Guessing a third time is not worth it, so this adds the measurement instead. ## The instrument One property increment per frame, in a loop that already increments a counter. No readback, no allocation, no timing call on the hot path -- the thing being measured must not be changed by measuring it. Counters are keyed per runtime and labelled from one level up: the 30 savers each call createGLRuntime() inside their own create(), so the registry announces the name before instantiating, rather than threading a label through 30 files. The two split-flap boards are labelled per side, because in dual view they are separate runtimes and an aggregate would hide one being slower than the other. Verified end to end in the state the wall is actually in -- two boards and a live saver at once: Split Flap (left) 58.2 53.5 62.9 4 1182x2260 Split Flap (right) 58.2 53.5 62.9 4 1182x2260 Moire Interference 58.5 53.5 63.9 4 2582x2260 min and max are per interval, not per frame, because a saver that averages 60 and drops to 8 for one interval is the interesting case and a mean alone hides it. Every row carries the resolution: every fps figure in this repo has been misread at least once for want of knowing what it was taken at (#225). ## On disk **One file, overwritten, never appended** -- the same discipline as the GPU report. Rows are per saver, not per sample: 30 savers plus two boards is the ceiling, main caps the file at 60 lines, and the file measured 404 bytes after a minute with three runtimes live. Bounded by the number of savers rather than by uptime, which is the property that matters on a wall left running for months. Counters are read every 15s and written every 60s; the read is memory-only, and only the write touches disk. ## Deliberately not included The Art-Net readback fix, even though it is measured and ready. If it shipped alongside this, the wall's first numbers would already be post-fix and its real cost on that hardware would be unmeasurable. Instrument first, then fix, then compare. 11 new tests, 618 -> 629, covering the folding and formatting -- a wrong number here would send the next round of diagnosis somewhere useless. The counter itself lives in the GL frame loop and needs a context to exercise. --- input_viewer_electron/src/main/index.js | 24 +++ input_viewer_electron/src/preload/index.js | 4 + .../src/renderer/renderer.js | 129 ++++++++++++++- .../src/renderer/screensavers/gl-base.js | 78 +++++++++- .../src/renderer/screensavers/registry.js | 4 + input_viewer_electron/test/fps-report.test.js | 147 ++++++++++++++++++ 6 files changed, 384 insertions(+), 2 deletions(-) create mode 100644 input_viewer_electron/test/fps-report.test.js diff --git a/input_viewer_electron/src/main/index.js b/input_viewer_electron/src/main/index.js index 2e344ea..1aa6a3b 100644 --- a/input_viewer_electron/src/main/index.js +++ b/input_viewer_electron/src/main/index.js @@ -451,6 +451,30 @@ function gpuReportPath() { return path.join(app.getPath('userData'), 'gpu-report.txt') } +// Frame-rate report (fps-report.txt). +// +// Same discipline as the GPU report and for the same reason: **one file, +// overwritten, never appended.** The renderer holds one row per saver in memory and +// sends a formatted body, so the size is bounded by the number of savers -- about +// 32 rows -- rather than by how long the wall has been running. A 60s cadence on a +// few KB of overwrite is nothing; the same cadence on an append would be the +// gigabytes this was asked to avoid. +const FPS_REPORT_MAX_LINES = 60 + +ipcMain.handle('write-fps-report', (event, body) => { + const file = path.join(app.getPath('userData'), 'fps-report.txt') + try { + const header = `Input Viewer ${app.getVersion()} -- frame rate report\n` + + `written ${new Date().toISOString()}\n` + const lines = String(body ?? '').split('\n').slice(0, FPS_REPORT_MAX_LINES) + fs.writeFileSync(file, header + lines.join('\n') + '\n') + return file + } catch (err) { + console.error('[FPS] report write failed:', err) + return null + } +}) + ipcMain.handle('write-gpu-report', async (event, rendererInfo) => { const file = gpuReportPath() const lines = [] diff --git a/input_viewer_electron/src/preload/index.js b/input_viewer_electron/src/preload/index.js index 51ccea8..be954e0 100644 --- a/input_viewer_electron/src/preload/index.js +++ b/input_viewer_electron/src/preload/index.js @@ -30,6 +30,10 @@ contextBridge.exposeInMainWorld('electronAPI', { // writes a single overwritten file. writeGpuReport: (rendererInfo) => ipcRenderer.invoke('write-gpu-report', rendererInfo), + // Frame-rate report. One overwritten file; the renderer sends a formatted body + // rather than raw samples, so main stays a dumb writer. + writeFpsReport: (body) => ipcRenderer.invoke('write-fps-report', body), + // System volume control getSystemVolume: () => ipcRenderer.invoke('get-system-volume'), setSystemVolume: (volume) => ipcRenderer.invoke('set-system-volume', volume), diff --git a/input_viewer_electron/src/renderer/renderer.js b/input_viewer_electron/src/renderer/renderer.js index a77acee..ee032e2 100644 --- a/input_viewer_electron/src/renderer/renderer.js +++ b/input_viewer_electron/src/renderer/renderer.js @@ -45,7 +45,7 @@ import { } from './screensavers/registry.js' import { installWeatherSource } from './screensavers/weather-source.js' import { installArtnetSync, getArtnetSync } from './screensavers/artnet-sync.js' -import { observeFrames } from './screensavers/gl-base.js' +import { observeFrames, sampleFrameCounters, setNextRuntimeLabel } from './screensavers/gl-base.js' // Imported directly rather than through the registry: the split-flap board is // the no-signal display, not one of the rotating screensavers (#92). @@ -1000,6 +1000,9 @@ function startNoSignalBoard(side, overlay) { canvas.width = Math.max(1, Math.round(rect.width)) canvas.height = Math.max(1, Math.round(rect.height)) try { + // Named per side: in dual view there are two boards, each its own runtime, and + // an aggregate would hide one being slower than the other. + setNextRuntimeLabel(`Split Flap (${side})`) const board = splitFlap.create(canvas) board.start() noSignalBoards[side] = board @@ -1536,6 +1539,124 @@ function updateDropdownVisibility() { /** * Render the simplified dropdown input lists (enabled inputs only) */ +// ============================================================================= +// Frame-rate report +// ============================================================================= + +/** + * Per-label frame-rate statistics, accumulated in memory. + * + * Exists because the wall reported lag that no measurement on a dev machine + * reproduces, and nothing told us the frame rate the wall was actually achieving. + * The GPU report established the hardware is healthy and the renderer is on D3D11; + * this answers the next question, which is what it manages at 6000x1200. + * + * **Bounded by the number of savers, not by uptime.** One row per label ever seen + * -- 30 savers plus two boards is the ceiling -- each holding six numbers. The file + * is overwritten, never appended, same as the GPU report. A wall running for months + * accumulates a few KB, once. + */ +const FPS_SAMPLE_MS = 15_000 +const FPS_REPORT_MS = 60_000 + +// Ignore a sample interval shorter than this: a saver that started or stopped +// mid-interval drew for only part of it, and dividing by the full interval would +// invent a low frame rate that never happened. +const FPS_MIN_SAMPLE_SECONDS = 3 + +/** @type {Map} */ +const fpsStats = new Map() + +/** + * Fold one round of frame counters into the running statistics. + * + * Exported for tests: this is the arithmetic worth pinning, and it needs no GL. + */ +function accumulateFrameStats (samples, stats = fpsStats) { + for (const s of samples) { + if (s.seconds < FPS_MIN_SAMPLE_SECONDS) continue + const fps = s.frames / s.seconds + const prev = stats.get(s.label) + if (!prev) { + stats.set(s.label, { + samples: 1, + frames: s.frames, + seconds: s.seconds, + min: fps, + max: fps, + last: fps, + size: `${s.width}x${s.height}`, + }) + continue + } + prev.samples++ + prev.frames += s.frames + prev.seconds += s.seconds + prev.min = Math.min(prev.min, fps) + prev.max = Math.max(prev.max, fps) + prev.last = fps + prev.size = `${s.width}x${s.height}` + } + return stats +} + +/** + * The report body: one line per label, worst mean first. + * + * Sorted by mean rather than by name because the question being asked is always + * "what is slowest", and on a 30-row table alphabetical order buries the answer. + * + * Exported for tests. + */ +function formatFpsReport (stats = fpsStats) { + const rows = [...stats.entries()] + .map(([label, v]) => ({ label, mean: v.frames / v.seconds, ...v })) + .sort((a, b) => a.mean - b.mean) + + const lines = [] + lines.push('Overwritten on every write; nothing here is appended.') + lines.push('') + if (rows.length === 0) { + lines.push('No frames counted yet.') + return lines.join('\n') + } + lines.push( + 'saver'.padEnd(26) + 'mean'.padStart(7) + 'min'.padStart(7) + + 'max'.padStart(7) + 'last'.padStart(7) + ' n'.padStart(4) + ' size') + for (const r of rows) { + lines.push( + r.label.slice(0, 25).padEnd(26) + + r.mean.toFixed(1).padStart(7) + + r.min.toFixed(1).padStart(7) + + r.max.toFixed(1).padStart(7) + + r.last.toFixed(1).padStart(7) + + String(r.samples).padStart(4) + ' ' + r.size) + } + return lines.join('\n') +} + +// Only the sample timer is held, as the re-entry guard. Both intervals run for the +// app's lifetime -- there is no state in which the wall wants to stop knowing its +// frame rate -- so a handle for the second one would be state nobody reads. +let fpsSampleTimer = null + +/** + * Start sampling. Two timers on purpose: counters are read often enough that a + * short-lived saver is not missed, and written to disk rarely, because the file is + * the part with a cost. + */ +function startFpsInstrumentation () { + if (fpsSampleTimer !== null) return + fpsSampleTimer = setInterval(() => { + accumulateFrameStats(sampleFrameCounters()) + }, FPS_SAMPLE_MS) + setInterval(() => { + if (fpsStats.size === 0) return + window.electronAPI?.writeFpsReport?.(formatFpsReport()) + .catch(err => console.error('[FPS] report failed:', err)) + }, FPS_REPORT_MS) +} + // ============================================================================= // GPU report // ============================================================================= @@ -3499,6 +3620,10 @@ async function init() { // are the ones this session will actually run with. reportGpu() + // Frame-rate sampling. Cheap enough to leave on: one property increment per + // frame, a counter read every 15s, and one overwritten file every 60s. + startFpsInstrumentation() + // Show cursor initially showCursor() @@ -3547,6 +3672,8 @@ export { hideNoSignal, formatDowntime, boardRowsFor, + accumulateFrameStats, + formatFpsReport, refreshNoSignalBoards, applyForcedNoSignal, updateDvdScreensaver, diff --git a/input_viewer_electron/src/renderer/screensavers/gl-base.js b/input_viewer_electron/src/renderer/screensavers/gl-base.js index 8b4eebe..aa2850b 100644 --- a/input_viewer_electron/src/renderer/screensavers/gl-base.js +++ b/input_viewer_electron/src/renderer/screensavers/gl-base.js @@ -183,6 +183,62 @@ const frameObservers = [] * @param {(rgba: Uint8Array, pixelCount: number) => void} fn * @returns {() => void} unsubscribe */ +/** + * Live frame counters, one per running runtime. + * + * The wall reported lag that none of the measurements on a dev machine reproduce, + * and there was no way to see the frame rate the wall was actually achieving. + * This is the cheapest possible instrument: one property increment per frame in a + * loop that already increments a counter, and nothing else on the hot path. No + * readback, no allocation, no timing call. + * + * Keyed by label so several concurrent runtimes stay distinguishable -- in dual + * view with no signal there are two split-flap boards AND possibly a screensaver, + * each with its own runtime, and an aggregate figure would hide which one is slow. + */ +const liveRuntimes = new Set() + +/** + * Label the next runtime that gets created. + * + * The 30 savers all call createGLRuntime(canvas) from inside their own create(), + * so the name lives one level up -- in the registry, which knows which entry it is + * instantiating. Rather than thread a label through 30 files, whoever is about to + * instantiate announces it here. + * + * Consumed on use, so a label cannot leak onto an unrelated runtime built later. + */ +let pendingRuntimeLabel = null +export function setNextRuntimeLabel(label) { + pendingRuntimeLabel = label || null +} + +/** + * Read and reset every live runtime's frame count. + * + * Returns one entry per runtime with the frames drawn and the wall-clock interval + * they were drawn over, leaving the caller to compute a rate -- so a caller that + * samples irregularly still gets an honest number. + * + * @returns {Array<{label: string, frames: number, seconds: number, width: number, height: number}>} + */ +export function sampleFrameCounters(now = performance.now()) { + const out = [] + for (const rec of liveRuntimes) { + const seconds = (now - rec.since) / 1000 + out.push({ + label: rec.label, + frames: rec.frames, + seconds, + width: rec.canvas.width, + height: rec.canvas.height, + }) + rec.frames = 0 + rec.since = now + } + return out +} + export function observeFrames(fn) { frameObservers.push(fn) return () => { @@ -204,7 +260,7 @@ export function observeFrames(fn) { * @param {HTMLCanvasElement} canvas * @returns {object} runtime */ -export function createGLRuntime(canvas) { +export function createGLRuntime(canvas, options = {}) { const gl = canvas.getContext('webgl2', { antialias: true, alpha: false, @@ -214,6 +270,16 @@ export function createGLRuntime(canvas) { throw new Error('WebGL2 is not available') } + // Frame counter for this runtime. `label` is what shows up in the fps report; + // anonymous runtimes are still counted so the total is never misleading. + const counter = { + label: options.label || pendingRuntimeLabel || 'unlabelled', + frames: 0, + since: 0, + canvas, + } + pendingRuntimeLabel = null + // Fullscreen quad (two triangles covering clip space). const quad = new Float32Array([-1, -1, 3, -1, -1, 3]) const vao = gl.createVertexArray() @@ -384,6 +450,11 @@ export function createGLRuntime(canvas) { lastTime = 0 dt = FALLBACK_DT resize() + // Registered on start rather than on create, so a runtime that is built and + // never started does not appear as a 0 fps entry. + counter.frames = 0 + counter.since = performance.now() + liveRuntimes.add(counter) const loop = () => { resize() const time = (performance.now() - startTime) / 1000 @@ -403,6 +474,8 @@ export function createGLRuntime(canvas) { // No observer means one branch per frame and nothing else. if (frameObservers.length) notifyFrameObservers() frame++ + // The whole instrument: one increment. See liveRuntimes. + counter.frames++ rafId = requestAnimationFrame(loop) } rafId = requestAnimationFrame(loop) @@ -414,6 +487,9 @@ export function createGLRuntime(canvas) { rafId = null } onFrame = null + // Dropped on stop, so a rotated-away saver stops reporting rather than + // lingering at whatever rate it last managed. + liveRuntimes.delete(counter) } function destroy() { diff --git a/input_viewer_electron/src/renderer/screensavers/registry.js b/input_viewer_electron/src/renderer/screensavers/registry.js index 9d93b49..a8e992c 100644 --- a/input_viewer_electron/src/renderer/screensavers/registry.js +++ b/input_viewer_electron/src/renderer/screensavers/registry.js @@ -18,6 +18,7 @@ * SCREENSAVERS array below. Pure fragment-shader ones can use * createShaderScreensaver from gl-base.js. */ +import { setNextRuntimeLabel } from './gl-base.js' import { seedFromClock } from './seed.js' import dvdLogo from './dvd-logo.js' import plasma from './plasma.js' @@ -220,6 +221,8 @@ export function startScreensaver(selector, seed) { // value can be logged -- reproducing a look means knowing what to pass back. const resolvedSeed = seed === undefined || seed === null ? seedFromClock() : seed try { + // Name the runtime the saver is about to build, for the fps report. + setNextRuntimeLabel(saver.name) active = saver.create(canvasEl, resolvedSeed) active.start() running = true @@ -236,6 +239,7 @@ export function startScreensaver(selector, seed) { if (saver !== SCREENSAVERS[0]) { activeIndex = 0 lastIndex = 0 + setNextRuntimeLabel(SCREENSAVERS[0].name) active = SCREENSAVERS[0].create(canvasEl, resolvedSeed) active.start() running = true diff --git a/input_viewer_electron/test/fps-report.test.js b/input_viewer_electron/test/fps-report.test.js new file mode 100644 index 0000000..4bf0cf6 --- /dev/null +++ b/input_viewer_electron/test/fps-report.test.js @@ -0,0 +1,147 @@ +// @vitest-environment jsdom +// SPDX-License-Identifier: Apache-2.0 +// SPDX-FileCopyrightText: 2025-2026 Schuberg Philis / Lab271 +/** + * Frame-rate instrumentation. + * + * The wall reports lag that no measurement on a dev machine reproduces, and the + * GPU report established the hardware is healthy. This is the next instrument, so + * the arithmetic behind it is worth pinning: a wrong number here would send the + * next round of diagnosis somewhere useless. + * + * The counter itself lives in gl-base's frame loop and needs GL to exercise, so + * these cover the folding and formatting -- which is where a bug would actually + * hide. + */ +import { describe, it, expect, vi } from 'vitest' +import { installRendererDom } from './helpers/renderer-dom.js' + +installRendererDom() + +const fakeTrack = () => ({ + stop: vi.fn(), + getSettings: () => ({ width: 1920, height: 1080, frameRate: 60 }), + getCapabilities: () => ({ + width: { max: 1920 }, height: { max: 1080 }, frameRate: { max: 60 } + }) +}) +Object.defineProperty(globalThis.navigator, 'mediaDevices', { + value: { + getUserMedia: vi.fn(async () => ({ + getTracks: () => [fakeTrack()], + getVideoTracks: () => [fakeTrack()], + getAudioTracks: () => [], + })), + enumerateDevices: vi.fn(async () => []), + }, + configurable: true, +}) + +const { accumulateFrameStats, formatFpsReport } = + await import('../src/renderer/renderer.js') + +const sample = (label, frames, seconds, width = 6000, height = 1200) => + ({ label, frames, seconds, width, height }) + +describe('accumulateFrameStats', () => { + it('turns frames over an interval into a rate', () => { + const stats = accumulateFrameStats([sample('Plasma', 600, 10)], new Map()) + const v = stats.get('Plasma') + expect(v.frames / v.seconds).toBeCloseTo(60, 5) + expect(v.samples).toBe(1) + expect(v.size).toBe('6000x1200') + }) + + it('accumulates across rounds rather than replacing', () => { + const stats = new Map() + accumulateFrameStats([sample('Plasma', 600, 10)], stats) + accumulateFrameStats([sample('Plasma', 300, 10)], stats) + const v = stats.get('Plasma') + expect(v.samples).toBe(2) + // The mean is over total frames and total seconds, not a mean of means -- + // otherwise two unequal intervals would weight wrongly. + expect(v.frames / v.seconds).toBeCloseTo(45, 5) + }) + + it('tracks the worst and best interval, not just the average', () => { + // A saver that averages 60 but drops to 8 for one interval is the interesting + // case, and a mean alone hides it. + const stats = new Map() + accumulateFrameStats([sample('Raymarch', 600, 10)], stats) + accumulateFrameStats([sample('Raymarch', 80, 10)], stats) + accumulateFrameStats([sample('Raymarch', 900, 10)], stats) + const v = stats.get('Raymarch') + expect(v.min).toBeCloseTo(8, 5) + expect(v.max).toBeCloseTo(90, 5) + expect(v.last).toBeCloseTo(90, 5) + }) + + it('discards an interval too short to mean anything', () => { + // A saver that started or stopped mid-interval drew for part of it; dividing by + // the whole interval would invent a low frame rate that never happened. + const stats = accumulateFrameStats([sample('Frost', 4, 0.5)], new Map()) + expect(stats.size).toBe(0) + }) + + it('keeps concurrent runtimes apart', () => { + // Dual view with no signal runs two boards plus possibly a saver, each its own + // runtime. An aggregate would hide one side being slower than the other. + const stats = accumulateFrameStats([ + sample('Split Flap (left)', 600, 10, 3000, 1200), + sample('Split Flap (right)', 120, 10, 3000, 1200), + ], new Map()) + expect(stats.get('Split Flap (left)').frames / 10).toBeCloseTo(60, 5) + expect(stats.get('Split Flap (right)').frames / 10).toBeCloseTo(12, 5) + expect(stats.get('Split Flap (left)').size).toBe('3000x1200') + }) + + it('records the size, so a figure cannot be read at the wrong resolution', () => { + // Every fps number in this repo has been misread at least once for want of the + // resolution it was taken at (#225). + const stats = accumulateFrameStats( + [sample('Mandelbrot', 300, 10, 3000, 600)], new Map()) + expect(stats.get('Mandelbrot').size).toBe('3000x600') + }) +}) + +describe('formatFpsReport', () => { + it('puts the slowest first, because that is the question being asked', () => { + const stats = accumulateFrameStats([ + sample('Fast', 1200, 10), + sample('Slow', 100, 10), + sample('Middle', 600, 10), + ], new Map()) + const body = formatFpsReport(stats) + const order = body.split('\n') + .filter(l => /^(Fast|Slow|Middle)/.test(l)) + .map(l => l.split(/\s+/)[0]) + expect(order).toEqual(['Slow', 'Middle', 'Fast']) + }) + + it('says so plainly when nothing has been counted', () => { + expect(formatFpsReport(new Map())).toContain('No frames counted yet') + }) + + it('states the overwrite discipline in the file itself', () => { + // The disk behaviour was an explicit requirement, so the file says what it does + // rather than leaving a reader to wonder whether it grows. + expect(formatFpsReport(new Map())).toContain('nothing here is appended') + }) + + it('carries the resolution on every row', () => { + const stats = accumulateFrameStats( + [sample('Plasma', 600, 10, 6000, 1200)], new Map()) + expect(formatFpsReport(stats)).toContain('6000x1200') + }) + + it('stays one line per saver, so the file cannot grow with uptime', () => { + // The bound that matters: rows are per label, not per sample. + const stats = new Map() + for (let i = 0; i < 50; i++) { + accumulateFrameStats([sample('Plasma', 600, 10)], stats) + } + const rows = formatFpsReport(stats).split('\n').filter(l => l.startsWith('Plasma')) + expect(rows).toHaveLength(1) + expect(stats.get('Plasma').samples).toBe(50) + }) +})