// The speed check for the rules: how long a game step takes on the benchmark saves (see perf-saves.ts), what inside // a step takes the time, and how fast the game can really run at 16x and 64x with the main loop's rules. Run it // before and after a change meant to be faster, or one that touches every machine. Like the survey, each line has // what we want beside it and !! when it is outside. The wants are the target as numbers: 64x at 60 fps on a world // several times today's size. // Run: node scripts/perf.ts [late] [big] [--runs=5] [--fresh] // --fresh makes the saves again (the late one takes about 3 minutes). Timings are noisy on a busy machine: // the first line says how busy it was. import { Session } from 'node:inspector/promises'; import { availableParallelism, loadavg } from 'node:os'; import { STEP, dayOf, loadGame, seedRandom, step, type State } from '../src/sim.ts'; import { levelFor } from './perf-world.ts'; import { onWire } from '../src/flows.ts'; import { NAMES, perfSave, type SaveName } from './perf-saves.ts'; const args = process.argv.slice(2); const names = NAMES.filter(n => args.includes(n)); const runs = +(args.find(a => a.startsWith('--runs='))?.split('=')[1] ?? 5); const fresh = args.includes('--fresh'); /** What we want, by save: ms per step of a sixtieth of a second (for comparing with before) and of the game's own step (a game minute). */ const WANT: Record = { late: { small: 1, big: 1 }, big: { small: 2, big: 2 }, // the game's step is the one that matters: 64x takes eight or so a frame }; /** The rest of a frame in the browser beside the steps: drawing (want 6 ms, see perf-draw.mjs) and the panels. */ const REST_MS = 7; const median = (xs: number[]) => { const s = [...xs].sort((a, b) => a - b); return s[Math.floor(s.length / 2)]; }; const fmt = (n: number, d = 2) => n.toFixed(d); const rows: [string, string, string, boolean][] = []; const check = (name: string, shown: string, want: string, ok: boolean) => rows.push([name, shown, want, !ok]); const flush = () => { const w = Math.max(...rows.map(r => r[0].length)), v = Math.max(...rows.map(r => r[1].length)); for (const [name, shown, want, off] of rows) console.log(`${off ? '!!' : ' '} ${name.padEnd(w)} ${shown.padStart(v)} want ${want}`); const bad = rows.filter(r => r[3]).length; rows.length = 0; return bad; }; function open(name: SaveName, text: string): State { const S = loadGame(levelFor(name), text); if (!S) throw new Error(`${name} does not load`); seedRandom(7); return S; } /** Steps of dt from a fresh load: ms each, after a few to warm up. The game's own slow-downs are ignored. */ function timeSteps(name: SaveName, text: string, dt: number, n: number): number[] { const S = open(name, text), out: number[] = []; for (let i = 0; i < 10; i++) { step(S, dt); S.slow = false; } for (let i = 0; i < n; i++) { const t0 = performance.now(); step(S, dt); out.push(performance.now() - t0); S.slow = false; } return out; } /** The main loop (main.ts frame) at a speed, zoomed out, with REST_MS of drawing and panels a frame: how much game * time passes for each second of real time, and the frames a second. A frame that runs past a screen refresh waits * for the next one, as requestAnimationFrame does. Like main.ts: steps of STEP, as many as the time owed holds, * until 12 ms of them, when the rest is let go. */ function reach(name: SaveName, text: string, speed: number, frames = 240) { const S = open(name, text), vsync = 1000 / 60; let dtReal = 1 / 60, owed = 0, game = 0, real = 0, work = 0; for (let f = 0; f < 60 + frames; f++) { owed += Math.min(0.05, dtReal) * speed; const t0 = performance.now(); let ran = 0; while (owed >= STEP) { step(S, STEP); S.slow = false; owed -= STEP; ran++; if (S.over || performance.now() - t0 > 12) { owed = Math.min(owed, STEP * 0.99); break; } } const ms = performance.now() - t0; const frame = Math.ceil((ms + REST_MS) / vsync - 1e-9) * vsync; dtReal = frame / 1000; if (f >= 60) { game += ran * STEP; real += frame / 1000; work += ms; } } return { speed: game / real, fps: frames / real, work: work / frames }; } /** A CPU profile of n steps of dt: the time inside step() by what it calls, and the busiest functions anywhere. */ async function profile(name: SaveName, text: string, dt: number, n: number) { const S = open(name, text); for (let i = 0; i < 10; i++) { step(S, dt); S.slow = false; } const session = new Session(); session.connect(); await session.post('Profiler.enable'); await session.post('Profiler.setSamplingInterval', { interval: 100 }); await session.post('Profiler.start'); for (let i = 0; i < n; i++) { step(S, dt); S.slow = false; } const { profile: p } = await session.post('Profiler.stop'); session.disconnect(); type Node = (typeof p.nodes)[number]; const byId = new Map(p.nodes.map(x => [x.id, x])), self = new Map(); p.samples!.forEach((id, i) => self.set(id, (self.get(id) ?? 0) + (p.timeDeltas![i] ?? 0) / 1000)); const label = (x: Node) => `${x.callFrame.functionName || '(anonymous)'} ${x.callFrame.url.split('/').pop()}:${x.callFrame.lineNumber + 1}`; const memo = new Map(); const incl = (x: Node): number => { let t = memo.get(x.id); if (t === undefined) memo.set(x.id, t = (self.get(x.id) ?? 0) + (x.children ?? []).reduce((a, c) => a + incl(byId.get(c)!), 0)); return t; }; const inside = new Map(); let stepTotal = 0, stepSelf = 0; for (const x of p.nodes) if (x.callFrame.functionName === 'step' && x.callFrame.url.endsWith('/src/sim.ts')) { stepTotal += incl(x); stepSelf += self.get(x.id) ?? 0; for (const c of x.children ?? []) { const y = byId.get(c)!, k = label(y); inside.set(k, (inside.get(k) ?? 0) + incl(y)); } } const selfBy = new Map(); const under = (x: Node) => { const k = label(x); selfBy.set(k, (selfBy.get(k) ?? 0) + (self.get(x.id) ?? 0)); for (const c of x.children ?? []) under(byId.get(c)!); }; for (const x of p.nodes) if (x.callFrame.functionName === 'step' && x.callFrame.url.endsWith('/src/sim.ts')) under(x); const gc = p.nodes.filter(x => x.callFrame.functionName === '(garbage collector)').reduce((a, x) => a + (self.get(x.id) ?? 0), 0); const per = (ms: number) => ms / n; const top = (m: Map, k: number) => [...m].filter(([key]) => !/^\((program|idle|garbage collector|root)\)/.test(key)).sort((a, b) => b[1] - a[1]).slice(0, k); console.log(`\n Inside a step of ${dt === STEP ? 'a game minute' : '1/60 s'} (ms a step, from a CPU profile of ${n} steps; profiling adds a little):`); console.log(` ${fmt(per(stepTotal)).padStart(6)} step, all of it (${fmt(per(stepSelf))} in step itself)`); for (const [k, v] of top(inside, 14)) console.log(` ${fmt(per(v)).padStart(6)} ${k}`); console.log(` ${fmt(per(gc)).padStart(6)} (garbage collection, anywhere)`); console.log(' Busiest functions inside a step (self ms a step):'); for (const [k, v] of top(selfBy, 12)) console.log(` ${fmt(per(v)).padStart(6)} ${k}`); } const cores = availableParallelism(), load = loadavg()[0]; console.log(`Speed check, ${new Date().toISOString().slice(0, 16)}. Load average ${load.toFixed(1)} on ${cores} cores${load > cores / 4 ? ' !! busy: the timings will run slow' : ''}.`); let bad = 0; for (const name of names.length ? names : NAMES) { const text = perfSave(name, fresh); const S = open(name, text); console.log(`\n${name}: ${S.machines.length} machines, ${S.machines.filter(m => m.owned).length} yours, ${onWire(S)} pieces of data moving, ${S.rogues.length} rogues, ${S.raids.length} raids, ${S.fronts.length} fronts, day ${dayOf(S)}`); timeSteps(name, text, 1 / 60, 200); // warm up the compiler on this save for (const [dt, n, key] of [[1 / 60, 300, 'small'], [STEP, 100, 'big']] as const) { const means: number[] = [], all: number[] = []; for (let r = 0; r < runs; r++) { const xs = timeSteps(name, text, dt, n); means.push(xs.reduce((a, b) => a + b, 0) / xs.length); all.push(...xs); } const m = median(means), want = WANT[name][key]; const p90 = [...all].sort((a, b) => a - b)[Math.floor(all.length * 0.9)]; check(`step at ${dt === STEP ? 'a minute' : '1/60 s'}, ms`, `${fmt(m)}`, `${want} or less (runs ${means.map(x => fmt(x)).join(' ')}; one step in ten over ${fmt(p90)})`, m <= want); } for (const speed of [16, 64]) { const r = reach(name, text, speed); check(`${speed}x reaches`, `${fmt(r.speed, 1)}x at ${Math.round(r.fps)} fps`, `${speed}x at 60 fps (steps take ${fmt(r.work, 1)} ms a frame, with ${REST_MS} ms for the rest)`, r.speed >= speed * 0.95 && r.fps >= 55); } bad += flush(); await profile(name, text, STEP, 100); } console.log(`\n${bad ? `${bad} outside what we want.` : 'Everything is within what we want.'}`);