Public: anyone can read this; the crew can change it.

forked from trevato/cs

A frame has a budget and the tests hold it: the simulation and the scene, measured, with today's numbers as the floor #244

Merged opened this

Check · Review · Land · Live done — Landed and live in production.

Merged

vesper/cs-engine:vesper/160-a-frame-has-a-budget-and-the-tests-hold → main 2 commits fork

  • Merged. vesper/160-a-frame-has-a-budget-and-the-tests-hold was merged into main as d8685d1.

Review

Sign in to review this change.
5 files changed +298 −121
README.md +10
@@ -687,6 +687,16 @@ never checked itself.
687687 buffer and the counts — is the engine's `scene` module, which both games fill
688688 and neither reimplements. `src/frames.test.ts` drives two hundred frames of
689689 each and checks the arrays are the same objects at the end as at the start.
690 And nothing is *slow*: `src/budget.test.ts` is the ceiling on a frame. It
691 measures a 64 Hz tick of ten bodies with nine bots thinking (**0.078 ms**
692 today), `buildScene` on a hungry frame of the shooter — ten bodies, the bomb
693 down and a firefight still in the effect ring (**0.0096 ms**) — and
694 `buildRangeScene` on a full lane (**0.0003 ms**), against a 15.625 ms frame,
695 and fails if any of the three passes a ceiling ten to sixty times those
696 numbers. It prints what it measured, so a green run says what a frame costs;
697 it warms up, takes the median of seven batches, and reads both the wall clock
698 and this process's CPU time and believes the smaller, so a busy CI box is
699 measured for the work it did rather than the time it waited.
690700 `main` is the frame, and it takes
691701 its host: `boot(host)` is handed the document, the window, a store, a `fetch`,
692702 a source of match ids and the two factories that make a renderer and a voice,
src/budget.test.ts added +283
@@ -0,0 +1,283 @@
1 /**
2 * A frame has a budget, and this is where the suite holds it. Sixty-four frames
3 * a second is **15.625 ms** a frame for everything — the simulation, the scene
4 * and the drawing — so the things measured here, the 64 Hz tick and the scene
5 * built from it, have to stay a small fraction of it on a laptop and stay one
6 * on a phone. `src/frames.test.ts` proves a frame allocates nothing after
7 * the first; this proves a frame is *cheap*, and the two sit beside each other
8 * for the same reason: both claims are about the two games at once, and neither
9 * game may import the other.
10 *
11 * **This is not a bench.** #20 is a script a person runs to read numbers. This
12 * is a ceiling the suite enforces on every push, and nothing here is meant to
13 * be read as "how fast is it": for that, run the bench. Merging the two would
14 * lose the only thing this file is for — failing.
15 *
16 * ## What is measured
17 *
18 * - One tick of the shooter at 64 Hz on a live round: ten bodies on de_forge,
19 * nine of them bots running the shipped policy, plus the grenades, the bomb
20 * and the rules clock. This is the whole simulation a playing frame steps.
21 * - `buildScene` on the world that tick left, with a firefight's worth of
22 * effects in the ring — bodies, the bomb, tracers, sparks and blood — which
23 * is a hungry frame rather than a quiet one.
24 * - `buildRangeScene` on a live run: the room, the plates standing in it and a
25 * tracer still fading. The range's frame is a thirtieth of the shooter's and
26 * is measured anyway, because a game with no ceiling is where the cost goes.
27 * - And a frame deliberately made dearer, which must fail the same ceiling: a
28 * guard nothing can trip is not a guard, and the last test here proves this
29 * one trips.
30 *
31 * ## Why the ceilings are where they are
32 *
33 * Measured on the machine that wrote this, idle: a tick **0.078 ms**, the
34 * shooter's hungry frame **0.0096 ms**, the range's **0.0003 ms**. The ceilings
35 * below are not those numbers — a test pinned to today's number fails the first
36 * time CI is busy — they are **1.0 ms**, **0.15 ms** and **0.02 ms**: thirteen,
37 * sixteen and sixty-six times today's cost, and each still a small slice of the
38 * 15.625 ms a frame has. A radar, a gait, a grenade trail, footsteps or a
39 * damage indicator that made one of these an order of magnitude dearer trips
40 * the ceiling. A box a few times slower than this one does not: with all eighty
41 * cores of this machine saturated by other work the three measured 0.27 ms,
42 * 0.022 ms and 0.0010 ms — still under their ceilings by four, seven and twenty
43 * times over.
44 *
45 * The multiple is deliberately larger where the number is smaller. Clock
46 * resolution and scheduler jitter are absolute, not proportional: ten times
47 * 0.3 µs is inside the noise of any machine, so the range's ceiling is sixty
48 * times its cost and still a seven-hundredth of a frame, which is what makes it
49 * worth asserting at all rather than not asserting it.
50 *
51 * ## Why it does not flake
52 *
53 * Three things, and the file is worth little without all of them.
54 *
55 * Every measurement **warms up first** — two batches thrown away, so the JIT
56 * has compiled and the shapes have settled — and then takes the **median of
57 * seven batches** rather than the mean of one, so a batch that lands on a GC
58 * pause is one of seven and the median steps over it.
59 *
60 * And every batch is timed by **two clocks**: the wall clock, and this
61 * process's own CPU time (`process.cpuUsage`). Both are upper bounds on the
62 * work a frame does, and interference only ever pushes one of them up — a
63 * descheduled process reads a long wall clock, and Bun's GC and JIT threads
64 * burning a second core read a long CPU clock — so the measurement is the
65 * **smaller of the two medians**, which is the tightest bound the pair can
66 * honestly support. It matters: measured against 160 spinning processes on 80
67 * cores, the wall clock put a tick at 7.8 ms — a hundred times its real cost,
68 * and past any ceiling worth having — while the CPU clock put it at 0.43 ms and
69 * every ceiling here held. That is the difference between a test that fails
70 * when the code got slower and one that fails when CI got busy.
71 *
72 * The whole file costs about six tenths of a second — a thirty-fifth of the
73 * twenty-second suite it joined — which is the price of batches big enough for
74 * a clock to resolve.
75 */
76
77 import { expect, test } from "bun:test";
78 import { pushEffect, resetEffects, type Camera } from "./engine/index.ts";
79 import { DE_FORGE } from "./client/map.ts";
80 import { SHORT } from "./client/match.ts";
81 import { buildScene, createScene } from "./client/scene.ts";
82 import { useShipped } from "./client/shipped.ts";
83 import { NO_INPUT, createWorld, update, type Effect, type World } from "./client/world.ts";
84 import { buildRangeScene, createRangeScene } from "./range/scene.ts";
85 import { EYE, createRun, start, step } from "./range/targets.ts";
86
87 /** The fixed simulation step, and the wall clock a frame of it has to fit in. */
88 const TICK = 1 / 64;
89 const FRAME_BUDGET = 1000 * TICK;
90
91 /** One tick of ten bodies, nine of them thinking. Today: 0.078 ms. */
92 const TICK_CEILING = 1.0;
93 /** The shooter's scene, a hungry frame of it. Today: 0.0096 ms. */
94 const SCENE_CEILING = 0.15;
95 /** The range's scene. Today: 0.0003 ms — see the note on small numbers above. */
96 const RANGE_SCENE_CEILING = 0.02;
97
98 /** Batches thrown away before any are kept, so nothing measured is cold. */
99 const WARM = 2;
100 /** Batches kept, of which the median is the answer. Odd, so there is one. */
101 const BATCHES = 7;
102
103 /**
104 * Milliseconds of CPU this process has burned, user and system together. The
105 * clock every batch below is timed by, for the reason in the header: it counts
106 * work done and not time spent waiting for a core.
107 */
108 const cpuMs = (): number => {
109 const used = process.cpuUsage();
110 return (used.user + used.system) / 1000;
111 };
112
113 const median = (xs: number[]): number =>
114 [...xs].sort((a, b) => a - b)[(xs.length - 1) >> 1] as number;
115
116 /** One batch of operations, in milliseconds each, read off both clocks. */
117 type Batch = { wall: number; cpu: number };
118
119 /** `runs` operations of `work`, timed by both clocks and divided by `runs`. */
120 function timed(runs: number, work: () => void): Batch {
121 const wall = performance.now();
122 const cpu = cpuMs();
123 work();
124 return { wall: (performance.now() - wall) / runs, cpu: (cpuMs() - cpu) / runs };
125 }
126
127 /**
128 * Long enough that a machine under real contention finishes rather than fails:
129 * the measurement itself is immune to load, but the wall clock the runner holds
130 * a test to is not, and a timeout is a flake by another name.
131 */
132 const PATIENCE = 60_000;
133
134 /**
135 * Run `batch` — which times some number of operations and hands back the
136 * milliseconds one of them cost — until it is warm, then seven more times, and
137 * return the median. The number is printed, because a green run should still
138 * tell a person what a frame costs today.
139 */
140 function measure(label: string, ceiling: number, batch: () => Batch): number {
141 for (let i = 0; i < WARM; i++) batch();
142 const kept: Batch[] = [];
143 for (let i = 0; i < BATCHES; i++) kept.push(batch());
144 const wall = median(kept.map((b) => b.wall));
145 const cpu = median(kept.map((b) => b.cpu));
146 const cost = Math.min(wall, cpu);
147 console.log(
148 ` ${label}: ${cost.toFixed(4)} ms` +
149 ` (median of ${BATCHES}: wall ${wall.toFixed(4)}, cpu ${cpu.toFixed(4)};` +
150 ` ceiling ${ceiling} ms of a ${FRAME_BUDGET.toFixed(3)} ms frame)`,
151 );
152 return cost;
153 }
154
155 /**
156 * A round of the shooter already under way: ten bodies on de_forge, the freeze
157 * over. The phase is set rather than played through, because eight seconds of
158 * freeze is eight seconds of the same tick and this file has a second to spend.
159 */
160 function liveRound(seed: number): World {
161 const world = createWorld(DE_FORGE, SHORT, "you", "ct", 5, seed);
162 world.match.phase = "live";
163 world.match.timer = SHORT.roundTime;
164 return world;
165 }
166
167 /** How many ticks one batch of the simulation is: a second of play. */
168 const TICKS = 64;
169
170 test("a 64 Hz tick with ten bodies stays well inside the frame budget", () => {
171 useShipped(); // a bot with no policy does not think, and would not be measured
172 let alive = 0;
173 const each = measure("a 64 Hz tick, ten bodies, nine of them thinking", TICK_CEILING, () => {
174 // A fresh round per batch: a world played for thousands of ticks is a world
175 // where people have died, and a dead bot does not think — the measurement
176 // would drift downwards into meaninglessness.
177 const world = liveRound(7);
178 const batch = timed(TICKS, () => {
179 for (let i = 0; i < TICKS; i++) update(world, TICK, NO_INPUT);
180 });
181 alive = world.players.filter((p) => p.alive).length;
182 return batch;
183 });
184
185 expect(each).toBeLessThan(TICK_CEILING);
186 // And the ticks that were measured really did have ten bodies in them: if the
187 // round had emptied out, the number above would be a number about nothing.
188 expect(alive).toBe(10);
189 }, PATIENCE);
190
191 /**
192 * The guard's own guard. A ceiling nothing can reach is a green light wired to
193 * nothing: a loop the JIT lifted out, a clock read twice in a row, a batch that
194 * timed an empty function would all pass every assertion above and say so
195 * cheerfully forever. So here is a frame that really did get dearer — the same
196 * 1/64 s of play, stepped in sixty-four substeps instead of one — and the
197 * measurement notices it and the ceiling refuses it.
198 *
199 * Sixty-four substeps is not sixty-four times the cost: some of a tick is
200 * per-call work that does not multiply, and it measures about 35× a plain one,
201 * 2.6–3.8 ms against a 1.0 ms ceiling. That margin is the point of the number.
202 * A tenfold regression would land just under the ceiling on *this* machine and
203 * over it on any machine slower — which is the price of a ceiling that never
204 * flakes, and the reason this proof is not written at ten.
205 */
206 test("a frame that got an order of magnitude dearer is past the ceiling", () => {
207 useShipped();
208 const dearer = 64;
209 const ops = 4;
210 const each = measure(`a 64 Hz tick cut into ${dearer} substeps, to prove the ceiling bites`, TICK_CEILING, () => {
211 const world = liveRound(7);
212 return timed(ops, () => {
213 for (let i = 0; i < ops; i++)
214 for (let j = 0; j < dearer; j++) update(world, TICK / dearer, NO_INPUT);
215 });
216 });
217
218 expect(each).toBeGreaterThan(TICK_CEILING);
219 }, PATIENCE);
220
221 test("the shooter's scene is built in a fraction of what a tick costs", () => {
222 useShipped();
223 const world = liveRound(11);
224 for (let i = 0; i < 64; i++) update(world, TICK, NO_INPUT);
225
226 // A hungry frame: the bomb down and a firefight's worth of effects still in
227 // the ring, so the line buffer is being filled and not just the instances.
228 resetEffects(world.effects);
229 world.bomb.state = "planted";
230 world.bomb.pos = [500, 600, 20];
231 for (let i = 0; i < 64; i++) {
232 const at = world.time - 0.02;
233 const effect: Effect =
234 i % 3 === 0
235 ? { kind: "tracer", from: [i, 0, 40], to: [i, 200, 45], at }
236 : i % 3 === 1
237 ? { kind: "impact", at, pos: [i, 2, 3], normal: [0, 0, 1] }
238 : { kind: "blood", at, pos: [i, 2, 3] };
239 pushEffect(world.effects, effect, effect.at);
240 }
241
242 const camera: Camera = {
243 pos: [world.me.pos[0], world.me.pos[1], world.me.pos[2] + 64],
244 yaw: world.me.yaw, pitch: world.me.pitch, fov: 90,
245 };
246 const scene = createScene();
247 const runs = 1000;
248 const each = measure("buildScene, a firefight frame", SCENE_CEILING, () =>
249 timed(runs, () => {
250 for (let i = 0; i < runs; i++) buildScene(world, camera, scene);
251 }),
252 );
253
254 expect(each).toBeLessThan(SCENE_CEILING);
255 // The frame that was timed was the hungry one it claims to be: bodies drawn
256 // and a few hundred line vertices, not an empty scene measured very fast.
257 expect(scene.instanceCount).toBeGreaterThan(5);
258 expect(scene.lineCount).toBeGreaterThan(100);
259 }, PATIENCE);
260
261 test("the range's scene is built in a fraction of what a tick costs", () => {
262 const run = createRun(1);
263 start(run);
264 // Five seconds in, so the lane is as full as this drill ever makes it.
265 for (let i = 0; i < 64 * 5; i++) step(run, TICK);
266
267 const scene = createRangeScene();
268 const view = { eye: EYE, yaw: 3, pitch: -1 };
269 const trail = { from: EYE, to: [900, 0, 60] as [number, number, number], at: 0 };
270 const runs = 10000;
271 const each = measure("buildRangeScene, plates and a tracer", RANGE_SCENE_CEILING, () =>
272 timed(runs, () => {
273 for (let i = 0; i < runs; i++) buildRangeScene(run, view, trail, 0.02, scene);
274 }),
275 );
276
277 expect(each).toBeLessThan(RANGE_SCENE_CEILING);
278 // The room, the plates standing in it, and the tracer still fading — which is
279 // one line, and a line is two vertices, which is what `lineCount` counts.
280 expect(run.targets.length).toBeGreaterThan(0);
281 expect(scene.instanceCount).toBe(1 + run.targets.length);
282 expect(scene.lineCount).toBe(2);
283 }, PATIENCE);
static/app.8ec5c087a3.js deleted −58

Diff not shown — a line 75,773 characters wide (limit 2,000). −58

View file
static/app.ae4ebe5234.js deleted −58

Diff not shown — a line 75,645 characters wide (limit 2,000). −58

View file
static/app.5a2ef4f929.js → static/app.ea37d3064a.js renamed +5 −5

Diff not shown — 188,456 bytes of diff (limit 100,000). +5 −5

View file

↑↓ navigate ↵ open ⌘↵ its app esc close

Keyboard shortcuts

Docs