Skip to content

Fix GPU timestamp readback: NotReady is a partial result, not a failure - #136

Merged
nnewson merged 1 commit into
mainfrom
gpu-timestamp-diagnostics
Aug 5, 2026
Merged

Fix GPU timestamp readback: NotReady is a partial result, not a failure#136
nnewson merged 1 commit into
mainfrom
gpu-timestamp-diagnostics

Conversation

@nnewson

@nnewson nnewson commented Aug 5, 2026

Copy link
Copy Markdown
Owner

Per-pass GPU timings had never worked on any device. The overlay reported "GPU timestamps unavailable" under both MoltenVK and KosmicKrisp, which read as a platform limitation and was parked as one — it was ours.

The device times fine (timestampPeriod=1 ns, timestampValidBits=64 on this Mac) and the profiler was enabled; resolve() was throwing the results away. Without VK_QUERY_RESULT_WAIT_BIT, vkGetQueryPoolResults returns VK_NOT_READY whenever ANY query in the range is unavailable, and some always are: a pass that did not run this frame — no transmissive draw, no spot light, no VDPM front — leaves its two queries reset and never written. The code accepted only eSuccess, discarding the per-query availability words it had explicitly requested, which exist precisely so a partial read can be filtered. Every frame therefore reported nothing. resolve() now treats eNotReady as the normal polling result and filters on availability; only a genuine error bails, with a warn naming the result.

Timestamp deltas are now MODULAR in the queue's timestampValidBits. Vulkan guarantees only those low bits carry data and defines overflow as wrapping to zero inside that width, so the previous full-64-bit compare-and-subtract was wrong twice on any queue narrower than 64 bits: it fed undefined upper bits into the arithmetic, and it treated a legitimate wrap as a decreasing span. The width is stored rather than merely checked against zero, both ends are masked, and the difference is masked again; the 64 case branches instead of shifting, since 1ull << 64 is undefined. This also removes the notion of a "malformed span" — a decreasing raw pair is a wrap, not an anomaly — so that counter and its overlay line are deleted rather than redefined.

Both timestamp boundaries now stamp at bottom-of-pipe. A top-of-pipe begin fires while the previous pass is still draining, so a span absorbs part of its predecessor and two adjacent sub-millisecond passes each report time the other spent. The shadow families already stamped bottom-to-bottom for that reason, which left the sum adding two conventions together; with one convention every passMs is a consecutive delta along a single timeline. stampBottom is gone and its callers use begin/end. The trade is documented, not hidden: a bubble before a pass is charged to that pass.

FrameStats::gpuTotalMs becomes gpuMeasuredPassSumMs, with profilePassContributesToTotal renamed to match and the overlay label changed from "Total" to "Measured pass sum". It adds the instrumented passes only — a frame also contains command-buffer setup, present, the gaps between passes, and anything nobody bracketed — so calling it a total invited reading it as GPU frame latency. A dedicated outer span is the honest way to get that number if it is ever wanted.

Two further changes make the failure mode visible next time. GpuTimingState (Unsupported / WarmingUp / Valid) replaces the bare gpuValid flag, which is now derived from it, and the overlay renders the three distinctly — merging them is how a live bug spent months looking like a device limitation. And the capability decision is logged at startup, WARN with both numbers when genuinely unsupported, so the one legitimate reason for missing timings names itself.

The availability policy and tick arithmetic move into the free, Vulkan-free resolveTimestampWords, so the half that was wrong is testable without a GPU: mixed availability (the regression case), half-written pairs, an 8-bit wrap (250 -> 5 == 11 ticks), undefined upper bits proven not to affect the result, a zero-valid-bits guard, timestamp-period scaling, the VDPM breakdown rows reporting without summing, and a short buffer.

Per-pass GPU timings had never worked on any device. The overlay
reported "GPU timestamps unavailable" under both MoltenVK and
KosmicKrisp, which read as a platform limitation and was parked as one —
it was ours.

The device times fine (timestampPeriod=1 ns, timestampValidBits=64 on
this Mac) and the profiler was enabled; resolve() was throwing the
results away. Without VK_QUERY_RESULT_WAIT_BIT, vkGetQueryPoolResults
returns VK_NOT_READY whenever ANY query in the range is unavailable, and
some always are: a pass that did not run this frame — no transmissive
draw, no spot light, no VDPM front — leaves its two queries reset and
never written. The code accepted only eSuccess, discarding the per-query
availability words it had explicitly requested, which exist precisely so
a partial read can be filtered. Every frame therefore reported nothing.
resolve() now treats eNotReady as the normal polling result and filters
on availability; only a genuine error bails, with a warn naming the
result.

Timestamp deltas are now MODULAR in the queue's timestampValidBits.
Vulkan guarantees only those low bits carry data and defines overflow as
wrapping to zero inside that width, so the previous full-64-bit
compare-and-subtract was wrong twice on any queue narrower than 64 bits:
it fed undefined upper bits into the arithmetic, and it treated a
legitimate wrap as a decreasing span. The width is stored rather than
merely checked against zero, both ends are masked, and the difference is
masked again; the 64 case branches instead of shifting, since 1ull << 64
is undefined. This also removes the notion of a "malformed span" — a
decreasing raw pair is a wrap, not an anomaly — so that counter and its
overlay line are deleted rather than redefined.

Both timestamp boundaries now stamp at bottom-of-pipe. A top-of-pipe
begin fires while the previous pass is still draining, so a span absorbs
part of its predecessor and two adjacent sub-millisecond passes each
report time the other spent. The shadow families already stamped
bottom-to-bottom for that reason, which left the sum adding two
conventions together; with one convention every passMs is a consecutive
delta along a single timeline. stampBottom is gone and its callers use
begin/end. The trade is documented, not hidden: a bubble before a pass
is charged to that pass.

FrameStats::gpuTotalMs becomes gpuMeasuredPassSumMs, with
profilePassContributesToTotal renamed to match and the overlay label
changed from "Total" to "Measured pass sum". It adds the instrumented
passes only — a frame also contains command-buffer setup, present, the
gaps between passes, and anything nobody bracketed — so calling it a
total invited reading it as GPU frame latency. A dedicated outer span is
the honest way to get that number if it is ever wanted.

Two further changes make the failure mode visible next time.
GpuTimingState (Unsupported / WarmingUp / Valid) replaces the bare
gpuValid flag, which is now derived from it, and the overlay renders the
three distinctly — merging them is how a live bug spent months looking
like a device limitation. And the capability decision is logged at
startup, WARN with both numbers when genuinely unsupported, so the one
legitimate reason for missing timings names itself.

The availability policy and tick arithmetic move into the free,
Vulkan-free resolveTimestampWords, so the half that was wrong is
testable without a GPU: mixed availability (the regression case),
half-written pairs, an 8-bit wrap (250 -> 5 == 11 ticks), undefined
upper bits proven not to affect the result, a zero-valid-bits guard,
timestamp-period scaling, the VDPM breakdown rows reporting without
summing, and a short buffer.
@nnewson
nnewson merged commit 9766f2c into main Aug 5, 2026
4 checks passed
@nnewson
nnewson deleted the gpu-timestamp-diagnostics branch August 5, 2026 22:40
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant