perf: Hades II hub is bound by the queue-0 packet worker; recording draws on a second thread takes ~30 to ~48 FPS locally (findings, work in progress)

Title and scene

Hades II, Linux, hub after the intro (idle area), same window and settings for every run. Title ID not recorded.

What is slow or what changed

The queue-0 packet worker is the limit in this scene, not the GPU. I have a local change set (not published, no PR yet) in which the worker hands each draw to a second thread that records it, and keeps decoding the next packets while that thread works. This issue records the findings and the state of the work so that it can be compared with related work before anything is posted as a PR.

Machine: AMD Ryzen 9 5950X, NVIDIA GeForce RTX 3080 Ti (driver 610.57.04), Linux 7.2.2, 94 GB RAM. The numbers are the window-title FPS, three readings per run, after the hub has loaded.

Rebased onto main a0f5916 (81 commits on top), all in the same session:

Build	FPS readings
`main` `a0f5916`	30.19, 28.65, 30.75
change, flag off	32.95, 31.94, 31.12
change, `APS5_MT_RECORD=1`, run 1	50.79, 47.23, 48.69
change, `APS5_MT_RECORD=1`, run 2	46.78, 48.35, 48.26

A second main run produced no readings (the run did not complete), so main has one run, and the machine load was not controlled (load average between 2 and 7 during these runs). Before the rebase, on the older base, the same scene read about 29 inline and 42 to 51 threaded.

Worker time per draw with the thread on (about 219k draws per 10 s, from the [mtrecord] line): capture 10.7 us, key/lookup/validate 9.1, decode 4.7, recompile 2.9, enqueue 2.8, vectors 1.9, precheck 0.9, job build 0.8. The record thread needs about 25 us per job. On the pre-rebase branch the write checker (APS5_MT_RECORD_CHECK=1, predicts every range a draw writes and compares it with what the job wrote) reported 0 uncovered ranges over about 3.3 million jobs; it was not on in the runs above.

Status

Performance traces (APS5_TRACE_*, main against the change, same machine and scene) and the pull requests are on the way. I will add the trace summary lines and digests to this issue, and the PRs will link back to it. The change will be split into several small PRs, each on current main.

Design

A record thread owns Graphics::Draw and the label recording of each draw job. The queue holds at most 7 jobs.
The worker publishes the memory each queued draw will write. Worker reads, captures, waits and label reads over a queued range drain first; packets that touch neither guest memory nor the GPU mutex run ahead; anything else drains first.
Taking GpuMutex with jobs pending drains first; try_lock sites fail fast.
Off by default (APS5_MT_RECORD=1); APS5_MT_RECORD_THREAD=0 runs the same jobs inline. The golden-stream colour hash with the flag off is unchanged.

Not done and not claimed

No performance traces as the report form asks. APS5_TRACE_* captures of main and the change on the same machine and scene are the next step; until then these are window-title FPS readings, not protocol numbers.
One title, one machine, Linux, NVIDIA only. Nothing on Windows or other GPUs.
The newest commits (predicated packets run ahead, deferred labels handed to the record job) have an open review finding: a second label deferred at the same address can have its queued-label entry erased by the cleanup of the first (needs a stamp-matched forget). Not fixed yet.
A heap-corruption abort at exit seen once and some intermittent test crashes were not reproduced.
The branch needs rewriting before any PR: Conventional Commit subjects, no comments, APS5_LOCKED_DRAW_PREPARE should throw instead of falling back, docs and debt entry. The change is large (about 12k lines) and would be split into several PRs.

Overlap is not yet analysed in detail: #1201 and #1202 (pipelined queue-0 draw commits), #1895 and #1896 (indirect draws), #5345 (single queue worker CPU-bound in another title), #4054, #5407 and #5216 (draw cache), #4889 (incremental pending write snapshots). I would like to know whether the committer in #1201/#1202 is meant to cover the same cut before I split this into PRs.

AI-assisted: yes

Trace captures, as the performance report asks. Same machine and session, one game at a time, the Hades II hub, APS5_TRACE_SECONDS=150:30 (30 s starting 150 s after the first present), the game log sent to /dev/null, no other APS5_TRACE_* or APS5_PROFILE_* switch. Each capture is a fresh start of the title; the shader and pipeline caches were warm from earlier runs.

Build	commit	presents in 30 s	frame p50 / p90 / p99 / max (ms)	FPS (1000 / p50)	queue worker busy
`main`	`a0f5916`	863	34.9 / 36.8 / 38.9 / 40.6	28.7	98.7 %
change, flag off	e3340a220	867	34.8 / 36.2 / 38.0 / 40.0	28.8	96.2 %
change, `APS5_MT_RECORD=1`	e3340a220	1303	23.1 / 24.4 / 26.3 / 30.0	43.2	85.8 %

With the flag off the change is the same as main within noise. With the flag on, p50 frame time drops from 34.8 ms to 23.1 ms (about 1.5x) and the worker is no longer saturated. This is lower than the 47 to 51 FPS read from the window title earlier. I have not explained the gap; the trace itself may cost time, and the title readings were taken in a different window of the run.

Caveats: all three summary lines have "trace_dropped": true (I have not checked what is dropped or how it affects the numbers), one capture per build, one scene, Linux and NVIDIA only, and no frame-dump comparison yet.

Summary lines

{"commit":"a0f5916a2930","dirty":false,"env":{"APS5_DRAW_PREPARE_AHEAD":"2","APS5_HOST_IMPORT_MIB":"16384","APS5_TRACE_SECONDS":"150:30"},"gpu":"NVIDIA GeForce RTX 3080 Ti","driver":"NVIDIA 610.57.04","os":"Linux 7.2.2-1-cachyos","resolution":"1920x1080","window":{"spec":"seconds 150:30","first_present":8076,"ms":30008.887},"presents":863,"frame_ms":{"p50":34.863,"p90":36.770,"p99":38.870,"max":40.624},"gpu_busy_ms_per_present":8.861,"worker_busy_pct":{"queue worker 0x0":98.651},"top_phases_ms_per_frame":{"Driver.Packet":34.284,"Driver.Packet.draw":31.728,"Driver.Draw":31.525,"Driver.Draw.shader_compile_and_link":13.968,"Driver.Draw.draw_and_resource_release":13.064,"Graphics.Draw":12.802,"Graphics.Draw.draw_and_resource_release":10.281,"Shader.DrawStage":9.712},"trace_dropped":true,"trace":"aps5-trace-a0f5916a2930-434051.json.gz"}
{"commit":"e3340a220f92","dirty":false,"env":{"APS5_DRAW_PREPARE_AHEAD":"2","APS5_HOST_IMPORT_MIB":"16384","APS5_TRACE_SECONDS":"150:30"},"gpu":"NVIDIA GeForce RTX 3080 Ti","driver":"NVIDIA 610.57.04","os":"Linux 7.2.2-1-cachyos","resolution":"1920x1080","window":{"spec":"seconds 150:30","first_present":6021,"ms":30019.858},"presents":867,"frame_ms":{"p50":34.779,"p90":36.202,"p99":38.010,"max":40.000},"gpu_busy_ms_per_present":8.819,"worker_busy_pct":{"queue worker 0x0":96.187},"top_phases_ms_per_frame":{"Driver.Packet":33.287,"Driver.Packet.draw":30.365,"Driver.Draw":27.539,"Driver.Draw.draw_and_resource_release":13.033,"Graphics.Draw":12.770,"Driver.Draw.shader_compile_and_link":11.128,"Graphics.Draw.draw_and_resource_release":10.274,"Shader.DrawStage":6.886},"trace_dropped":true,"trace":"aps5-trace-e3340a220f92-462321.json.gz"}
{"commit":"e3340a220f92","dirty":false,"env":{"APS5_DRAW_PREPARE_AHEAD":"2","APS5_HOST_IMPORT_MIB":"16384","APS5_MT_RECORD":"1","APS5_TRACE_SECONDS":"150:30"},"gpu":"NVIDIA GeForce RTX 3080 Ti","driver":"NVIDIA 610.57.04","os":"Linux 7.2.2-1-cachyos","resolution":"1920x1080","window":{"spec":"seconds 150:30","first_present":9887,"ms":30003.025},"presents":1303,"frame_ms":{"p50":23.129,"p90":24.419,"p99":26.348,"max":30.034},"gpu_busy_ms_per_present":8.430,"worker_busy_pct":{"queue worker 0x0":85.788},"top_phases_ms_per_frame":{"Driver.Packet":19.737,"Driver.Packet.draw":17.111,"Driver.Draw":14.996,"Driver.Draw.shader_compile_and_link":11.306,"Shader.DrawStage":6.284,"Shader.DrawStage.capture_resources":3.787,"Driver.Draw.prepare":1.345,"Shader.DrawStage.materialize":1.305},"trace_dropped":true,"trace":"aps5-trace-e3340a220f92-448630.json.gz"}

The trace files (aps5-trace-*.json.gz) are not attached yet; I can attach them on request. Pull requests are still on the way.

Thanks, the matched trace capture makes the performance result much stronger: the flag-off branch stays near main (34.8 ms vs 34.9 ms p50), while APS5_MT_RECORD=1 reaches 23.1 ms p50 and lowers worker busy time. I would hold off splitting/posting the implementation until the remaining limitations are closed: all three runs report trace_dropped=true, the change still has the same-address deferred-label cleanup race called out in the report, and the write checker/frame-dump equivalence has not been rerun on the rebased code. Could you attach the trace files or summarize what was dropped, and report the rebased checker/frame comparison before proposing the PR split? Those would let reviewers separate the measured speedup from recording loss or output differences.

@eliyarson

Another title with the same limit, for comparison: High on Life (PPSA15388, UE 4.27), standing in the home base facing the portal. It runs at about 4–5 FPS there. The queue-0 packet worker is busy the whole frame, while the GPU is idle most of it.

Trace, 10 s at that spot (APS5_TRACE_SECONDS window, APS5_PROFILE_GPU=1):


presents	49 in 10.1 s, frame p50 / p90 / p99 = 179 / 272 / 437 ms
GPU busy per present	59 ms
queue worker 0x0	99.3 % busy, about 1,300 draws per frame
queue worker 0x20	99.3 % busy, but 93 % of its time is `Driver.Packet.memory_wait` (waiting for queue 0)

Queue worker 0x0, share of its recorded time:

Scope	Share
`Driver.Packet`	92.6 %
`Driver.Draw`	63.5 % (4.07 s over 41,475 draws, about 98 µs per draw)
`Graphics.Draw.draw_and_resource_release`	32.7 %
`Resources.Complete`	22.3 % (3,322 calls, about 0.43 ms each)
`Driver.Dispatch`	11.5 %
`Driver.Draw.shader_compile_and_link`	11.1 % (17,787 calls; the caches were warm)
`Recorder.Sync`	10.0 % (382 calls, about 1.7 ms each)

So queue 0 spends about 98 µs per draw here, roughly twice the ~45 µs per draw of the Hades II hub above (219k draws per 10 s), at a far lower draw count. A record thread like @eliyarson's APS5_MT_RECORD looks like the right lever here too. Pinning threads changed nothing: I moved the queue worker to its own P-core and the title's spinning workers to E-cores, live with taskset, and FPS stayed at 3.0–3.9. When the change is posted I can run the same spot against it.

Details

Linux (CachyOS, kernel 7.2.9), Intel i9-14900K, NVIDIA RTX 4090 (driver 615.78.08), output 3840x2160.
Build: main 18c438b10 plus feat(agc): sample non-sRGB textures through FORCE_DEGAMMA samplers as sRGB views #4487, feat(libSceAgcDriver): support secondary LOD bias and relax unnormalized coordinate filters #5156, feat(agc): storage image access to depth planes through 2D array views #5003, fix(libScePlayGo): report missing chunk metadata #5494 and local diagnostic switches (the same stack as on AGC: a cube's packed-tail mips rendered per face are not seen by the cube's sampled view; the reflection capture filters a clear value (High on Life PPSA15388, black lighting) #4736 and High on Life (PPSA15388): occlusion-query results hide walls and props in view (all fine when every query reports visible) #5488), so dirty is true. One of those local switches opens the trace window when a file appears, so the window starts at the portal instead of at a fixed time. The scope names and accounting are main's.
trace_dropped is true. Queue worker 0x0 filled its buffer after about 6.4 s, so the per-scope shares and per-draw numbers above come from those first 6.4 s (31 presents). The presents, frame times, GPU busy and worker busy are from the summary line and cover the whole window.
Per frame in that span: 1,279–1,390 draws, Driver.Draw 99–193 ms, frame 166–272 ms.
GPU track: batch 2.85 s, draw 0.96 s, copy 0.22 s over the window.
On the CPU side (perf at the same spot), the queue worker's samples are spread thin. No function takes more than about 5 %; the biggest are BdaResources, Evaluator::EvaluateWide, InPlaceReads, DrawCopiedWriters and CompletePendingCpuWrites, plus about 9 % in operator new.

Summary line:

{"presents":49,"frame_ms":{"p50":179.155,"p90":271.969,"p99":436.538,"max":436.538},"gpu_busy_ms_per_present":59.257,"worker_busy_pct":{"queue worker 0x0":99.316,"queue worker 0x20":99.257},"top_phases_ms_per_frame":{"Driver.Packet":410.599,"Driver.Packet.memory_wait":196.982,"Driver.Packet.draw":140.028,"Driver.Draw":139.753,"Driver.Draw.draw_and_resource_release":95.453,"Graphics.Draw":95.182,"Graphics.Draw.draw_and_resource_release":79.73,"Resources.Complete":47.244},"trace_dropped":true}

Tested and written by Claude (AI assistant) on a contributor's machine.

More High on Life (PPSA15388, UE 4.27) data, on current main this time. It points at caches whose keys almost never repeat in this title.

Setup. main 718ae1355 plus #5156, #5494, #5232 and local diagnostics. The occlusion path is the CPU one from #5213. Warm caches.

1. Frame trace on an open outdoor map, 20 s (APS5_TRACE_SECONDS, nothing dropped), 10 s standing still, then 10 s turning:

	Standing	Turning
FPS	4.2	3.8
draws per frame	~1,100	~1,130
`Driver.Draw` per draw	160 µs	186 µs
`Graphics.Draw.validate`, share of queue worker 0x0	23.8 %	30.5 %
`Resources.Complete`	17.9 %	8.6 %

Graphics.Draw.validate runs about 33 times per frame. Its median is 28 µs, but the 90th percentile is 2 ms and the maximum is 136 ms, so a few calls per frame take most of that share. Queue worker 0x0 is 95 % busy, and the GPU is mostly idle.

2. APS5_PROFILE_DRAW=1, home base, 10 s windows, standing and turning:

Cache, per 10 s	Result
validation memo	81,405 hits, 0 misses (0–6 while turning)
draw resource cache (`[rescache] draws`)	76,456 hits, 1,469 misses
draw cache (`[draw-cache]`)	77,681 lookups, 77,587 "no entry", 94 hits. 47 inserts, 477 entries, no evictions
dispatch resource cache	698 hits, 58,929 misses. Miss churn: `GuestBuffers 58761 (V# word 58761/0/0/0)`

So:

The validation memo isn't the problem. The expensive validate calls in the trace are the step itself on a few draws, not memo misses.
The dispatch cache misses almost every time, and the churn line names V# word 0, the buffer base. UE4 allocates per-frame constant data from a ring, so the same dispatch sees a new buffer address each frame, and a key with that address never repeats.
The draw cache isn't full and evicts nothing, but a key is seldom seen a second time (47 inserts per 10 s against ~78,000 lookups). That's consistent with keys that include per-frame addresses too, though the log doesn't say which words differ for this cache.

Per draw packet ([draw] driver phases, standing): capture 9.7 µs, recompile 6.3, decode 3.0, Graphics::Draw 61.6, total 84.8 µs. A draw-cache hit skips decode. Leaving ring-allocated base addresses out of the key, or treating them as data, looks like the lever for UE4 titles. A record thread like APS5_MT_RECORD would then have less to move. #4943 and #5656 look aimed at exactly this draw-cache case (moved user-data pointers, user words a stage doesn't read), so I'll run them at the same spot next and post the hit rates.

Details

Linux, RTX 4090 (driver 615.78.08), i9-14900K.
The trace window opens on a trigger file (local switch), so it starts on the map rather than at a fixed time. APS5_TRACE_CAPACITY (local) raised the per-thread buffer so 20 s fit.
Earlier traces from this title on older main are in my comment above. Per draw was about 98 µs there, in a scene with more cheap draws.
With the shader cache warm, the home base runs 9–10 FPS standing and about 5 FPS while strafing, and the outdoor map 3.5–4.
Full [rescache] / [draw-cache] / [draws] lines for both windows are available if useful.

Tested and written by Claude (AI assistant) on a contributor's machine.

NOTE: EasyPS5 is ingame for High on Life now (just severe performance issues)
But I have not had a single crash in 30 runs.

@MarcZX100 on trace_dropped=true: I read the traces back. The flag is set because the queue-0 worker's event buffer fills early, not because of anything specific to APS5_MT_RECORD. The summary numbers aren't affected.

TraceThread::DefaultCapacity is 262,144 slices per thread. In this scene the queue-0 worker writes about 80,000 slices a second, so its buffer is full about 3.3 s into the 30 s window. After that point the worker has no slices in the trace. The presenter and gpu tracks run to the end of the window.
The same thing happens on main. I see it in all 33 traces of this scene, flag on and flag off. Last worker slice, in seconds into the window:

trace	worker slices	last worker slice	presenter / gpu last slice
`main` `a0f5916`	262,050	3.32 s	29.97 / 30.01 s
`main` `665ad7d` (6 runs)	262,046–262,050	3.20–3.27 s	~30 s
branch, flag off (e3340a220)	262,048	3.36 s	29.99 / 30.02 s
branch, `APS5_MT_RECORD=1` (e3340a220)	261,973	3.90 s	29.98 / 30.00 s

The summary line isn't cut short. p50/p90/p99, gpu_busy_ms_per_present, worker_busy_pct and the phase totals come from present timestamps and per-thread totals. Those keep accumulating after the slice buffer is full. The flag would also be set if the 512-entry totals table overflowed. That's very unlikely here, because each thread records only 22–31 distinct scopes in these traces. Still, the summary can't tell those two cases apart, and that's part of what I filed.
One limitation of my branch: the record thread isn't bound to the trace, so its time appears only in the [mtrecord] counters and not as its own track. I'll bind it before the next measurements.

Filed as #5786, with a proposed fix: per-thread drop details in the summary, a marker where a track ends, and an opt-in APS5_TRACE_EVENTS buffer size. I'm preparing a PR for it.

The traces are about 3 MB each gzipped. I can attach the main and the flag-on/flag-off ones if that helps.

The other two points still stand: the same-address deferred-label cleanup race, and the write checker and frame-dump comparison on the rebased code. I'll report on both before proposing a split.

Follow-up on the open items from my last comment, all at 1e9e3ca68 (Hades II hub, RTX 3080 Ti, NVIDIA 610.57.04, Linux).

Label race (stamp-based cleanup). The new agc_driver_mt_record_label_stamps test fails on the commit before the fix (e3340a220, with a one-line forwarder so the test compiles: "the cleanup of the first label dropped the second label's queued entry") and passes with it. All 11 agc_driver_mt_record* tests ran 300 times each serially and 300 times each with -j8, no failure.

Write checker. Three hub runs with APS5_MT_RECORD=1 APS5_MT_RECORD_CHECK=1, about 4 minutes each in the hub, 4.0 to 5.4 million record jobs each: every run ends with uncovered=0, wildcard-ranges=0, and no assert. Scope: the checker only sees writes that go through the observer, which here is about 9 to 12 thousand per run, mostly storage textures. Label notes, writebacks and opaque-stage writes are excluded by design, so this says no observed write fell outside its prediction, not that every job was checked.

Frame dumps. Two runs with the flag and two without, APS5_DUMP_FRAMES every 60 presents at quarter scale, compared from the first hub frame on. Each frame with the flag is matched to the closest frame without it; the worst match is 33.0 dB, against 32.7 dB between the two runs without the flag. That rules out gross corruption only: a small wrong region would stay above that threshold, and the title screen is not compared.

Heap corruption at exit. Not reproduced. In our own logs "double free" appears twice, once with APS5_MT_RECORD and once in a run from before it existed. An ASan + UBSan build ran the 11 agc_driver_mt_record* tests 50 times each with no report, but that does not exercise the exit path, and I have not run the game under ASan yet. This stays open.

Separately, there is an intermittent segfault right after GUI.pkg opens, before the title screen, with or without APS5_MT_RECORD. Both cases in this round happened while a build was loading the machine; I have not looked into it further.

The trace drop explanation is now #5786, with the fix in #5813.

Exit crash, follow-up: with glibc heap checks on (libc_malloc_debug.so, glibc.malloc.check=3), two hub runs with APS5_MT_RECORD=1 exited cleanly on SIGTERM, so the double free or corruption abort is still not reproduced. A third run with MALLOC_PERTURB_ crashed at exit in the audio mixer, reading a pointer from freed memory while exit() was running static destructors: #5864. That is a different failure, and nothing in it involves APS5_MT_RECORD, but it may be how the double free happens too; I could not confirm it, because the earlier aborts left no stack.

@Raghav314

Same-session comparison with #1201 (pipelined queue-0 draw commits), Hades II hub, same machine and method as above (mean of the window-title FPS over a 60 s hold, three interleaved runs per arm, no profiling variables):

Build	Mean FPS
this change at `1e9e3ca68`, flag off	34.1
this change, `APS5_MT_RECORD=1`	52.2
#1201 + @Raghav314's fixes (`e19e113`), flag off	36.0
#1201, `APS5_PIPELINED_DRAWS=1`	57.7

Both reach the same scene at a similar gain, #1201 a little higher. Note for anyone measuring either: APS5_PROFILE_DRAW=1 together with APS5_DRAW_PREPARE_AHEAD=2 costs this change 7 to 11 FPS here (27.0 / 41.4 with both set), more than #1201 loses with the same environment.

Since #1201 already covers this ground and is further along in review, I'm going to help it land instead of opening the PRs this issue promised. Per-run numbers and the ordering cases I found in #1201 are in #1201 (comment). I'll keep this issue for the Hades II data and close it once #1201 is merged.

High on Life data point on current main (760ffa683, plus #5828, #5509, #5778 and #5821, none of which touch draw cost). Same machine and spot as my earlier numbers (top of the stairs facing the portal and TV), with the shader cache warm (only hits, no misses in the window):

Head	Facing the portal and TV	Panning in the house
`718ae1355`-based stack (my earlier posts here)	3.6–3.9 FPS	—
`760ffa683` + the PRs above	4.5–6.3 FPS just after loading, a steady 8.1 FPS once texture streaming settles	7.3–8.7 FPS

So about 1.5–2× faster at that spot, which lines up with the draw-reuse merges since then (#494, #5906, #6093 and others). One thread still sits at about 90% of a core.

Details

Linux (CachyOS), RTX 4090, i9-14900K. Warm cache: the cold first run of a new head compiles hundreds of shaders and drops to 0.5 FPS while panning, so cold numbers aren't comparable.
On the main menu, the old and new stacks are the same, about 30–43 FPS. Moving the mouse drops the menu from about 40 to 22–29 FPS, and it recovers as soon as the mouse stops. I haven't separated the game's hover redraws from input handling yet.

Tested and written by Claude (AI assistant) on a contributor's machine.

Navigation Menu

Repository navigation

perf: Hades II hub is bound by the queue-0 packet worker; recording draws on a second thread takes ~30 to ~48 FPS locally (findings, work in progress) #5485

Title and scene

What is slow or what changed

Status

Design

Not done and not claimed

Related

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

perf: Hades II hub is bound by the queue-0 packet worker; recording draws on a second thread takes ~30 to ~48 FPS locally (findings, work in progress) #5485

Description

Title and scene

What is slow or what changed

Status

Design

Not done and not claimed

Related

Activity

eliyarson commented on Oct 13, 2026

MarcZX10 commented on Oct 13, 2026

Tamalero commented on Oct 14, 2026

Tamalero commented on Oct 14, 2026

eliyarson commented on Oct 14, 2026

eliyarson commented on Oct 14, 2026

eliyarson commented on Oct 14, 2026

eliyarson commented on Oct 14, 2026

Tamalero commented on Oct 15, 2026

Metadata

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Issue actions