MOOR security

Dieser Eintrag ist auf Englisch verfasst.

Timestamps that arrive late when another app uses the GPU

Entry 056838 of 942 tests pass

Metal 4 wrote a command buffer's GPU timestamps late, all at the end, whenever another process kept the GPU busy; writing each one in a small encoder of its own fixed it.

What changed

D3D12 games measure GPU time with timestamp queries: the GPU writes its clock into a query heap at a point in the command list, and the game reads the difference. The layer used to write these with Metal 4's command-buffer-level writeTimestampIntoHeap:atIndex:. Now each timestamp gets a compute encoder (a block of GPU commands) of its own: a barrier that waits for all earlier work, a precise timestamp, and a 4-byte copy of zeros onto zeros.

Before and after, where the stamp sits.Before: command-buffer stamp: dispatch / draw encoders, cb.writeTimestampIntoHeap, next encoders, stamp after later work; After: a compute encoder of its own: dispatch / draw encoders, barrier after all stages precise timestamp 4-byte copy (zeros onto zeros), next encoders; dispatch / draw encoders → cb.writeTimestampIntoHeap; cb.writeTimestampIntoHeap → next encoders; cb.writeTimestampIntoHeap → stamp after later work (another process loads the GPU: written at the end of the command buffer); dispatch / draw encoders → barrier after all stages precise timestamp 4-byte copy (zeros onto zeros); barrier after all stages precise timestamp 4-byte copy (zeros onto zeros) → next encodersBefore: command-buffer stampAfter: a compute encoder of its owndispatch / draw encoderscb.writeTimestampIntoHeapnext encodersstamp after later workdispatch / draw encodersbarrier after all stagesprecise timestamp4-byte copy (zeros onto zeros)next encodersanother process loads the GPU:written at the end of the command buffer
Before and after, where the stamp sits. (Mermaid source)

The interesting part

A test was still failing once or twice in ten runs: four full-screen draws of a slow pixel shader measured 0.05 ms instead of milliseconds. A small native program (stamp, dispatch, stamp, dispatch, stamp, dispatch, stamp) showed why. With nothing else running, its stamps looked right. Beside two other processes spinning the GPU, the stamps in most rounds were written together at the very end of the command buffer, after the work that should follow them, though the API's header says the stamp is taken after earlier work completes.

What didn't work: a barrier encoder after each stamp, and a stamp alone in an encoder (written at once, before earlier work ends). What worked: barrier, stamp and some real work in the same encoder.

The regression test now starts a copy of itself as a second process that keeps the GPU busy. A second queue in the same process caught the bug only 1 run in 5, while the second process caught it in 4 of 6, and 0 of 8 fail with the fix.

The old stamps were also short with nothing else running: the draw round read 1.30 ms, where its pixel work should need about 1.8 ms; it now reads 2.27 ms.

Numbers

  • Rounds with an interval under 0.5 ms, beside two load processes: command-buffer stamps 78 of 120, with a barrier copy after each 70 of 120, stamp-only encoder 40 of 40, own encoder with barrier, stamp and copy 0 of 80.
  • The perf bench reads GPU time from these timestamps; it rose for bench-draws from 959 to 1,069 us and for bench-room from 293 to 318 us, steady over reruns. Probably the measurement now covering all the work, as in the test; not separated from the new encoder's own cost, which I couldn't measure above the noise.
  • Full run: 838 pass, 28 fail, 76 skip of 942; the previous run had 837.
Rounds with a timestamp interval under 0.5 ms, beside two processes loading the GPU (each dispatch about 2 ms) (data as CSV)

how the timestamp is written · % of rounds

  1. command buffer (78 / 120)65
  2. command buffer + barrier copy (70 / 120)58.3
  3. stamp-only encoder (40 / 40)100
  4. precise stamps in the work encoders (0 / 200)0
  5. own encoder: barrier + stamp + copy (0 / 80)0
Tests by suite at the end of this entry: 838 of 942 pass (data as CSV)
  • pass
  • fail
  • skip

suite · share of each row's total

  1. vkd3d-proton490 pass, 15 fail, 72 skip of 577
  2. vkd3d177 pass, 9 fail, 4 skip of 190
  3. apps77 pass, 0 fail, 0 skip of 77
  4. api (+1)74 pass, 0 fail, 0 skip of 74
  5. wine-dxgi16 pass, 4 fail, 0 skip of 20
  6. samples4 pass, 0 fail, 0 skip of 4
Zur Eintragsliste