Repository navigation
Conversation
The committer destroyed a finished commit in place, under the pipeline's mutex: the closure's programs, results, captures, regions and snapshots, twenty or more heap frees a draw on the thread the queue waits for, while the queue worker's enqueue waited on the same lock. A finished commit is now moved out under the lock and handed to a reaper thread, which destroys batches of 64 and wakes on its own 2 ms timer otherwise, so the committer pays one deque move and no wake per draw. APS5_NO_COMMIT_REAPER=1 restores destruction in place, after the lock. On Ratchet & Clank under RetroArch's PCSX2 core, audio produced in the heavy intro scenes 52-53% of real time to 55-56%, two alternating runs each. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
|
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.
|
jotitadev
left a comment
There was a problem hiding this comment.
On Linux this crashes draw tests at process exit. Each test prints its final success line, then dies with double free or corruption (out) or a SegFault. APS5_NO_COMMIT_REAPER=1 makes the crash go away.
Machine: NVIDIA GeForce RTX 3070, driver 595.99.02, Vulkan 1.4.329, Ubuntu 26.04 (kernel 7.0.0-38), i7-8700. GCC 15.2 (glibc), Release, BUILD_TESTING=ON, ANYPS5_GPU="NVIDIA GeForce RTX 3070". Head 74dad0097 merged into main 5d9dcc42d (clean merge).
main 5d9dcc4 |
this PR | this PR + APS5_NO_COMMIT_REAPER=1 |
|
|---|---|---|---|
agc_driver_draw_cache_reuse_off, 20 runs |
passes in every suite run | 15/20 fail | 0/20 fail |
agc_driver_inactive_vertex_point_size, 20 runs |
passes in every suite run | 20/20 fail | 0/20 fail |
pipelin|draw_cache|agc_driver_pm4 (30 tests), 3 runs |
30/30 | 2 or 3 fail per run (draw_cache_reuse*) |
30/30 |
ctest -R "^agc|shader|recompiler" -j1(flip, display andlds_atomics64excluded): 7 failures, against 1 onmain. The 6 new ones are allSegFaultorSubprocess abortedat about 1.58 s:draw_cache_reuse_off,inactive_vertex_point_size,mesh_index_cache,msaa_enable_single_sample,sample_mask_drawandstencil_ref_export_unused. The remaining failure isstore_over_untracked, which fails onmaintoo (#6347).- Verbose output of one failing run:
A repeated draw reused the cached draw without graphics pipeline libraries, thendouble free or corruption (out), thenSubprocess aborted. The test's own checks have already passed at that point.
This is probably a lifetime problem. reap() loops forever and nothing stops or joins reaper. Queue0()'s pipeline is leaked on purpose, so the reaper is still running during exit(). Whatever was retired in the last ~2 ms is then destroyed on the reaper thread while static destructors tear down the pools and caches their closures return memory to. On main the closure is destroyed before outstanding drops, so nothing outlives the last drain. I did not take a backtrace. The env toggle and the timing (after the test's last line) both point there. A drain or shutdown that flushes retired on the caller would probably fix it, as would joining the reaper.
GPUs tested: NVIDIA GeForce RTX 3070, driver 595.99.02, Ubuntu 26.04
Written with AI assistance (Claude Code). I ran the builds and tests above on my machine.
fma-rc
left a comment
There was a problem hiding this comment.
I measured this in Astro's Playroom's heavy gameplay scene on an RTX 5080. The base is main 5d9dcc4 with and without this PR, hidden, with a 20 s window and two alternating rounds. Main gave 12.17 and 11.72 FPS; this PR gave 12.76 and 12.81. In the trace, queue 0 waits 4.4 µs per draw for room instead of 6.0, and the frames match main's.
The exit crash jotitadev reported reproduces on AMD too. On a Radeon 680M (RADV), agc_driver_draw_cache_reuse_off aborts with double free or corruption (!prev) in 5 of 10 runs with this PR. It passes 10 of 10 with APS5_NO_COMMIT_REAPER=1, and 10 of 10 on main. My Playroom runs end with a kill, so they never reach that path.
|
Data point from a CPU-bound scene on Windows: RTX 3060 12 GB (NVIDIA 617.42), i5-12400F, Windows 10 19045, MinGW GCC Release. Minecraft Dungeons II (PPSA16064 01.100.100), title screen, no input, 200 s rows,
Above AI-assisted: yes (Claude Code) |
|
A second title for comparison, same box and build (
Flat here, which fits: this scene has about half the idle gaps per frame of the Minecraft Dungeons II title (24 ms against 45 ms), so there is less CPU-side waiting for the reaper to take off. No regression, 0 fatal. AI-assisted: yes (Claude Code) |
|
I tested this PR locally and found a double free in some Setup. Upstream main at 72c5eed plus local diagnostic patches (my local branch f62f3f762). Section 1 and the earlier batch in section 2 have #6617 applied on top; the table in section 2 is that base without #6617. Release, Linux (CachyOS), Ryzen 9 5950X, RTX 3080 Ti, NVIDIA 610.57.04. Hades II hub, pinned to cores 8-15,24-31 with 1. Double free in the tests.
2. Destroying the closure outside the mutex accounts for part of the gain on its own. Same binary, only that change, no reaper thread, toggled by an environment variable. n=4 per arm, interleaved (OFF ON ON OFF ON OFF OFF ON), no crashes:
In an earlier batch (n=4 per arm, interleaved, Quiesce fix applied), #6617 with the reaper gave 71.09 ± 0.47 FPS and with One title, one machine, pinned cores. No unpinned runs, no other game, no TSan. 3. The patch. The variant from section 2 is below. The game runs used the opt-in version of the switch; with the default flipped ( diff --git a/core/libs/prx/libSceAgcDriver/Execution/include/Driver/Draw/DrawPipeline.hpp b/core/libs/prx/libSceAgcDriver/Execution/include/Driver/Draw/DrawPipeline.hpp
--- a/core/libs/prx/libSceAgcDriver/Execution/include/Driver/Draw/DrawPipeline.hpp
+++ b/core/libs/prx/libSceAgcDriver/Execution/include/Driver/Draw/DrawPipeline.hpp
@@ -58,6 +58,7 @@ private:
std::exception_ptr failure;
std::atomic<std::size_t> outstanding{0};
std::uint32_t idleWaiters = 0;
+ std::uint32_t retiring = 0;
bool committerWaiting = false;
bool stopped = false;
std::thread thread;
diff --git a/core/libs/prx/libSceAgcDriver/Execution/src/Driver/Draw/DrawPipeline.cpp b/core/libs/prx/libSceAgcDriver/Execution/src/Driver/Draw/DrawPipeline.cpp
--- a/core/libs/prx/libSceAgcDriver/Execution/src/Driver/Draw/DrawPipeline.cpp
+++ b/core/libs/prx/libSceAgcDriver/Execution/src/Driver/Draw/DrawPipeline.cpp
@@ -117,6 +117,10 @@ void DrawPipeline::report(std::chrono::steady_clock::time_point now) {
}
void DrawPipeline::run() {
+ static const bool destroyUnlocked = [] {
+ const char* text = std::getenv("APS5_NO_COMMIT_DESTROY_UNLOCKED");
+ return text == nullptr || text[0] != '1';
+ }();
for (;;) {
Commit* commit = nullptr;
{
@@ -146,12 +150,23 @@ void DrawPipeline::run() {
stopped = true;
if (!shutdown) Driver::Get().ReportFailure(fatal);
}
- std::lock_guard lock(mutex);
+ std::unique_lock lock(mutex);
+ std::optional<Item> finished;
+ if (destroyUnlocked) {
+ finished = std::move(items.front());
+ ++retiring;
+ }
items.pop_front();
++commits;
commitNs += spent;
if (failed) ++commitErrors;
if (fatal != nullptr && failure == nullptr) failure = fatal;
+ if (finished.has_value()) {
+ lock.unlock();
+ finished.reset();
+ lock.lock();
+ --retiring;
+ }
outstanding.fetch_sub(1, std::memory_order_release);
if (idleWaiters != 0) idle.notify_all();
}
@@ -164,7 +179,7 @@ void DrawPipeline::Drain(DrainReason reason, std::uint32_t opcode) {
const auto start = std::chrono::steady_clock::now();
std::unique_lock lock(mutex);
++idleWaiters;
- idle.wait(lock, [&] { return items.empty(); });
+ idle.wait(lock, [&] { return items.empty() && retiring == 0; });
--idleWaiters;
const auto index = static_cast<std::size_t>(reason);
++drains[index];
LLM assistance used. I ran the builds and tests. |
|
A Linux data point on how much this costs the committer in another title, from a profile and not a measurement of this PR. Metal Gear Solid 4 (PPSA18194), Ubuntu 24.04, i7-13700K, RTX 4070 Ti (595.99.02), Release, pad input.
So in MGS4 about a tenth of the committer's time goes to the closure frees this PR moves off it. I haven't run this PR on MGS4. AI-assisted: yes (Claude Code) |
|
Linux data point: The Smurfs - Dreams (PPSA21607, Unreal Engine), CachyOS, Ryzen 9 5950X, RX 6650 XT / RADV Mesa 26.2.4, main 9f25d0b + this PR + #6566 + #6208 + #6501 (+ unrelated local rendering fixes). Same spot in the Smurfs' Village, standing still,
The committer is the bottleneck in this title (~120k commits per 10 s), so the commit time maps straight to frame rate. No rendering differences or aborts. AI-assisted (Claude Code). |
adriadam10
left a comment
There was a problem hiding this comment.
Thanks for the measurements. Reading the diff, the crash jotitadev, fma-rc and eliyarson reported has two causes in DrawPipeline.cpp:
reap()loops forever (l.198-209), so therunningCommitters.fetch_subthat used to endrun()now sits after it (l.210) and never runs;run()no longer decrements it. Put it back at the end ofrun().- The reaper thread is never stopped or joined:
Stop()(l.213) joins only the committer. Retired items (up to 63) outlivedevice.Reset()inDriver::stop()and are destroyed afterwards without the GPU lock, which fits thedouble free or corruptionat exit that goes away withAPS5_NO_COMMIT_REAPER=1. The reaper needs a stop flag set underretireMutex, a final drain ofretired, and a join inStop(), so every closure is destroyed before the device goes. eliyarson'sQuiesce()plus aretiringcounter (his comment above) covers the window between popping the item andretire().
Also, the perf label asks for the aps5-summary.jsonl lines of a capture on main and one with the change, from the same title and scene, plus the tools/trace_digest.py output; the third-party numbers help but the form asks for them in the PR.
|
Following the teardown reports above, I tested a shutdown follow-up on main Source: integration branch, retaining this PR's authored commit. The follow-up 9b3ce9fc4d joins the committer first, then signals the reaper to flush its last batch and joins it before Regression tests cover a captured object's blocked destructor and a 65-item batch tail. The blocked-destructor test passes on main, fails with the unmodified PR integrated into main ( Validation on the same Linux / Radeon RX 6650 XT / RADV machine, with Vulkan required, shader cache disabled and Khronos validation enabled:
The expanded suite command is: ctest --test-dir build-full -R '^(agc_draw_pipeline_stop_(active|tail)|agc_driver_(pipelined_fill|pm4|same_queue_label_wait|pipelined_predication_read|draw_cache_reuse(_off|_verify|_inline)?|inactive_vertex_point_size))$' -V --timeout 30
These are shutdown/test results. The subsequent title measurement is pinned to the original sources above and is only one ordered pair. The existing committer self-stop/detach behavior is preserved and is not covered by the synchronous shutdown claim. AI-assisted: yes. Refresh on main
|
|
Native-title follow-up to the shutdown tests above: Record of Lodoss War -Deedlit in Wonder Labyrinth- (
main official summary: {"commit":"7a015c0946e2","dirty":false,"env":{"APS5_DRAW_CACHE_ENTRIES":"4096","APS5_HOST_IMPORT_MIB":"16384","APS5_PAD_INPUT_FILE":"<path>","APS5_PIPELINED_DRAWS":"1","APS5_SPIRV_OPT":"full","APS5_TRACE_SECONDS":"200:30"},"gpu":"AMD Radeon RX 6650 XT (RADV NAVI23)","driver":"radv Mesa 26.2.4-arch1.1","os":"Linux 7.2.9-arch1-1","resolution":"3840x2160","window":{"spec":"seconds 200:30","first_present":9410,"ms":30003.439},"presents":698,"frame_ms":{"p50":41.744,"p90":52.656,"p99":68.522,"max":79.143},"gpu_busy_ms_per_present":2.218,"worker_busy_pct":{"queue worker 0x0":43.62},"top_phases_ms_per_frame":{"Driver.Packet":18.746,"Driver.Packet.device_lock":12.798,"Graphics.Draw":9.591,"Graphics.Draw.validate":7.781,"Driver.Packet.prepare_memory":5.045,"GpuMutex.wait.label":3.465,"Recorder.Sync":3.323,"GpuMutex.wait.other":2.98},"trace_dropped":false,"trace":"aps5-trace-7a015c0946e2-1334271.json.gz"}candidate official summary: {"commit":"1365624ca52d","dirty":false,"env":{"APS5_DRAW_CACHE_ENTRIES":"4096","APS5_HOST_IMPORT_MIB":"16384","APS5_PAD_INPUT_FILE":"<path>","APS5_PIPELINED_DRAWS":"1","APS5_SPIRV_OPT":"full","APS5_TRACE_SECONDS":"200:30"},"gpu":"AMD Radeon RX 6650 XT (RADV NAVI23)","driver":"radv Mesa 26.2.4-arch1.1","os":"Linux 7.2.9-arch1-1","resolution":"3840x2160","window":{"spec":"seconds 200:30","first_present":9494,"ms":30008.19},"presents":718,"frame_ms":{"p50":40.368,"p90":51.067,"p99":63.197,"max":72.338},"gpu_busy_ms_per_present":2.28,"worker_busy_pct":{"queue worker 0x0":42.605},"top_phases_ms_per_frame":{"Driver.Packet":17.802,"Driver.Packet.device_lock":12.24,"Graphics.Draw":9.282,"Graphics.Draw.validate":7.487,"Driver.Packet.prepare_memory":4.658,"GpuMutex.wait.label":3.052,"Recorder.Sync":2.941,"GpuMutex.wait.other":2.898},"trace_dropped":false,"trace":"aps5-trace-1365624ca52d-1495193.json.gz"}Official |
|
Thanks @adriadam10. I read @JJenkx's follow-up
That covers what my @TheAggie, if you pull this into #6617: @JJenkx's replay of it on newer main is The no-reaper variant from my earlier comment (closure destroyed after the lock is released, no reaper thread) is now on my fork as branch For the LLM assistance used. |
|
I'm picking this up alongside @adriadam10 because it is part of a stack that gets PPSA04263 further on current |
|
Windows data point from Yakuza 0 Director's Cut (PPSA31327), which is committer-bound in gameplay. Windows 11 Pro 26200, RTX 4070 (617.42), Ryzen 7 7800X3D, WinLibs GCC 15.2.0, Release, character standing still in Kamurocho.
Replicated on current
Summary lines (one run of each build){"commit":"a286c08cd91f","dirty":false,"env":{"APS5_NO_PAD_INPUT":"1","APS5_PAD_INPUT_FILE":"<path>","APS5_TRACE_SECONDS":"170:60"},"gpu":"NVIDIA GeForce RTX 4070","driver":"NVIDIA 617.42","os":"Windows 10.0.26200","cpu":"AMD Ryzen 7 7800X3D 8-Core Processor","cpu_threads":16,"memory_mib":31892,"title_id":"PPSA31327","title":"Yakuza 0 Director's Cut","content_version":"01.015.000","resolution":"1920x1080","window":{"spec":"seconds 170:60","first_present":2932,"ms":60110.216},"presents":174,"frame_ms":{"p50":343.785,"p90":352.964,"p99":443.525,"max":448.872},"gpu_busy_ms_per_present":74.113,"worker_busy_pct":{"queue worker 0x0":98.708},"top_phases_ms_per_frame":{"Driver.Packet":340.744,"Driver.Packet.draw":310.283,"Driver.Draw":307.147,"Graphics.Draw":292.543,"Graphics.Draw.draw_and_resource_release":204.982,"Driver.Draw.shader_compile_and_link":159.927,"Shader.DrawStage":125.474,"Driver.Draw.draw_enqueued":116.955},"trace_dropped":true,"trace_dropped_threads":{"queue worker 0x0":{"events_full_after_s":3.265,"events_lost":4557401,"totals_full":false},"draw committer":{"events_full_after_s":8.264,"events_lost":1660133,"totals_full":false}},"trace":"aps5-trace-a286c08cd91f-18056.json.gz"}{"commit":"8af2a67c84e7","dirty":false,"env":{"APS5_NO_PAD_INPUT":"1","APS5_PAD_INPUT_FILE":"<path>","APS5_TRACE_SECONDS":"170:60"},"gpu":"NVIDIA GeForce RTX 4070","driver":"NVIDIA 617.42","os":"Windows 10.0.26200","cpu":"AMD Ryzen 7 7800X3D 8-Core Processor","cpu_threads":16,"memory_mib":31892,"title_id":"PPSA31327","title":"Yakuza 0 Director's Cut","content_version":"01.015.000","resolution":"1920x1080","window":{"spec":"seconds 170:60","first_present":2988,"ms":60071.381},"presents":198,"frame_ms":{"p50":302.144,"p90":314.216,"p99":328.471,"max":405.043},"gpu_busy_ms_per_present":72.331,"worker_busy_pct":{"queue worker 0x0":98.613},"top_phases_ms_per_frame":{"Driver.Packet":298.984,"Graphics.Draw":271.880,"Driver.Packet.draw":270.452,"Driver.Draw":267.294,"Graphics.Draw.draw_and_resource_release":192.471,"Driver.Draw.shader_compile_and_link":150.712,"Shader.DrawStage":118.400,"Driver.Draw.draw_enqueued":88.169},"trace_dropped":true,"trace_dropped_threads":{"queue worker 0x0":{"events_full_after_s":3.384,"events_lost":4513922,"totals_full":false},"draw committer":{"events_full_after_s":7.938,"events_lost":1744082,"totals_full":false}},"trace":"aps5-trace-8af2a67c84e7-8036.json.gz"}AI-assisted: yes |
The reaper loop never returned, so the committer count it decremented after the loop never dropped: run() now decrements it itself. Stop() now also stops the reaper under retireMutex, lets it destroy what is still retired and joins it, so no finished commit outlives device.Reset(). A retire after the stop destroys the item in place. The shutdown test checks that the reaper stopped and that a finished commit's closure is gone once the driver has shut down. Co-authored-by: Scott Schuster <scott.n.schuster@gmail.com>
|
This pull request is labeled |
|
@fma-rc @adriadam10 the exit crash you both reported is fixed on 4fe2bfb, which keeps @TheAggie's commit and adds the fix (8326fb0) on top of current
On an RTX 4090, without the fix: @fma-rc, if you can repeat your RADV exit run (5/10 before) on this head, that would settle the crash on AMD too. |
|
@oneandonlydean confirmed on RADV, the exit crash is gone on 4fe2bfb. Same Radeon 680M laptop and tests as before:
|
fma-rc
left a comment
There was a problem hiding this comment.
Read 8326fb0, it fixes the crash I reported. The reaper now exits on reaperStopping, drains what was retired before it stopped, and Stop() joins it after the committer, so nothing retired outlives the device. A retire after the stop destroys the item outside retireMutex, which is right. closing and reaperStopping both stay set after Stop(), so later commits run and are destroyed inline, which matches how the committer already behaves after shutdown. The new test checks both the reaper count and the closure lifetime. Runs on RADV are in my comment above.
All four points are addressed at 4fe2bfb: run() decrements runningCommitters again; the reaper's stop flag is set under retireMutex, its last batch is drained and Stop() joins it; the pop-to-retire window is closed by ordering (Stop() joins the committer before stopping the reaper, and Driver::stop calls Stop() before device.Reset()); the perf-label summary lines and trace_digest output are in JJenkx's 19 Oct comment. Dismissing so the review state matches the head; please re-request changes if I've missed something.
|
A Linux/RADV data point for 4fe2bfb, from ASTRO BOT (PPSA21567), whose Sky Garden is committer-bound on this machine. Setup: ASTRO BOT 01.019.000, One build:
Traces for round 2: both off, reaper on, atomic passes on, both on. The trace buffers filled after 3 s on queue worker 0 and after 10 s on the committer, so use the summary lines for timings, not the per-thread busy columns.
|
| thread | busy | wait | untraced | in slices < 20 us | largest |
|---|---|---|---|---|---|
| queue worker 0x0 | 17.7 (6 %) | 0.6 (0 %) | 265.0 | 19.8 | Driver.Packet 18.3, Driver.Completion 0.0 |
| title | 0.2 (0 %) | 0.0 (0 %) | 283.2 | 0.7 | Shader.ResolveGraphicsStagesAbi 0.2, Shader.ResolveAbi 0.0 |
| title | 0.1 (0 %) | 0.0 (0 %) | 283.3 | 0.3 | Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.0 |
| title | 0.0 (0 %) | 0.0 (0 %) | 283.3 | 0.0 | Shader.ResolveGraphicsStagesAbi 0.0, Shader.ResolveAbi 0.0 |
| title | 0.1 (0 %) | 0.0 (0 %) | 283.3 | 0.9 | Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.0 |
| draw committer | 36.4 (13 %) | 3.2 (1 %) | 243.7 | 19.8 | Graphics.Draw 32.8, Recorder.Submit 3.4 |
| queue worker 0x40 | 19.1 (7 %) | 262.5 (93 %) | 1.8 | 2.6 | Driver.Packet 281.4, Driver.EndSubmission 0.2 |
| queue worker 0x48 | 0.3 (0 %) | 281.4 (99 %) | 1.7 | 0.2 | Driver.Packet 281.5, Driver.EndSubmission 0.1 |
| presenter | 0.5 (0 %) | 0.8 (0 %) | 282.1 | 0.0 | VideoOut.Flip 1.3, Driver.Present 0.0 |
| queue worker 0x46 | 0.5 (0 %) | 281.1 (99 %) | 1.7 | 0.7 | Driver.Packet 1.1, Driver.EndSubmission 0.1 |
| title | 0.1 (0 %) | 0.0 (0 %) | 283.2 | 0.3 | Shader.ResolveGraphicsStagesAbi 0.1 |
| gpu | 141.6 (50 %) | 0.0 (0 %) | 141.8 | 0.0 | batch 141.6 |
Largest slices (ms per frame, inclusive, all threads): Driver.Packet 582.4, Driver.Packet.memory_wait 534.1, Driver.WorkerWait 280.4, Driver.WorkerWait.dequeue_order 276.3
Longest waits
- Driver.Packet.memory_wait (queue worker 0x48) 325.5 ms at 30873 ms, present 1087
- Driver.WorkerWait (queue worker 0x46) 315.2 ms at 3954 ms, present 991
- Driver.Packet.memory_wait (queue worker 0x48) 314.4 ms at 4051 ms, present 992
- Driver.Packet.memory_wait (queue worker 0x48) 311.0 ms at 1477 ms, present 983
Largest GPU batches (GPU ranges inside, and the CPU slices that recorded each, inclusive)
- batch 39307: 12.2 ms at 46857 ms, present 1143: GPU no ranges; recorded by no CPU slices
- batch 41218: 12.1 ms at 49130 ms, present 1151: GPU no ranges; recorded by no CPU slices
- batch 38351: 11.9 ms at 45693 ms, present 1139: GPU no ranges; recorded by no CPU slices
- batch 20572: 11.9 ms at 24502 ms, present 1064: GPU no ranges; recorded by no CPU slices
- batch 41455: 11.6 ms at 49429 ms, present 1152: GPU no ranges; recorded by no CPU slices
trace_digest.py, reaper on
seconds 90:50 from present 995: 187 presents, frame p50 268.4 / p90 277.3 / p99 282.3 / max 292.9 ms, GPU busy 137.8 ms per present
AMD Radeon RX 9070 XT (RADV GFX1201), radv Mesa 26.2.4-arch3.1, Linux 7.3.0-2-cachyos, 3840x2160, commit 9bf2da0c4fe1, dropped: yes
{"commit":"9bf2da0c4fe1","dirty":false,"env":{"APS5_HOST_IMPORT_MIB":"4096","APS5_NO_ATOMIC_PASSES":"1","APS5_NO_SNAPSHOT_CHECK":"1","APS5_TRACE_DIR":"<path>","APS5_TRACE_SECONDS":"90:50"},"gpu":"AMD Radeon RX 9070 XT (RADV GFX1201)","driver":"radv Mesa 26.2.4-arch3.1","os":"Linux 7.3.0-2-cachyos","cpu":"AMD Ryzen 7 7800X3D 8-Core Processor","cpu_threads":16,"memory_mib":31228,"title_id":"PPSA21567","title":"ASTRO BOT","content_version":"01.019.000","resolution":"3840x2160","window":{"spec":"seconds 90:50","first_present":995,"ms":50172.378},"presents":187,"frame_ms":{"p50":268.425,"p90":277.314,"p99":282.347,"max":292.884},"gpu_busy_ms_per_present":137.755,"worker_busy_pct":{"queue worker 0x0":99.32,"queue worker 0x40":99.508,"queue worker 0x48":99.448,"queue worker 0x46":0.508},"top_phases_ms_per_frame":{"Driver.Packet":801.115,"Driver.Packet.memory_wait":507.814,"Driver.Packet.draw":201.085,"Driver.Draw":200.185,"Graphics.Draw":160.379,"Graphics.Draw.draw_and_resource_release":140.264,"Driver.Draw.shader_compile_and_link":135.277,"Shader.DrawStage":120.608},"trace_dropped":true,"trace_dropped_threads":{"queue worker 0x0":{"events_full_after_s":3.668,"events_lost":3289833,"totals_full":false},"draw committer":{"events_full_after_s":11.45,"events_lost":887735,"totals_full":false}},"trace":"aps5-trace-9bf2da0c4fe1-609717.json.gz"}Slowest frames (largest slices inside each, inclusive)
- present 1069: 292.9 ms at 19806 ms: Driver.Packet (queue worker 0x48) 292.7, Driver.Packet.memory_wait (queue worker 0x48) 292.4, Driver.Packet (queue worker 0x40) 292.3, Driver.WorkerWait (queue worker 0x46) 291.0
- present 1144: 282.3 ms at 39899 ms: Driver.Packet (queue worker 0x48) 282.2, Driver.Packet.memory_wait (queue worker 0x48) 281.9, Driver.Packet (queue worker 0x40) 281.4, Driver.WorkerWait (queue worker 0x46) 281.2
- present 1007: 281.3 ms at 3260 ms: Driver.Packet (queue worker 0x48) 281.1, Driver.Packet.memory_wait (queue worker 0x48) 280.8, Driver.Packet (queue worker 0x40) 280.5, Driver.WorkerWait (queue worker 0x46) 280.0
- present 1130: 279.9 ms at 36123 ms: Driver.Packet (queue worker 0x48) 279.7, Driver.Packet.memory_wait (queue worker 0x48) 279.5, Driver.Packet (queue worker 0x40) 279.1, Driver.WorkerWait (queue worker 0x46) 278.5
- present 1009: 279.2 ms at 3820 ms: Driver.Packet (queue worker 0x48) 279.0, Driver.Packet.memory_wait (queue worker 0x48) 278.8, Driver.Packet (queue worker 0x40) 278.5, Driver.WorkerWait (queue worker 0x46) 278.0
Threads (ms per frame)
| thread | busy | wait | untraced | in slices < 20 us | largest |
|---|---|---|---|---|---|
| queue worker 0x0 | 17.0 (6 %) | 0.7 (0 %) | 250.6 | 20.1 | Driver.Packet 17.7, Driver.Completion 0.0 |
| title | 0.1 (0 %) | 0.0 (0 %) | 268.2 | 0.7 | Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.0 |
| title | 0.0 (0 %) | 0.0 (0 %) | 268.3 | 0.0 | Shader.ResolveGraphicsStagesAbi 0.0, Shader.ResolveAbi 0.0 |
| title | 0.1 (0 %) | 0.0 (0 %) | 268.2 | 0.3 | Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.0 |
| title | 0.1 (0 %) | 0.0 (0 %) | 268.2 | 0.9 | Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.0 |
| queue worker 0x40 | 10.5 (4 %) | 256.0 (95 %) | 1.8 | 2.6 | Driver.Packet 266.3, Driver.EndSubmission 0.2 |
| queue worker 0x48 | 0.3 (0 %) | 266.5 (99 %) | 1.5 | 0.2 | Driver.Packet 266.7, Driver.EndSubmission 0.1 |
| draw committer | 34.4 (13 %) | 0.6 (0 %) | 233.3 | 20.7 | Graphics.Draw 30.1, Recorder.Submit 4.2 |
| presenter | 0.5 (0 %) | 0.6 (0 %) | 267.2 | 0.0 | VideoOut.Flip 1.0, Driver.Present 0.1 |
| queue worker 0x46 | 0.5 (0 %) | 266.2 (99 %) | 1.6 | 0.7 | Driver.Packet 1.1, Driver.EndSubmission 0.1 |
| title | 0.1 (0 %) | 0.0 (0 %) | 268.2 | 0.3 | Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.0 |
| gpu | 137.8 (51 %) | 0.0 (0 %) | 130.5 | 0.0 | batch 137.8 |
Largest slices (ms per frame, inclusive, all threads): Driver.Packet 551.8, Driver.Packet.memory_wait 507.1, Driver.WorkerWait 265.5, Driver.WorkerWait.dequeue_order 261.5
Longest waits
- Driver.Packet.memory_wait (queue worker 0x48) 291.5 ms at 19839 ms, present 1069
- Driver.WorkerWait (queue worker 0x46) 286.5 ms at 37662 ms, present 1135
- Driver.WorkerWait (queue worker 0x46) 284.4 ms at 46317 ms, present 1167
- Driver.WorkerWait (queue worker 0x46) 284.1 ms at 45779 ms, present 1165
Largest GPU batches (GPU ranges inside, and the CPU slices that recorded each, inclusive)
- batch 43627: 12.6 ms at 50017 ms, present 1181: GPU no ranges; recorded by no CPU slices
- batch 36592: 12.5 ms at 41907 ms, present 1151: GPU no ranges; recorded by no CPU slices
- batch 31668: 12.4 ms at 36247 ms, present 1130: GPU no ranges; recorded by no CPU slices
- batch 39433: 12.3 ms at 45152 ms, present 1163: GPU no ranges; recorded by no CPU slices
- batch 33041: 12.3 ms at 37855 ms, present 1136: GPU no ranges; recorded by no CPU slices
Written by Claude (AI assistant) on a contributor's machine.
AI-assisted: yes
|
A data point from GTA V (PPSA04264) on Windows (RTX 4090, i9-13900K, MinGW GCC 15.2). It is from a profile on an older base, not a run of this PR.
A note on measuring GTA: the open world trace buffers fill after about 4 s (queue worker events), like in the runs above. So I would report committer us/commit and the I can run 4fe2bfb against its AI-assisted: yes (Claude Code) |
|
Re-measured on current
On the base I measured on 10-22 (before #6946) this PR gave -8 %. On current Summary lines (base, then base + this PR){"commit":"13abb3589418","dirty":false,"env":{"APS5_NO_PAD_INPUT":"1","APS5_PAD_INPUT_FILE":"<path>","APS5_TRACE_SECONDS":"140:60"},"gpu":"NVIDIA GeForce RTX 4070","driver":"NVIDIA 621.01","os":"Windows 10.0.26200","cpu":"AMD Ryzen 7 7800X3D 8-Core Processor","cpu_threads":16,"memory_mib":31892,"title_id":"PPSA31327","title":"Yakuza 0 Director's Cut","content_version":"01.015.000","resolution":"1920x1080","window":{"spec":"seconds 140:60","first_present":2825,"ms":60158.708},"presents":186,"frame_ms":{"p50":322.007,"p90":334.950,"p99":351.833,"max":431.291},"gpu_busy_ms_per_present":74.935,"worker_busy_pct":{"queue worker 0x0":98.794},"top_phases_ms_per_frame":{"Driver.Packet":319.309,"Graphics.Draw":290.048,"Driver.Packet.draw":289.367,"Driver.Draw":287.064,"Graphics.Draw.draw_and_resource_release":205.158,"Driver.Draw.shader_compile_and_link":145.218,"Shader.DrawStage":118.438,"Driver.Draw.draw_enqueued":115.814},"trace_dropped":true,"trace_dropped_threads":{"queue worker 0x0":{"events_full_after_s":3.262,"events_lost":4558755,"totals_full":false},"draw committer":{"events_full_after_s":7.808,"events_lost":1754780,"totals_full":false}},"trace":"aps5-trace-13abb3589418-91032.json.gz"}{"commit":"c19a99fde524","dirty":false,"env":{"APS5_NO_PAD_INPUT":"1","APS5_PAD_INPUT_FILE":"<path>","APS5_TRACE_SECONDS":"140:60"},"gpu":"NVIDIA GeForce RTX 4070","driver":"NVIDIA 621.01","os":"Windows 10.0.26200","cpu":"AMD Ryzen 7 7800X3D 8-Core Processor","cpu_threads":16,"memory_mib":31892,"title_id":"PPSA31327","title":"Yakuza 0 Director's Cut","content_version":"01.015.000","resolution":"1920x1080","window":{"spec":"seconds 140:60","first_present":2837,"ms":60262.110},"presents":179,"frame_ms":{"p50":332.441,"p90":352.828,"p99":435.396,"max":476.511},"gpu_busy_ms_per_present":75.849,"worker_busy_pct":{"queue worker 0x0":98.762},"top_phases_ms_per_frame":{"Driver.Packet":332.302,"Driver.Packet.draw":302.081,"Graphics.Draw":301.942,"Driver.Draw":299.738,"Graphics.Draw.draw_and_resource_release":213.515,"Driver.Draw.shader_compile_and_link":167.281,"Shader.DrawStage":132.778,"Driver.Draw.draw_enqueued":101.120},"trace_dropped":true,"trace_dropped_threads":{"queue worker 0x0":{"events_full_after_s":3.363,"events_lost":4570590,"totals_full":false},"draw committer":{"events_full_after_s":7.917,"events_lost":1749870,"totals_full":false}},"trace":"aps5-trace-c19a99fde524-37624.json.gz"}AI-assisted: yes |
|
@TheAggie thanks for this, and @johandavidcm thanks for the careful measurements. I'm closing it for now, for three reasons:
If you see a case where the reaper thread still wins on top of current main, please reopen with the numbers and we'll look again. |
What
With pipelined draws the committer is the thread the queue worker waits for. After each commit it popped the item from the pipeline's deque under the pipeline mutex, which destroyed the commit's closure right there: the decode's programs, the compiled results, the stage captures, the regions, the snapshots and the rest, twenty or more heap frees a draw, on the critical thread and with the lock held while the worker's enqueue waited for it.
DrawPipeline::runmoves the finished item out under the lock and hands it toretire, which queues it for a reaper thread. The reaper destroys batches: it is woken only when 64 items have gathered, and otherwise checks every 2 ms, so the committer pays one deque move and no wake per draw. (Waking it per commit cost more than it saved.)APS5_NO_COMMIT_REAPER=1destroys the item in place as before, though after the lock.ShaderMemoryreturns its pages to the destroying thread's pool (as it already did on the committer), and the rest are plain frees.Tested
Windows 11, NVIDIA GeForce RTX 5070 Ti, MinGW-w64 GCC 15.2.0, on main
ce991f1ec.ctest: 1278 of 1297 pass, 14 skipped.guest_call_trace_abortandwindows_backtrace_reportfail, and fail the same way on plain main here;agc_driver_prepared_graphics_prebuild_0/_1andundeliverable_host_exceptionfail under my test runner because it skips their environment changes and pass pattern, and pass run with those.agc_driver_gpu_indirect_arguments_misaligned_writer_ahead, new on this main, does not compile with MinGW (alignas(65536)exceeds the object file maximum of 8192) and was left out of the run. The pipelined, draw-cache and PM4 tests (13) also pass withAPS5_NO_COMMIT_REAPER=1.APS5_BATCH_CAP=256, audio muted, same build with and without this change, two alternating runs each: audio produced in the heavy intro scenes 52-53% of real time without, 55-56% with (the base here also carries perf(agc): find cached draws across moved user-data pointers #4943, perf(agc): reuse cached draw stages when only buffer base addresses moved #5609, perf(agc): cut per-draw heap allocations #6312, perf(agc): a DMA_DATA prefetch keeps the draw pipeline #6538, perf(agc): relocate cached draws across user words that only reach the shader as values #6539 and perf(agc): fewer heap allocations per recorded draw #6566, which make its draws hit the cache; the change itself is independent of them).Checklist
main; no other open PR implements the same functionsNotImplemented_nid_no_patch); silent stubs are listed in TechnicalDebt.mdfiles or images added to the repository (attach them to this PR)🤖 Generated with Claude Code