Skip to content

perf: RDR gameplay at 2.6 FPS, single queue worker CPU-bound #5345

Open

Description

@bcortezf

Title and scene

PPSA30528, after the intro: Armadillo, idle in-game, 3840x2160. Capture window APS5_TRACE_SECONDS=100:5 from the first present, input sequence: menu > Play > Normal.

What is slow or what changed

Frame p50 378 ms (2.7 FPS) at commit 981acf21ed70. Menus run at 60 FPS; the first seconds of the cutscene run at ~10 FPS.

  • queue worker 0x0 is busy 98.9% of the window; the process uses ~1.5 of 16 logical cores and the 3D engine of the GPU is at ~37%.
  • Driver.Packet takes 383 ms per frame (Driver.Draw 354, of which Graphics.Draw 178 and Driver.Draw.shader_compile_and_link 1 25).
  • About 3,900 to 4,700 draw packets per frame at ~61 us each (APS5_PROFILE_DRAW run: Graphics::Draw 30 us, decode 5, capture 7, recompile 6.5, key/lookup/validate 6.7).
  • The draw cache (APS5_DRAW_CACHE_ENTRIES, default 4096) hits 98% in menus and the cutscene but 0 to 6% in gameplay (131k lookups per 10 s, 131k inserts, 300k to 730k evictions). The register key includes the user-data SGPR words (RegisterStateKey in DrawRegisterKey.cpp), which differ every frame.
  • With APS5_DRAW_CACHE_ENTRIES=65536 the cinematic phase reaches 72 to 85% hits but gameplay stays at 4 to 8% and costs 81 us per packet (107 MiB).

Not compared against another commit: this is a report of a slow scene.

Threads (ms per frame)

thread busy wait untraced in slices < 20 us largest
queue worker 0x0 238.9 (63 %) 0.0 (0 %) 140.0 213.6 Driver.Packet 238.7, Driver.Completion 0.1
presenter 0.4 (0 %) 43.4 (11 %) 335.1 0.1 Driver.Present 43.8
gpu 160.4 (42 %) 0.0 (0 %) 218.5 0.0 batch 160.4

Largest slices (ms per frame, inclusive, all threads): Driver.Packet 238.7, Driver.Packet.draw 232.1, Driver.Draw 231.1, batch 160.4, Driver.Draw.draw_and_resource_release 106.7, Graphics.Draw 105.4, Graphics.Draw.draw_and_resource_release 78.9, Driver.Draw.shader_compile_and_link 63.3, Driver.Present 43.8, Driver.Present.render_fence_wait 43.4

Machine: NVIDIA GeForce RTX 4070 SUPER, driver 616.64, Windows 11 (10.0.26200), 16 logical CPUs.
AI-assisted analysis: yes.

Summary lines

{"commit":"981acf21ed70","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TRACE_SECONDS":"100:5"},"gpu":"NVIDIA GeForce RTX 4070 SUPER","driver":"NVIDIA 616.64","os":"Windows 10.0.26200","resolution":"3840x2160","window":{"spec":"seconds 100:5","first_present":1757,"ms":5303.468},"presents":14,"frame_ms":{"p50":377.957,"p90":383.301,"p99":385.044,"max":385.044},"gpu_busy_ms_per_present":162.657,"worker_busy_pct":{"queue worker 0x0":98.868},"top_phases_ms_per_frame":{"Driver.Packet":374.291,"Driver.Packet.draw":347.668,"Driver.Draw":346.172,"Driver.Draw.draw_and_resource_release":175.450,"Graphics.Draw":173.889,"Graphics.Draw.draw_and_resource_release":149.509,"Driver.Draw.shader_compile_and_link":122.328,"Shader.DrawStage":91.928},"trace_dropped":true,"trace":"aps5-trace-981acf21ed70-18020.json.gz"}

Traces

aps5-trace-981acf21ed70-18020.json.gz

Digest

13 frames over 4925.8 ms (no summary line found)

Slowest frames (largest slices inside each, inclusive)

  • present 1758: 385.0 ms at 378 ms: Driver.Packet (queue worker 0x0) 363.6, Driver.Packet.draw (queue worker 0x0) 353.3, Driver.Draw (queue worker 0x0) 351.8, Driver.Draw.draw_and_resource_release (queue worker 0x0) 163.3
  • present 1759: 383.3 ms at 763 ms: Driver.Packet (queue worker 0x0) 361.7, Driver.Packet.draw (queue worker 0x0) 350.9, Driver.Draw (queue worker 0x0) 349.4, Driver.Draw.draw_and_resource_release (queue worker 0x0) 162.6
  • present 1762: 380.4 ms at 1902 ms: Driver.Packet (queue worker 0x0) 358.5, Driver.Packet.draw (queue worker 0x0) 347.7, Driver.Draw (queue worker 0x0) 346.2, Driver.Draw.draw_and_resource_release (queue worker 0x0) 160.1
  • present 1765: 379.9 ms at 3037 ms: Driver.Packet (queue worker 0x0) 236.3, Driver.Packet.draw (queue worker 0x0) 231.5, Driver.Draw (queue worker 0x0) 230.4, batch (gpu) 152.8
  • present 1767: 379.2 ms at 3792 ms: batch (gpu) 154.3, Driver.Present (presenter) 40.3, Driver.Present.render_fence_wait (presenter) 40.1, Vulkan.Retire (presenter) 40.1

Longest waits

  • Driver.Present.render_fence_wait (presenter) 42.6 ms at 763 ms, present 1759
  • Driver.Present.render_fence_wait (presenter) 41.8 ms at 3038 ms, present 1765
  • Driver.Present.render_fence_wait (presenter) 41.7 ms at 4171 ms, present 1768
  • Driver.Present.render_fence_wait (presenter) 40.3 ms at 0 ms, present 1757
  • Driver.Present.render_fence_wait (presenter) 40.1 ms at 4548 ms, present 1769
  • Driver.Present.render_fence_wait (presenter) 40.1 ms at 3792 ms, present 1767
  • Driver.Present.render_fence_wait (presenter) 40.1 ms at 2282 ms, present 1763
  • Driver.Present.render_fence_wait (presenter) 39.8 ms at 1525 ms, present 1761
  • Driver.Present.render_fence_wait (presenter) 39.7 ms at 4926 ms, present 1770
  • Driver.Present.render_fence_wait (presenter) 39.7 ms at 2660 ms, present 1764

Worker stacks

No response

Capture

  • The caches were warm (the scene ran once and the title was restarted)
  • No other APS5_TRACE_* or APS5_PROFILE_* switch was set and the log was not redirected
  • Captures compared here come from the same machine, scene and settings

Activity

  1. MarcZX10 commented on Oct 13, 2026

    @MarcZX10
    Contributor

    I checked the current-main cache path and the attached trace. Simply removing user-data SGPRs from the draw key would risk reusing stale draw inputs: RegisterStateKey includes selected user words (DrawRegisterKey.cpp); a key hit reuses the cached DrawDecode and its programs (Draw.cpp); and decode copies queue user-data registers into each program (DrawDecode.cpp). Those words can carry the changing resource addresses described here.

    A safe cache improvement likely needs to separate reusable decode/pipeline state from per-draw user-data refresh, then verify the refreshed resources and compare the same scene before/after. The attached trace digest covers 13 frames in about 4.9 s and its summary says samples were dropped, so a complete comparable capture would help establish the baseline once a change is available.

  2. AlxcBTW commented on Oct 13, 2026

    @AlxcBTW
    Contributor

    A parallel data point from Sword of the Sea (PPSA25344, UE5) that may help narrow this down. Our gameplay is also queue-worker-0 bound (~130 ms of serial q0 CPU per 148 ms frame), with the same cache picture on the dispatch side: the ahead helper sees ~91 % new dispatch keys every frame (50,308 resolved per 10 s = 4,395 hits + 45,853 inserted), so recipes are attached and almost never reused.

    In our case, the churn isn't the user-data ring words but V# word 0 (buffer base addresses) inside the descriptor tables: [rescache] miss churn ... GuestBuffers 134118 (V# word 133354/0/764/0). A ring-pointer masking experiment (keys with the user-data ring words masked out) produced only ~210 moved hits per 10 s out of ~80k masked keys. If RDR's gameplay keys churn on table contents rather than on the SGPR words themselves, widening the cache won't help either. That would match your 65,536-entry run, where gameplay stayed at 4–8 %. It might be worth logging which key component differs on a miss before changing the key.

  3. MarcZX10 commented on Oct 13, 2026

    @MarcZX10
    Contributor

    Thanks, this is a useful second data point. Your Sword of the Sea result makes descriptor-table contents a concrete candidate and shows why masking the ring pointers or increasing cache capacity alone would not establish a fix.\n\nI checked the current key paths: compute DispatchContentKey excludes ShaderData/FlattenedSrt words when template refresh is enabled, but ShaderResources::ContentKey still includes guest-buffer descriptors; the draw-register cache in my earlier note is a separate key and reuse path. So I would keep these observations distinct until the RDR trace identifies which cache owns the expensive misses.\n\nThe discriminating next measurement is a bounded miss breakdown by key component (shader identity, registers, guest-buffer descriptor words, and other resource fields), with per-component changed counts and no raw guest addresses in logs. That should tell us whether the two titles share descriptor churn or whether RDR is spending time elsewhere in queue-worker work. I have not changed cache semantics based on these counters alone.

  4. AlxcBTW commented on Oct 13, 2026

    @AlxcBTW
    Contributor

    Agreed, keep them separate until the trace says which cache owns the misses. The bounded per-component miss breakdown is something I need for Sword of the Sea anyway: shader identity, registers, guest-buffer descriptor words, other resource fields, changed counts only, no raw addresses. If you're not already writing it, I'll put it up as a small diagnostic PR behind APS5_PROFILE_DRAW, covering both the draw-register cache and ShaderResources::ContentKey, so both titles can run the same counters. Say so if you'd rather do it yourself.

  5. bcortezf commented on Oct 13, 2026

    @bcortezf
    ContributorAuthor

    RDR (PPSA30528) adds a data point on which cache owns the misses. Per 10 s in gameplay: 136k draw packets, all drawn, at ~61 us each on the worker, against ~728 dispatches (~4% of worker time). The draw-register cache sits at 0–6% hits (131k “no entry” / 10 s); with 65,536 entries it only reaches 4–8% and costs more per packet (81 us), consistent with keys that never repeat rather than capacity. So here the expensive misses are in the draw-register path, not the dispatch cache.

    @AlxcBTW, go ahead with the diagnostic PR; I’ll run it on RDR and post the per-component counters, plus a capture without dropped samples.

  6. MarcZX10 commented on Oct 13, 2026

    @MarcZX10
    Contributor

    The new RDR counters clarify the cache to target: the worker spends most of its time in draw packets, and the draw-register cache has 131k no-entry misses per 10 s; dispatches account for only about 4% of worker time. I opened #5364 for an opt-in, bounded miss breakdown on that draw-register path. It compares consecutive lookups for the same shader set and reports changed register groups without logging raw values or addresses.\n\nAlxcBTW’s separate Sword of the Sea observation points at ShaderResources::ContentKey, which #5364 does not instrument. That is a useful complementary follow-up; keeping it focused on the resource-content-key path would avoid duplicating the draw-register part. The dropped-sample-free capture from RDR should help tell how much of the worker cost these miss counters explain.

  7. JAB-dev commented on Oct 14, 2026

    @JAB-dev
    Contributor

    A third title with the same picture: Besiege (PPSA20313), main at a0f5916 plus #5364, Windows 11, RTX 4070 SUPER, 1080p, 160 s after launch. In steady state, per 10 s, the draw-register cache sees about 80,000 lookups and about 78,000 misses (2.5% hits). The tracer's classification of the misses, summed over each 10 s with a local counter on top of it:

    • user-data registers only changed: about 55,000 (70%)
    • stable registers and user-data registers: about 10,500
    • stable registers, user-data registers and shader/device identity (a different shader pair bound): about 12,400 (16%)
    • stable registers only: about 500

    APS5_DRAW_CACHE_ENTRIES=65536 raises the hits to about 21% on Besiege and the frame rate does not change (17.0 against 16.8 FPS). #5407 (bypass under 5% hits) gives +4% there (17.5 against 16.9 FPS), and #4943 (moved user-data pointers) gives -3% to -5%: its alias path reports 2 to 3 hits through a relocated entry per 125,000 alias lookups.

  8. MarcZX10 commented on Oct 14, 2026

    @MarcZX10
    Contributor

    Thanks, the Besiege measurements add a useful third title: most misses on this route are user-data-only changes, while a larger table increased hit rate without improving frame rate and the bypass gave a small gain. That supports keeping the #5364 tracer narrowly diagnostic; it does not establish a universal cache-size or bypass threshold. The separate ContentKey observation still merits its own measurements.

  9. bcortezf commented on Oct 14, 2026

    @bcortezf
    ContributorAuthor

    Correction to the scene of this report, and what changes.

    The capture window used here (APS5_TRACE_SECONDS=100:5, Play at 45 s, Normal at 70 s) falls inside the intro cutscene at the Blackwater dock, not at Armadillo as the title section says. That is also why draws per frame varied between runs (2.6k to 3.5k). Gameplay at Armadillo station starts at about 74 s if the cutscene is skipped by holding cross.

    So the “queue worker is the limit” conclusion holds for the cutscene. In gameplay it does not: on main + #494 + #1193 + #1202 + #5216, Armadillo reads 3.99 FPS with the GPU busy 249 of 251 ms per frame (GPU-bound at 3840x2160), the draw pipeline thread at 225 ms and the worker at 186 ms, about 5.5k draws per frame. I will track the gameplay case separately.

    Two smaller notes:

    In the cutscene, with the pipeline on, one Recorder.Sync of 46 to 59 ms per frame sits on the draw thread: Revalidate > cachedTexture > EqualsCommitted > FlushForAccess > SyncThrough > Sync. A cached texture the GPU wrote this frame is revalidated by a CPU byte compare, which drains the GPU. That bounds what the pipeline can gain here.
    My earlier “neutral on top of #494” for #5216 came from a textual merge only. As noted on #494, the admission rule keeps a shape whose keys never repeat from getting an entry, so that run does not say anything about data hits.

  10. parl0v commented on Oct 14, 2026

    @parl0v
    Contributor

    A second title for the key question from #5408: PPSA25344 (Sword of the Sea, UE5), title screen, main f0854887d + #5364, APS5_TRACE_RESOURCE_KEY_MISSES=1, RTX 3060, 300 s.

    [keymiss] resource-content dispatch (10 s): misses 6810; differing: layout 0, V# word0 6810, V# word1 1054, V# word2 659, V# word3 0, image 1253, sampler 0, shader-data 0, other 0, draw target/index 0; no-candidate 0; identical 0; not comparable 0
    [keymiss] resource-content draw (10 s): misses 13; differing: layout 0, V# word0 0, V# word1 0, V# word2 0, V# word3 0, image 4, sampler 0, shader-data 0, other 0, draw target/index 0; no-candidate 0; identical 9; not comparable 0
    
    • Dispatch misses: V# word 0 (buffer base) differs in all of them (~6,800 per 10 s, steady across the run). Word 1 differs in 13–15 %, word 2 (num_records) in ~10 %, images in 18 %. Layout, word 3, sampler and shader data never do. So at least 57 % of the misses change nothing but base addresses.
    • Draw misses are negligible here (13–14 per 10 s, 9 identical).

    For SotS, masking the base address out of the dispatch resource-content key is the component worth trying. That's the same direction as the RDR question here, if RDR's trace shows word 0 too.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions