A benchmark harness, and the GPU timestamps it caught lying

What changed

Until now the layer only had correctness tests. This session added a way to measure speed, so later optimisation work has a number to beat (see the harness diagram):

• A benchmark program: a small D3D12 program with three scenes. room is an existing test scene. draws is 10000 small quads a frame. pso creates 48 pipeline state objects (compiled shader and render-state bundles). Per frame it measures recording time, submit time (the layer turns the D3D12 command list into Metal commands while the game waits), GPU time and frame time.
• MTL12_PERF=<file>: an environment variable. With it set, the layer writes one line of counters per presented frame. The line has the CPU time spent in the layer by kind and the GPU time Metal reports. That works for real programs I can't change: here ModelViewer and three bgfx examples.
• A runner: runs all seven scenes, prints one line per scene with the change against the last run on the same machine, and keeps a history file. A full run takes about 100 seconds. The recording shows the bench scenes compared against the baseline.

The interesting part

The first GPU times from the draws scene were absurd: 82 of 200 frames were about 7.7e17 µs. The end timestamp was older than the start. On Metal 4 a timestamp resolve (copying the counter into a buffer the program can read) does not wait for the write before it. An earlier spike had found this and worked around it with a small barrier-carrying copy placed before the resolve. After a render pass, that workaround no longer worked. The resolve still returned the value from the round before, in every round but the first.

The new test api/timestamp_after_work reproduces this. It runs 40 rounds of spinning shaders, as dispatches and as draws. In each round it checks that the end is after the start and after the previous round, and that resolving again later gives the same value. Before the fix it failed 120 checks. The fix (second diagram): the layer ends the Metal command buffer at a timestamp resolve, has the queue wait until that buffer has finished, and resolves in a new one. The test passes, and the benchmark had 0 bad frames out of 200. The cost is real: at every timestamp resolve the GPU drains, so two frames in flight no longer overlap. In the room scene that is probably the ~160 µs of the 466 µs frame that neither submit nor GPU time explains. That figure is inferred, not measured.

Numbers

First baseline (medians, M1 Max):

• bench room: 466 µs a frame, 299 µs GPU, 142 µs submit.
• bench draws: 20.3 ms a frame, 19.1 ms of it in submit, 2.1 ms GPU. That makes the layer CPU-bound at about 1.9 µs per draw.
• bench pso: the first pipeline takes 12.6 ms, the rest 1.6 ms each. With Metal's shader cache cold, the first took 230 ms.
• ModelViewer, bgfx shadowmaps and bgfx assao hold vsync (16.7 ms) with 43–64 µs of CPU in the layer.
• bgfx drawstress: 148.7 ms a frame, but only 3.2 ms of CPU in the layer's Metal side and 10.8 ms of GPU. Where the rest goes is not measured yet.
• Two runs in a row agreed within 3% on medians.
• Full suite: 836 pass, 28 fail, 76 skip of 940. That is one more passing (the new test) and 0 newly failing.