Repository navigation
Conversation
…y idle The recorder now passes whether every batch it submitted has completed (its timeline semaphore against its submission count). When it has and the oldest deferred object waited 30 ms, the drain runs at once: vkQueueWaitIdle finds the queue idle, so a title whose GPU finishes each frame before the next one starts drains about once a frame instead of stalling every 100 ms. The 512-object and 100 ms bounds stay for a queue that never idles.
github-actions
Bot
added
perf
|
This pull request is labeled |
|
Summary lines and traces, as the perf label asks. Planet of Lana (PPSA19450), village after New Game,
This PR: The drains show directly as
|
| thread | busy | wait | untraced | in slices < 20 us | largest |
|---|---|---|---|---|---|
| queue worker 0x0 | 14.7 (42 %) | 10.1 (29 %) | 10.2 | 47.2 | Driver.Packet 14.4, Driver.EndSubmission 0.3 |
| draw committer | 11.5 (33 %) | 0.0 (0 %) | 23.5 | 17.9 | Graphics.Draw 7.9, Recorder.Submit 3.5 |
| presenter | 0.9 (3 %) | 9.2 (26 %) | 24.9 | 0.1 | VideoOut.Flip 10.1, Driver.Present 0.0 |
Largest slices (ms per frame, inclusive, all threads): Driver.Packet 14.4, Driver.Packet.draw 11.2, Driver.Draw 11.0, Driver.WorkerWait 10.1, Driver.WorkerWait.idle_and_completion_poll 10.1, VideoOut.Flip 10.1, Driver.Present 9.3, VideoOut.Flip.present 9.3, Driver.Present.render_fence_wait 9.2, Vulkan.Retire 9.2
Longest waits
- Driver.WorkerWait (queue worker 0x0) 29.9 ms at 2480 ms, present 4038
- Driver.Present.render_fence_wait (presenter) 29.3 ms at 2480 ms, present 4039
- Driver.WorkerWait (queue worker 0x0) 22.9 ms at 478 ms, present 3981
- Driver.Present.render_fence_wait (presenter) 21.8 ms at 478 ms, present 3982
- Driver.WorkerWait (queue worker 0x0) 14.0 ms at 3658 ms, present 4072
- Driver.WorkerWait (queue worker 0x0) 14.0 ms at 6800 ms, present 4162
- Driver.WorkerWait (queue worker 0x0) 13.0 ms at 8170 ms, present 4201
- Driver.WorkerWait (queue worker 0x0) 12.9 ms at 1465 ms, present 4009
- Driver.WorkerWait (queue worker 0x0) 12.8 ms at 2306 ms, present 4033
- Driver.WorkerWait (queue worker 0x0) 12.8 ms at 6484 ms, present 4153
tools/trace_digest.py, this PR
seconds 95:10 from present 4015: 294 presents, frame p50 33.8 / p90 35.8 / p99 39.7 / max 41.9 ms, GPU busy 24.3 ms per present
Apple M4 Pro, MoltenVK 1.4.2, Darwin 27.0.0, 3840x2160, commit 33dbe48a8e0d (dirty), dropped: no
{"commit":"33dbe48a8e0d","dirty":true,"env":{"APS5_ASYNC_PIPELINES":"1","APS5_NO_PAD_INPUT":"1","APS5_PAD_INPUT_FILE":"<path>","APS5_TRACE_DIR":"<path>","APS5_TRACE_EVENTS":"1048576","APS5_TRACE_SECONDS":"95:10","APS5_VIDEOOUT_TELEMETRY_DIR":"<path>"},"gpu":"Apple M4 Pro","driver":"MoltenVK 1.4.2","os":"Darwin 27.0.0","cpu":"VirtualApple @ 2.50GHz","cpu_threads":12,"memory_mib":24576,"title_id":"PPSA19450","title":"Planet of Lana","content_version":"01.010.000","resolution":"3840x2160","window":{"spec":"seconds 95:10","first_present":4015,"ms":10013.23},"presents":294,"frame_ms":{"p50":33.789,"p90":35.79,"p99":39.741,"max":41.878},"gpu_busy_ms_per_present":24.335,"worker_busy_pct":{"queue worker 0x0":62.869},"top_phases_ms_per_frame":{"Driver.Packet":20.976,"Driver.Packet.draw":16.603,"Driver.Draw":16.448,"Graphics.Draw":15.388,"VideoOut.Flip":12.22,"Graphics.Draw.draw_and_resource_release":11.782,"Driver.Present":11.413,"VideoOut.Flip.present":11.383},"trace_dropped":false,"trace":"aps5-trace-33dbe48a8e0d-45115.json.gz"}Slowest frames (largest slices inside each, inclusive)
- present 4121: 41.9 ms at 3610 ms: Driver.Packet (queue worker 0x0) 19.1, Driver.Packet.draw (queue worker 0x0) 15.9, Driver.Draw (queue worker 0x0) 15.6, Graphics.Draw (draw committer) 14.1
- present 4304: 41.4 ms at 9838 ms: Driver.WorkerWait (queue worker 0x0) 19.1, Driver.WorkerWait.idle_and_completion_poll (queue worker 0x0) 19.1, VideoOut.Flip (presenter) 19.0, VideoOut.Flip.present (presenter) 18.3
- present 4225: 39.7 ms at 7141 ms: Driver.Packet (queue worker 0x0) 17.5, Driver.Packet.draw (queue worker 0x0) 13.2, Driver.Draw (queue worker 0x0) 13.0, Driver.WorkerWait (queue worker 0x0) 12.9
Threads (ms per frame)
| thread | busy | wait | untraced | in slices < 20 us | largest |
|---|---|---|---|---|---|
| queue worker 0x0 | 11.8 (35 %) | 12.2 (36 %) | 10.1 | 46.9 | Driver.Packet 11.5, Driver.EndSubmission 0.3 |
| draw committer | 8.5 (25 %) | 0.0 (0 %) | 25.5 | 17.9 | Graphics.Draw 7.7, Recorder.Submit 0.8 |
| presenter | 0.9 (3 %) | 11.3 (33 %) | 21.8 | 0.1 | VideoOut.Flip 12.2, Driver.Present 0.0 |
Largest slices (ms per frame, inclusive, all threads): VideoOut.Flip 12.2, Driver.WorkerWait 12.2, Driver.WorkerWait.idle_and_completion_poll 12.1, Driver.Packet 11.5, Driver.Present 11.4, VideoOut.Flip.present 11.4, Driver.Present.render_fence_wait 11.3, Vulkan.Retire 11.3, Vulkan.Retire.wait 11.3, Driver.Packet.draw 9.2
Longest waits
- Driver.WorkerWait (queue worker 0x0) 19.0 ms at 9838 ms, present 4303
- Driver.Present.render_fence_wait (presenter) 18.2 ms at 9839 ms, present 4304
- Driver.WorkerWait (queue worker 0x0) 15.2 ms at 670 ms, present 4034
- Driver.Present.render_fence_wait (presenter) 14.9 ms at 671 ms, present 4035
- Driver.WorkerWait (queue worker 0x0) 14.7 ms at 9226 ms, present 4285
- Driver.WorkerWait (queue worker 0x0) 14.0 ms at 3724 ms, present 4123
- Driver.WorkerWait (queue worker 0x0) 14.0 ms at 1901 ms, present 4070
- Driver.Present.render_fence_wait (presenter) 14.0 ms at 9227 ms, present 4286
- Driver.WorkerWait (queue worker 0x0) 13.9 ms at 6284 ms, present 4199
- Driver.Present.render_fence_wait (presenter) 13.3 ms at 3725 ms, present 4124
github-actions
Bot
removed
the
perf numbers missing
MarcZX10
left a comment
MarcZX10
left a comment
There was a problem hiding this comment.
Reviewed head 8738e58545556d451c19edf05d62167d93dcb081. The 30 ms path is gated on the recorder timeline having completed all submitted batches; the existing 512-object and 100 ms drains remain the fallback when that condition is false. The added mock cases cover young idle, older busy, and older idle queues.
I downloaded both attached event traces and reran tools/trace_digest.py against the corresponding pasted summary lines. It matched the reported windows and no-drop flags: 287 presents on the baseline and 294 on the change, with p90/p99 of 44.751/48.517 ms and 35.790/39.741 ms respectively. The baseline’s macOS compatibility stack is disclosed in the PR description; both captures use the same title, scene, machine and MoltenVK setup. The report gives useful frame-tail improvement, while the no-deferral comparison indicates some remaining overhead.
Conventions, labels, eligibility, intake and report checks pass. Product, relinker and write-watch jobs are path-skipped. The author reports focused Vulkan validation tests and native title runs on the stated machine. No issue found in the reviewed code or evidence.
|
Some comparisons could not be completed because a pull request conflicts with the base branch. Review these shared files manually before concluding that there is no overlap.
|
|
Thanks, the attached traces do show the Recorder.Submit reduction. To bind them to this PR: the run was made from a dirty tree (33dbe48a8e0d). Could you attach the source SHAs plus the production diff or file hashes that tie that run to this head, against the same c930034 macOS baseline and prerequisite stack? That shows the comparison differs only by this change. Please also include the focused test logs from that validation run. |
|
@oneandonlydean The run marked
Over these files, To take the dirty tree out of the picture, I repeated the capture today from clean commits. The base is The effect is now much smaller than in the description.
The summary lines and traces of these two captures are attached. I'll put these numbers at the top of Tested. The change still removes the forced queue drains, but on current aps5-summary-main-1027.txt |
What
On MoltenVK, #10062 destroys released buffers and device memory only while the graphics queue is idle (KhronosGroup/MoltenVK#2876). Before every recorder or command batch submission it drains the queue once 512 objects wait or the oldest has waited 100 ms. A title that releases buffers all the time reaches the 100 ms bound about ten times a second, and each
vkQueueWaitIdlestops the queue worker until the GPU has finished everything queued. That cost was not measured in #10062.With this change the recorder also passes whether every batch it has submitted has completed: its timeline semaphore against its submission count, read with
vkGetSemaphoreCounterValueKHR, without waiting. When they have, and the oldest deferred object has waited 30 ms, the drain runs at once. It still callsvkQueueWaitIdle, so the guarantee #2876 needs is unchanged, but the queue is already idle. A title whose GPU finishes a frame before the next one starts now drains about once a frame, between frames.CommandBatchsubmissions.DeferredObjectslookup per submission.waitIdle(an empty command buffer committed and waited for), and Planet of Lana lost about 2% against no deferral. With 30 ms it is about 1%.agc_deferred_destructioncovers three new cases:Tested
Current
main(2026-10-27), clean commits. Base9f6232f229ebismain3fea2a937bplus the 8 macOS PRs listed on #1 (fork branchbench/main-boot-1027); the change87853364575cis the base plus this commit (bench/dd-pr).mainnow has #11142, which removed most buffer creations, so the drains this PR avoids are rare there: the base committer spends 0.1 ms per frame inRecorder.Submit, not 3.5 ms.trace_digest, 95:10: base 302 presents, p50 32.9 / p90 34.9 / p99 44.5 / max 53.0 ms; this PR 306 presents, p50 32.6 / p90 34.6 / p99 37.7 / max 42.5 ms.agc_deferred_destructionandagc_buffer_poolpass 3 of 3.The runs below are from the earlier base (
main035ac96eddwith the macOS PRs), before #11142.macOS 27.0.1, Apple M4 Pro, MoltenVK 1.4.2 (Vulkan SDK 1.4.363.0), x86-64 Release under Rosetta 2.
maindoes not build and run on macOS, so this ran onmain035ac96edd+ #10366 #10552 #7631 #7804 #11249 #10669 #10540 #11447 #11047 #11048 #10876 #9263 and a local patch that loadslibvulkan.1.dylib, without and with this commit. Every run had mimalloc injected withDYLD_INSERT_LIBRARIES(as #11130 does on request), and the same shader cache.Planet of Lana (PPSA19450), New Game into the village, 120 s runs, alternated, fps from 85 s:
main(#10062 as merged)APS5_NO_DEFERRED_DESTRUCTION=1tools/trace_digest.pyon theAPS5_TRACE_SUMMARY_EVERY=10summaries, gameplay intervals (attached):main: 70-110 s, 277-284 presents per 10 s, p50 33.7-34.7, p90 44.8-45.9, p99 49.2-54.5 ms, largest phase Driver.Packet 23.9-24.4 ms per frameSummary lines of the attached traces (
APS5_TRACE_SECONDS=95:10 APS5_TRACE_EVENTS=1048576, window 95-105 s; the change build is marked dirty because the 30 ms constant was edited before the commit, its code equals this head apart from the debt text and the test):main:{"commit":"c930034b60a8","dirty":false,"env":{"APS5_ASYNC_PIPELINES":"1","APS5_NO_PAD_INPUT":"1","APS5_PAD_INPUT_FILE":"<path>","APS5_TRACE_DIR":"<path>","APS5_TRACE_EVENTS":"1048576","APS5_TRACE_SECONDS":"95:10","APS5_VIDEOOUT_TELEMETRY_DIR":"<path>"},"gpu":"Apple M4 Pro","driver":"MoltenVK 1.4.2","os":"Darwin 27.0.0","cpu":"VirtualApple @ 2.50GHz","cpu_threads":12,"memory_mib":24576,"title_id":"PPSA19450","title":"Planet of Lana","content_version":"01.010.000","resolution":"3840x2160","window":{"spec":"seconds 95:10","first_present":3968,"ms":10041.083},"presents":287,"frame_ms":{"p50":33.333,"p90":44.751,"p99":48.517,"max":51.355},"gpu_busy_ms_per_present":21.749,"worker_busy_pct":{"queue worker 0x0":69.718},"top_phases_ms_per_frame":{"Driver.Packet":23.883,"Driver.Packet.draw":18.592,"Driver.Draw":18.431,"Graphics.Draw":15.645,"Graphics.Draw.draw_and_resource_release":12.029,"VideoOut.Flip":10.065,"Driver.Present":9.268,"VideoOut.Flip.present":9.258},"trace_dropped":false,"trace":"aps5-trace-c930034b60a8-41812.json.gz"}This PR:
{"commit":"33dbe48a8e0d","dirty":true,"env":{"APS5_ASYNC_PIPELINES":"1","APS5_NO_PAD_INPUT":"1","APS5_PAD_INPUT_FILE":"<path>","APS5_TRACE_DIR":"<path>","APS5_TRACE_EVENTS":"1048576","APS5_TRACE_SECONDS":"95:10","APS5_VIDEOOUT_TELEMETRY_DIR":"<path>"},"gpu":"Apple M4 Pro","driver":"MoltenVK 1.4.2","os":"Darwin 27.0.0","cpu":"VirtualApple @ 2.50GHz","cpu_threads":12,"memory_mib":24576,"title_id":"PPSA19450","title":"Planet of Lana","content_version":"01.010.000","resolution":"3840x2160","window":{"spec":"seconds 95:10","first_present":4015,"ms":10013.230},"presents":294,"frame_ms":{"p50":33.789,"p90":35.790,"p99":39.741,"max":41.878},"gpu_busy_ms_per_present":24.335,"worker_busy_pct":{"queue worker 0x0":62.869},"top_phases_ms_per_frame":{"Driver.Packet":20.976,"Driver.Packet.draw":16.603,"Driver.Draw":16.448,"Graphics.Draw":15.388,"VideoOut.Flip":12.220,"Graphics.Draw.draw_and_resource_release":11.782,"Driver.Present":11.413,"VideoOut.Flip.present":11.383},"trace_dropped":false,"trace":"aps5-trace-33dbe48a8e0d-45115.json.gz"}Stray (PPSA02100), the title #10062 was written for, 180 s runs pressing cross into the game,
MTL_DEBUG_LAYER=1, a MoltenVK without residency sets (where #2876 still crashes without the deferral):APS5_NO_DEFERRED_DESTRUCTION=1: segmentation fault after about 30 s (status 139), so fix(shader): flush f16 min/max denormal inputs #2876 still reproduces on this setup.main: 3 of 3 runs reach 180 s, no device loss, no Metal assertion.WAIT_REG_MEM(the AGC wait diagnostic printed). The same diagnostic appears in 5 of 12 Stray runs on 2026-10-24 without this change, so I don't attribute it to this PR.Tests:
agc_deferred_destructionandagc_buffer_poolpass withANYPS5_REQUIRE_VULKAN=1 ANYPS5_NO_SHADER_CACHE=1 VK_INSTANCE_LAYERS=VK_LAYER_KHRONOS_validation: noVUID-line, no "was not found but was requested by env var VK_INSTANCE_LAYERS".agc_deferred_destructionuses a mock device.tools/check_conventions.py --base upstream/mainpasses.tools/pr_overlap.pyfinds no conflicting lines. It could not compare the open pull requests that conflict withmain; of those, perf(agc): reuse cached draw stages when only buffer base addresses moved #5609 also editsRecorder.cpp.Not tested: Linux and Windows (the path only runs on MoltenVK), GCC.
Checklist
main; no other open PR implements the same functionsNotImplemented_nid_no_patch); silent stubs are listed under Silent stubs in their library's technical debt file.mdfiles or images added to the repository (attach them to this PR)