Skip to content

perf(shader): replay an image table column's decoded records when its content recurs - #12051

Closed
SleglJan wants to merge 6 commits into
boykopovar:mainfrom
SleglJan:perf/shader-column-memo
Closed

SleglJan wants to merge 6 commits into
boykopovar:mainfrom
SleglJan:perf/shader-column-memo

Conversation

@SleglJan

@SleglJan SleglJan commented Oct 27, 2026 •

Copy link
Copy Markdown
Contributor

What

When the result memo misses and the table resolution reuse misses too, an image table column is resolved from its records: each record's decode is looked up in the decode memo (one global mutex per record), null descriptors are checked, each element is hashed and placed, and the map is written. On a scene with large tables the same column content comes back on most of these misses, read through image resources that agree in every field but the descriptor source, the first use and the table index. This PR keeps a column's decoded records and replays them when the same content recurs:

  • The memo key is the column's content (its codes and words, hashed once per snapshot block by SharedValues::Hash), its key count and its records-outside-the-snapshot state, plus the usage: the image resource without its descriptor source, first use and table index, its runtime mode list and the reducing-sampler state. Columns of at least 64 keys, in the runtime resolution; the registration-time Populate path does not use the memo.
  • A hit replays the column's records and elements into the resolution: the elements are placed through the same dedup as a fresh decode, and the poison records and the direct-sampler mask are recomputed from the current resource. A miss decodes as before and records the column.
  • The memo holds one entry per content and usage and references the snapshot block it missed on, so a content's codes and words are not copied per entry; entries evict by least recent use under a word budget (APS5_TABLE_COLUMN_MEMO_WORDS, default 33,554,432 words of estimated host memory) and an entry count of 4,096.
  • The column memo report of APS5_PROFILE_DRAW counts hits, misses never seen and misses whose content changed; the last two keep one slot per usage (up to 131,072) under a mutex, only while APS5_PROFILE_DRAW is set.
  • APS5_NO_TABLE_COLUMN_MEMO=1 resolves every column from its records as before.
  • APS5_VERIFY_TABLE_COLUMN_MEMO=1 also resolves every replayed snapshot from its records and compares the map, elements, samplers, poison records and faults; the first twenty differences are printed and the count goes into the report line.
  • APS5_TABLE_COLUMN_MEMO_DIAG=1 extends that line with the distinct contents and usages of the window and, for the changed-content misses whose previous column is still pinned, the keys whose descriptor differs and the 1,024-key chunks holding them; it takes effect only with APS5_PROFILE_DRAW.
  • The four switches change memo behaviour only, never the recompiled output, so they are listed as neutral to the shader disk cache key (NeutralSwitches).
  • Tests: agc_shader_table_column_memo (a replayed resolution equals a fresh one across a second variant, another first use and another descriptor source; a changed mode list or decode input misses; the hit and miss counters), with the verified, off, reported, diagnosed and diagnosed-unreported variants. dc1e7e5 adds agc_shader_table_column_memo_placement, _placement_before and _placement_off (thirty selected single-record tables and one merged column in one resolution, the merged column resolved after or before them; its narrowed domain binds its 65 keyed records and record 0, thirty of its records equal the selected tables' records and land on the same elements, 66 elements in all, equal to the plain resolution), _evicted_by_count (4,096 distinct contents, then the least recently used entry leaves first, read through hits and misses), _evicted_by_budget (APS5_TABLE_COLUMN_MEMO_WORDS=65536, 200 contents with the first replayed after every insertion: the newest and the first kept, the least recently used evicted) and _oversize_entry (APS5_TABLE_COLUMN_MEMO_WORDS=0x1: nothing kept), and nine _words* registrations (the same column resolved twice per value: kept on the second resolution under unset, 1048576 and 0x100000; the first resolution fails with the variable's message for 0, -1, empty, abc, 12x and a 20-digit overflow).

Related open PRs: #6340, #10193, #7642 and #10256 work on the driver's image table entries and device tables. #7223 (nested image tables through runtime pointers) changes the same resolution loop and adds child tables and the pointers that key them, which this memo does not cover: whichever lands second has to extend the key and the replay to them, or exclude nested columns from the memo. What the second to land changes is proposed on #7223 (#7223 (comment)): keep the pointer-keyed parent column out of the memo (its child tables still go through the resolution as ordinary columns and stay eligible), or key the memo on the child content; the order itself is open with #7223's author.

Tested

CachyOS Linux (kernel 7.2.10), NVIDIA GeForce RTX 3080, driver 615.78.08, AMD Ryzen 9 7950X3D, 64 GB; GCC 16.2.1, CMake 4.4.4.

  • ctest -R "^agc" on this PR at dc1e7e5: 1,073 passed, 10 skipped, 1 failed of 1,084. The one failure, agc_driver_mesh_barycentric_emulation, fails the same way on plain main c547dea on this machine ("AGC graphics: the pixel shader did not emulate barycentrics", NVIDIA 615.78.08).
  • ctest --test-dir build -R "^agc_shader_" -V with ANYPS5_REQUIRE_VULKAN=1, ANYPS5_NO_SHADER_CACHE=1 and VK_INSTANCE_LAYERS=VK_LAYER_KHRONOS_validation: 37/37 on main c547dea, 58/58 on this PR at dc1e7e5 (the 21 extra are the column memo tests). Neither log has was not found but was requested by env var VK_INSTANCE_LAYERS, and neither has a VUID- line.

What this change claims now: the [recompile] Populate time is down on main (171 / 169 / 172 ms per frame against 67 / 69 / 72 in the A/B below); no frame-rate gain on main within the run spread (walk presents per second 0.369 / 0.369 / 0.341 against 0.358 / 0.326 / 0.371); the +11.5 % walk gain below was measured only on the local base and does not reproduce on main.

Capture pair, 007 First Light (PPSA11386), the walk after the resume of the first level: main at the PR's base c547dea (2026-10-28, 12:04 to 12:47 CET) and this PR at its head dc1e7e5 (12:51 to 13:34 CET), same machine and boot, a build and a test run in between, APS5_TRACE_FRAMES=1085:150 on both sides. Not as the form asks: APS5_TRACE_EVENTS=4194304 on both sides, because queue worker 0x0 records about 10,700 events per present here and the default buffer of 262,144 events (docs/dev/BUILD.md) holds about 25 presents; APS5_TRACE_DIR for the output directory; APS5_TIME_SCALE=0.1 and scripted input through APS5_PAD_INPUT_FILE, both visible in the lines' env; and, not visible there, the log written to a file, the NVIDIA shader disk cache on and pointed at a per-run directory copied from a seed run (a 16 GiB size cap, its cleanup skipped), the shader disk cache and the journal warm from that seed run rather than from a restart, and the title in a scope with swap turned off. No other APS5_TRACE_* switch and no APS5_PROFILE_* switch is set. Both sides the same way: main from its own seed; this PR from a copy of the PR's seed with main's journal records (the journal header's source version set to the PR's), so the journal records and the NVIDIA cache are identical on both sides while the shader disk cache is each side's own, the shader cache source versions being 41abaa3b8f8b9199 on main and 75f9ad0bc594cabf on this PR. The title executable is unedited.

{"commit":"c547deaacb62","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TIME_SCALE":"0.1","APS5_TRACE_DIR":"<path>","APS5_TRACE_EVENTS":"4194304","APS5_TRACE_FRAMES":"1085:150"},"gpu":"NVIDIA GeForce RTX 3080","driver":"NVIDIA 615.78.08","os":"Linux 7.2.10-1-cachyos","cpu":"AMD Ryzen 9 7950X3D 16-Core Processor","cpu_threads":32,"memory_mib":63428,"title_id":"PPSA11386","title":"007 First Light","content_version":"01.018.000","resolution":"3840x2160","window":{"spec":"frames 1085:150","first_present":1085,"ms":418164.785},"presents":150,"frame_ms":{"p50":2711.721,"p90":3216.898,"p99":3992.038,"max":4422.742},"gpu_busy_ms_per_present":477.688,"worker_busy_pct":{"queue worker 0x0":99.931,"queue worker 0x20":99.869,"queue worker 0x28":99.746,"queue worker 0x30":99.799,"queue worker 0x38":82.472},"top_phases_ms_per_frame":{"Driver.Packet":13395.303,"Driver.Packet.memory_wait":9050.250,"Driver.Packet.dispatch":2341.595,"GpuMutex.wait.hook":2314.830,"Driver.Dispatch":2091.833,"Resources.Complete":1952.857,"Driver.Packet.draw":1763.494,"Driver.Draw":1762.767},"trace_dropped":false,"trace":"aps5-trace-c547deaacb62-2.json.gz"}
{"commit":"dc1e7e5695ab","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TIME_SCALE":"0.1","APS5_TRACE_DIR":"<path>","APS5_TRACE_EVENTS":"4194304","APS5_TRACE_FRAMES":"1085:150"},"gpu":"NVIDIA GeForce RTX 3080","driver":"NVIDIA 615.78.08","os":"Linux 7.2.10-1-cachyos","cpu":"AMD Ryzen 9 7950X3D 16-Core Processor","cpu_threads":32,"memory_mib":63428,"title_id":"PPSA11386","title":"007 First Light","content_version":"01.018.000","resolution":"3840x2160","window":{"spec":"frames 1085:150","first_present":1085,"ms":436633.103},"presents":150,"frame_ms":{"p50":2882.072,"p90":3378.460,"p99":4499.485,"max":7033.048},"gpu_busy_ms_per_present":497.524,"worker_busy_pct":{"queue worker 0x0":99.946,"queue worker 0x20":99.900,"queue worker 0x28":99.815,"queue worker 0x38":82.658,"queue worker 0x30":99.844},"top_phases_ms_per_frame":{"Driver.Packet":13992.217,"Driver.Packet.memory_wait":9511.346,"GpuMutex.wait.hook":2578.339,"Driver.Packet.dispatch":2452.564,"Driver.Dispatch":2167.295,"Resources.Complete":2116.024,"Graphics.Draw":1816.352,"Driver.Packet.draw":1792.957},"trace_dropped":false,"trace":"aps5-trace-dc1e7e5695ab-2.json.gz"}
  • Digests (tools/trace_digest.py output) and the two traces: pre-release https://github.com/SleglJan/AnyPS5/releases/tag/perf-traces-shader-column-memo on my fork, both files over the 25 MB attachment limit (31.7 and 32.4 MB), sha256 e44ae16fa69649761e15a3f5cd9a394f8089e4a51db7e34c59d2590ff518e6e5 (main) and 22b1ef75f9c6c30a4c75a5552866af2d790655ae1ede305a18e25a1f5e5d1fd7 (this PR).
  • tools/performance_compare.py on the lines: no configuration difference; this PR minus main: frame p50 +170 ms (+6.3 %), p90 +162 (+5.0 %), p99 +507 (+12.7 %), max +2,610 (+59 %), mean frame +123 (+4.4 %), GPU busy per present +20 (+4.2 %); one pair, one run per side. Highest VmHWM 24,371 against 25,134 MiB, both including the trace buffers (seven threads at 160 MiB each, 1,120 MiB, on both sides).
  • Harness validity, under both readings defined in the next bullet: both runs on route with no device faults; collapse cannot be judged on this switch set. Second reading: main's run passes every check readable here (collapse is not readable; peak device memory used 9,550 MiB over the run, 9,042 MiB at the level load, every other figure under its limit), this change's run invalid: it peaks at 9,883 MiB at frame 1,036 (the level load, before the walk and outside the trace window), over our 9,850 MiB limit; its next-highest 1 s sample is 9,782 MiB at frame 1,248. First reading: both invalid, because the staging-shadow refusal lines count as unrecovered refusals there (main 2, its full count; this change 4, a lower bound, four prints per run at most).
  • The A/B on main c547dea with APS5_PROFILE_DRAW=1 and APS5_TRACE_SUMMARY_EVERY=60 (three alternated pairs, 2026-10-27 22:41 to 2026-10-28 03:00 CET, this change at f5cf0db, main at the PR's base c547dea while main itself was 32 merges past it, journals unequal, the cache and swap settings as above): walk presents per second under the first reading, declared before the series (any unrecovered allocation refusal invalid), n = 1 / 1, main 0.341 against this change 0.326; under the later reading, which counts staging-shadow refusal lines as handled and was declared after pair 1's results, which made both its runs invalid only through these lines, while pair 2's first run was running, n = 3 / 3, main 0.369 / 0.369 / 0.341 (mean 0.360) against this change 0.358 / 0.326 / 0.371 (mean 0.352); four of the six runs differ between the two readings, all on that line. [recompile] Populate 171 / 169 / 172 against 67 / 69 / 72 ms per frame. Highest VmHWM per run main 23,651 / 24,614 / 24,036 MiB, this change 24,460 / 25,557 / 23,802 MiB.

The earlier alternated A/B, the same title and walk, measured before this rebase on a local base, not on main: upstream main 5357acd plus #5372 (squashed, with its 662a50b change reverted) and #10423, plus local logging and scripted input, and the title's two feedback-wait limits widened in its executable as described in #6172 (local only). Both sides run with APS5_WRITTEN_SHADOW_MAX_KIB=2048 APS5_NO_WRITTEN_SHADOW=1 APS5_PROFILE_DRAW=1 and a warm shader disk cache from a seed run per side; 2026-10-27, six pairs alternated base / this change, 20 minutes each, the same machine and session.

  • Our run validity rule of that day (a texture-cache admission streak taken as a storage-budget collapse) left this change with 1 valid run of 6 against 5 of 6 for the base, so that rule gives no verdict. No run of the series reached the 512 MiB storage floor, and the lowest storage budgets are equal (base 2,788-3,125 MiB, this change 2,858-3,127 MiB). One synchronous-present pair (APS5_FLIP_INFLIGHT=0) cut the held-entry difference between the sides from 2.09x to 1.29x and showed no streaks, an observation from one pair, with no cause read from it.
  • Second reading, declared after the first four runs, once the first flagged run had shown no slowdown in its streak window, and fixed before the other eight: a run invalid only through the streak counts as valid unless its storage budget reached 512 MiB or its longest streak window ran below 0.90 of its own walk rate; runs with host placements (the exhaustion rule) stay invalid. Base n = 5, this change n = 3.
base this change
walk, presents per second, second reading (base n = 5, this change n = 3) 0.962 (0.933-0.989) 1.073 (1.034-1.106)
walk, presents per second, all six runs per side 0.965 (0.933-0.989) 1.087 (1.034-1.112)
Populate ms per frame, all six 157 (148-170) 50 (48-51)
GPU busy ms per frame, all six 315 (311-317) 313 (309-318)
main menu, presents per second, all six 3.37 (3.31-3.43) 3.40 (3.37-3.49)
title screen reached, s after start, all six 117-118 117-118
  • Walk +11.5 % by the second reading's means and +12.6 % over all six runs per side; every run of this change is above every run of the base. The menus and the boot do not change: the memo's hits are in gameplay, where the big tables recur.
  • Column memo in gameplay: 93.1-93.2 % hits over the six runs of this change (125-132 hits per frame); in the verify run with APS5_VERIFY_TABLE_COLUMN_MEMO=1, 106,481 hits and 7,958 misses over 92 ten-second lines (93.0 %), 29,618 replayed resolutions re-resolved from their records, 0 mismatches. Every miss was a column whose content changed; the memo held 323-402 entries.
  • Level load, two quantities: the 1 s peak of device memory outside the texture caches (the local-base figures) and, for the main series, the 1 s peak of nvidia-smi memory used by all processes between the resume and frame 1,055, with the memory outside the texture caches read at the [gpu] budget line nearest that peak and the title's own device memory as the highest nvidia-smi pmon sample in that window. Local-base series: base 1,033-1,257 MiB against this change 1,206-2,528 MiB outside the caches, with first host placements in 3 of 6 runs against 1 of 6 (Fisher, one-sided, 0.27); the series had one seed per side (its own shader disk cache, frozen NVIDIA cache and journal) and the PR side loaded the smaller journal, so the cause there is not established. On main c547dea, each series in one session, main always from one seed, this change minus main:
series journals commit 1 s peak of memory used, per pair (MiB) outside the caches at the nearest budget line (MiB) title's own device memory, pmon (MiB)
the A/B above, three pairs unequal (this change 215 pipelines, main 175) f5cf0db +809 / +403 / +373 not read not read
three pairs to frame 1,720, 2026-10-28 07:35-11:13 CET shared (175 / 185 / 884.5 MiB) f5cf0db +83 / −434 / +118 −147 / +89 / +1,888 (pair 3's main line 26 s from the peak) −173 / −123 / −14
five pairs stopped at frame 1,100, 13:41-16:30 CET shared dc1e7e5 −214 / +445 / −77 / −541 / +133 +109 / −187 / −511 / +257 / −62 (pair 5's main line 37 s from the peak) +226 / +577 / +184 / +101 / +23
the capture pair above, trace switches, one run per side shared dc1e7e5 +841 (9,883 against 9,042) −574 −9

Over the eight shared-journal pairs the means are main 9,321 against this change 9,260 MiB; without the three-pair series' pair 3 (its main run had six shader disk cache misses) 7 / 7, 9,384 against 9,298. Both groupings, 8 / 8 and 7 / 7, were declared before the five-pair series ran; both include that series' four runs which the same declaration's disk-cache rule makes invalid, and the declaration did not say how to treat them. The sign is not consistent across pairs; the one series with every pair higher on this change is the one with unequal journals. Four of the eight pairs have a run with 4 to 6 misses in the boot, none later (cause not chased); grouped after seeing the data, the four pairs without one give +445 / −541 / +83 / −434 MiB. Host placements by frame 1,055: main in 2 of its 8 shared-journal runs ([bufferpool] at least 3 in one, at least 1 in the other), this change in 3 of 8 ([gpu] at least 3 with [bufferpool] at least 1 in one, [bufferpool] at least 1 in each of the other two); the capture pair: this change [gpu] at least 8, main none.

Checklist

  • Based on current main (main f8f5b24 merged in at c5dcde9, after the results above were posted); no other open PR implements the same functions
  • One topic per PR; follow-ups go in a new PR
  • No comments in code except technical debt
  • Unimplemented paths throw; silent stubs are listed in their library's technical debt file
  • No notes, investigation .md files or images added to the repository
  • New third-party code is a submodule built from source
  • Generic behaviour, not specific to one title
  • Depends on: none; related: feat(shader): resolve nested image tables through runtime pointers #7223 (what the second to land changes, proposed there)
  • Fixes: none
  • Unblocks: none
  • GPUs tested: NVIDIA GeForce RTX 3080, driver 615.78.08, CachyOS Linux 7.2.10
  • AI-assisted: yes (Claude Code)

🤖 Generated with Claude Code

… content recurs

An image table column whose content (codes and words) and key count match a column
any shader resolved before, through an image resource description that agrees in every
field the decode reads, replays that column's decoded records and elements instead of
decoding them again. The memo holds the decoded records per (content, usage) under a
word budget (APS5_TABLE_COLUMN_MEMO_WORDS, default 1<<25), shares one content's codes
and words across compiled variants and across shaders, and evicts by least recent use
when the budget or the entry count is reached.

APS5_NO_TABLE_COLUMN_MEMO resolves every column from its records as before.
APS5_VERIFY_TABLE_COLUMN_MEMO also resolves every replayed snapshot from its records
and counts the resolutions that differ in the column memo report of APS5_PROFILE_DRAW.
APS5_TABLE_COLUMN_MEMO_DIAG extends that report with the distinct contents and usages
of the window and the records that changed between a column's contents. The four
switches change memo behaviour only, never the recompiled output, so they are listed
as neutral to the shader disk cache key.

Tests: agc_shader_table_column_memo, with the verify, off and diagnosed variants.

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
@github-actions github-actions Bot added perf Performance change perf numbers missing perf pull request without a before and after summary line labels Oct 27, 2026
@github-actions

Copy link
Copy Markdown

This pull request is labeled perf, so it needs the summary line of a capture on main and one with the change, from the same title, scene and machine, as the Performance report form asks. Please paste both aps5-summary.jsonl lines, attach the two traces and add the output of tools/trace_digest.py.

@github-actions

github-actions Bot commented Oct 27, 2026 •

Copy link
Copy Markdown

Other open pull requests touch the same code. Merging one will break the other, or both implement the same thing. If this one builds on them, list them in Depends on.

Pull request Conflicting files (lines on main) Same exports Same new files
PR 7223 core/shader/recompiler/Optimization/src/ResourceMaterializer.cpp L1819-1822, L1856-1858, L1915-1917, L1933-1935
PR 7395 core/shader/recompiler/Optimization/src/ResourceMaterializer.cpp L1819-1822, L1856-1858, L1915-1917, L1933-1935
PR 8939 core/shader/recompiler/Optimization/src/ResourceMaterializer.cpp L1819-1822, L1856-1858, L1915-1917, L1933-1935
PR 9457 core/shader/recompiler/Optimization/src/ResourceMaterializer.cpp L1819-1822, L1856-1858, L1915-1917, L1933-1935
PR 9633 core/shader/recompiler/Optimization/src/ResourceMaterializer.cpp L1819-1822, L1856-1858, L1915-1917, L1933-1935
PR 9749 core/shader/recompiler/Optimization/src/ResourceMaterializer.cpp L1819-1822, L1856-1858, L1915-1917, L1933-1935
PR 9790 core/shader/recompiler/Optimization/src/ResourceMaterializer.cpp L1819-1822, L1856-1858, L1915-1917, L1933-1935
PR 9969 core/shader/recompiler/Optimization/src/ResourceMaterializer.cpp L1819-1822, L1856-1858, L1915-1917, L1933-1935
PR 10000 core/libs/prx/libSceAgcDriver/tests/ShaderMemory.cpp L3862
PR 10846 core/shader/recompiler/Optimization/src/ResourceMaterializer.cpp L1819-1822, L1856-1858, L1915-1917, L1933-1935
PR 12616 docs/dev/ENVIRONMENT.md L67

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.

Pull request Shared files not compared
PR 907 core/shader/recompiler/Optimization/src/ResourceMaterializer.cpp
PR 1368 core/libs/prx/libSceAgcDriver/CMakeLists.txt
PR 1395 core/libs/prx/libSceAgcDriver/CMakeLists.txt
PR 2434 core/libs/prx/libSceAgcDriver/CMakeLists.txt
PR 4449 core/libs/prx/libSceAgcDriver/CMakeLists.txt
PR 4472 docs/dev/ENVIRONMENT.md
PR 5021 core/libs/prx/libSceAgcDriver/CMakeLists.txt
PR 5371 core/libs/prx/libSceAgcDriver/CMakeLists.txt
core/libs/prx/libSceAgcDriver/tests/ShaderMemory.cpp
core/shader/recompiler/Optimization/include/Optimization/ResourceMaterializer.hpp
core/shader/recompiler/Optimization/src/ResourceMaterializer.cpp
PR 5609 core/shader/recompiler/ShaderDiskCache.cpp
PR 5925 core/libs/prx/libSceAgcDriver/CMakeLists.txt
core/shader/recompiler/ShaderDiskCache.cpp
PR 6185 core/libs/prx/libSceAgcDriver/CMakeLists.txt
docs/dev/ENVIRONMENT.md
PR 6186 core/libs/prx/libSceAgcDriver/CMakeLists.txt
docs/dev/ENVIRONMENT.md
PR 6187 core/libs/prx/libSceAgcDriver/CMakeLists.txt
PR 6188 core/libs/prx/libSceAgcDriver/CMakeLists.txt
PR 6192 core/libs/prx/libSceAgcDriver/CMakeLists.txt
PR 6209 core/libs/prx/libSceAgcDriver/CMakeLists.txt
PR 6235 core/libs/prx/libSceAgcDriver/tests/ShaderMemory.cpp
PR 6280 core/libs/prx/libSceAgcDriver/CMakeLists.txt
core/shader/recompiler/Optimization/include/Optimization/ResourceMaterializer.hpp
core/shader/recompiler/Optimization/src/ResourceMaterializer.cpp
core/shader/recompiler/ShaderDiskCache.cpp
PR 6300 core/libs/prx/libSceAgcDriver/CMakeLists.txt
PR 6412 core/libs/prx/libSceAgcDriver/CMakeLists.txt
core/libs/prx/libSceAgcDriver/tests/ShaderMemory.cpp
core/shader/recompiler/Optimization/include/Optimization/ResourceMaterializer.hpp
core/shader/recompiler/Optimization/src/ResourceMaterializer.cpp
core/shader/recompiler/ShaderDiskCache.cpp
PR 6481 core/libs/prx/libSceAgcDriver/CMakeLists.txt
PR 6488 core/libs/prx/libSceAgcDriver/tests/ShaderMemory.cpp
core/shader/recompiler/Optimization/src/ResourceMaterializer.cpp
core/shader/recompiler/ShaderDiskCache.cpp
PR 6743 core/libs/prx/libSceAgcDriver/CMakeLists.txt
PR 6808 core/libs/prx/libSceAgcDriver/CMakeLists.txt
PR 6924 core/shader/recompiler/ShaderDiskCache.cpp
docs/dev/ENVIRONMENT.md
PR 6970 core/shader/recompiler/ShaderDiskCache.cpp
PR 7275 core/libs/prx/libSceAgcDriver/CMakeLists.txt
PR 7449 docs/dev/ENVIRONMENT.md
PR 7457 core/libs/prx/libSceAgcDriver/CMakeLists.txt
docs/dev/ENVIRONMENT.md
PR 7464 core/libs/prx/libSceAgcDriver/CMakeLists.txt
PR 7514 core/libs/prx/libSceAgcDriver/CMakeLists.txt
docs/dev/ENVIRONMENT.md
PR 7604 core/libs/prx/libSceAgcDriver/CMakeLists.txt
docs/dev/ENVIRONMENT.md
PR 7642 core/libs/prx/libSceAgcDriver/CMakeLists.txt
core/libs/prx/libSceAgcDriver/tests/ShaderMemory.cpp
core/shader/recompiler/Optimization/include/Optimization/ResourceMaterializer.hpp
core/shader/recompiler/Optimization/src/ResourceMaterializer.cpp
core/shader/recompiler/ShaderDiskCache.cpp
docs/dev/ENVIRONMENT.md
PR 7684 core/libs/prx/libSceAgcDriver/tests/ShaderMemory.cpp
core/shader/recompiler/Optimization/src/ResourceMaterializer.cpp
core/shader/recompiler/ShaderDiskCache.cpp
PR 7922 docs/dev/ENVIRONMENT.md
PR 8004 core/libs/prx/libSceAgcDriver/tests/ShaderMemory.cpp
docs/dev/ENVIRONMENT.md
PR 8014 core/libs/prx/libSceAgcDriver/CMakeLists.txt
PR 8484 core/libs/prx/libSceAgcDriver/CMakeLists.txt
docs/dev/ENVIRONMENT.md
PR 8542 core/libs/prx/libSceAgcDriver/CMakeLists.txt
docs/dev/ENVIRONMENT.md
PR 8592 core/libs/prx/libSceAgcDriver/CMakeLists.txt
PR 9012 docs/dev/ENVIRONMENT.md
PR 9020 core/libs/prx/libSceAgcDriver/CMakeLists.txt
core/libs/prx/libSceAgcDriver/tests/ShaderMemory.cpp
PR 9335 core/libs/prx/libSceAgcDriver/CMakeLists.txt
core/libs/prx/libSceAgcDriver/tests/ShaderMemory.cpp
PR 9345 docs/dev/ENVIRONMENT.md
PR 9356 core/libs/prx/libSceAgcDriver/tests/ShaderMemory.cpp
core/shader/recompiler/ShaderDiskCache.cpp
docs/dev/ENVIRONMENT.md
PR 9387 core/libs/prx/libSceAgcDriver/tests/ShaderMemory.cpp
core/shader/recompiler/ShaderDiskCache.cpp
docs/dev/ENVIRONMENT.md
PR 9508 core/libs/prx/libSceAgcDriver/CMakeLists.txt
core/libs/prx/libSceAgcDriver/tests/ShaderMemory.cpp
core/shader/recompiler/ShaderDiskCache.cpp
docs/dev/ENVIRONMENT.md
PR 9676 docs/dev/ENVIRONMENT.md
PR 9700 core/libs/prx/libSceAgcDriver/CMakeLists.txt
PR 9712 core/libs/prx/libSceAgcDriver/CMakeLists.txt
docs/dev/ENVIRONMENT.md
PR 9748 core/libs/prx/libSceAgcDriver/CMakeLists.txt
core/libs/prx/libSceAgcDriver/tests/ShaderMemory.cpp
PR 9889 core/libs/prx/libSceAgcDriver/tests/ShaderMemory.cpp
core/shader/recompiler/Optimization/src/ResourceMaterializer.cpp
core/shader/recompiler/ShaderDiskCache.cpp
PR 9892 core/libs/prx/libSceAgcDriver/CMakeLists.txt
PR 9897 core/libs/prx/libSceAgcDriver/CMakeLists.txt
core/libs/prx/libSceAgcDriver/tests/ShaderMemory.cpp
core/shader/recompiler/ShaderDiskCache.cpp
PR 9898 core/libs/prx/libSceAgcDriver/CMakeLists.txt
docs/dev/ENVIRONMENT.md
PR 10049 core/shader/recompiler/ShaderDiskCache.cpp
PR 10069 docs/dev/ENVIRONMENT.md
PR 10193 core/libs/prx/libSceAgcDriver/CMakeLists.txt
core/libs/prx/libSceAgcDriver/tests/ShaderMemory.cpp
core/shader/recompiler/Optimization/include/Optimization/ResourceMaterializer.hpp
core/shader/recompiler/Optimization/src/ResourceMaterializer.cpp
core/shader/recompiler/ShaderDiskCache.cpp
docs/dev/ENVIRONMENT.md
PR 10233 core/libs/prx/libSceAgcDriver/CMakeLists.txt
core/libs/prx/libSceAgcDriver/tests/ShaderMemory.cpp
core/shader/recompiler/Optimization/src/ResourceMaterializer.cpp
PR 10442 core/libs/prx/libSceAgcDriver/CMakeLists.txt
docs/dev/ENVIRONMENT.md
PR 10678 docs/dev/ENVIRONMENT.md
PR 10757 core/libs/prx/libSceAgcDriver/CMakeLists.txt
core/libs/prx/libSceAgcDriver/tests/ShaderMemory.cpp
docs/dev/ENVIRONMENT.md
PR 10894 docs/dev/ENVIRONMENT.md
PR 10920 core/libs/prx/libSceAgcDriver/CMakeLists.txt
PR 11351 core/libs/prx/libSceAgcDriver/CMakeLists.txt
core/libs/prx/libSceAgcDriver/tests/ShaderMemory.cpp
docs/dev/ENVIRONMENT.md
PR 11483 core/libs/prx/libSceAgcDriver/tests/ShaderMemory.cpp
PR 11554 core/libs/prx/libSceAgcDriver/CMakeLists.txt
PR 11948 docs/dev/ENVIRONMENT.md
PR 12132 core/libs/prx/libSceAgcDriver/tests/ShaderMemory.cpp
docs/dev/ENVIRONMENT.md

@oneandonlydean

Copy link
Copy Markdown
Collaborator

@SleglJan thanks, the exact content and usage comparison before a replay makes the memo safe. Two things before this can go in:

  1. Could you post a same-machine A/B on current main, without local patches or title-executable edits, with the run-validity rule fixed before the runs, plus max RSS for both (the default budget allows 128 MiB)?
  2. noteColumnLookup takes the diagnostics mutex and inserts into its maps on every lookup, even when APS5_PROFILE_DRAW is off. Could that bookkeeping run only when the report is enabled?

…rofile

noteColumnLookup fed the never-seen and changed-content counters of the column
memo report on every lookup, taking the diagnostics mutex and inserting into its
slot and content maps whether or not APS5_PROFILE_DRAW, the report's only reader,
was set. It now returns first unless the draw profile is on, and the strict usage
hash of APS5_TABLE_COLUMN_MEMO_DIAG is computed under the same condition.

The column memo test gains a reported variant with APS5_PROFILE_DRAW=1 that
expects the three first sights and the one content change, and a diagnosed
variant without the profile switch; without it every variant expects those
counters to stay at zero, and the diagnosed variant sets the profile switch its
report needs.

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
@SleglJan

Copy link
Copy Markdown
Contributor Author

@oneandonlydean

  1. Done in f5cf0db: noteColumnLookup returns before touching the mutex or its maps unless APS5_PROFILE_DRAW is set, which is the only consumer of what it records outside the tests (the never-seen and changed-content misses and the distinct missed contents of the column memo report, and the APS5_TABLE_COLUMN_MEMO_DIAG sets and diffs). The column memo test now runs a variant with APS5_PROFILE_DRAW=1 that expects the three first sights and the one content change, and one with APS5_TABLE_COLUMN_MEMO_DIAG=1 alone; without the profile switch every variant expects those counters to stay at zero, and the diagnosed variant sets the profile switch its report needs. Hits, misses, replay and verify are unchanged. The PR text is updated accordingly.

  2. On the A/B. What we can give now, and what a run on current main needs:

  • Max RSS of the title process over the twelve runs of the series above (/proc/<pid>/status VmRSS, the highest of the samples taken every 10 s): base 31,278,692-32,065,656 kB, this change 30,552,592-32,080,180 kB. The memo's budget is 33,554,432 words, about 128 MiB of host memory by its own estimate.
  • 007 on main c547dea on this machine, one run today with a cold shader disk cache and the same executable edit: 20 compute pipeline creations of 1 s or more at boot summing 551 s (the longest 100 s), the first level's resume at 1,215 s (the series' warm base runs above resumed at 224-226 s, the base's own cold seed at 255 s), gameplay start at 1,285 s at 0.18 presents per second, and no new frame after frame 1,117 for the remaining 631 s, with 33 pipeline creations summing 411 s in that time; peak VmRSS 25,839,584 kB. Not diagnosed. main has no code fix for 007 First Light (PPSA11386): the terrain crash after Resume is a stale read of a GPU feedback buffer past the title's own wait limits #6172's stale feedback read (the issue was closed by docs(dev): describe the guest clock scale switch #6181, a documentation PR for APS5_TIME_SCALE), and whether 007 passes the resume on main without the executable edit, with or without the clock scale, is untried here. The base also carries perf(agc-driver): join a buffer bound from inside a range across the ranges it crosses #5372 (open) for this title. We have no warm run on main, so we do not know its pace on this title beyond that run.

An A/B on plain main would need APS5_TIME_SCALE in place of the executable edit, if the title passes the resume with it, and a warm seed per side; the run above does not say what pace it would then measure the memo at. If that is what you want, we can run it (two cold seeds plus three alternated pairs, about 5 h of GPU time on this machine) and report presents per second, Populate per frame and max RSS for both sides, with the validity rule fixed before the first run. If another title serves better and we have it, say which one and we will look for large recurring image tables there; the memo keys on the column content, not on the title.

On the overlap bot's list: #7223's nested columns add inputs (child tables and the pointers that key them) that this memo does not cover, so whichever lands second has to extend the key and the replay to the child tables and pointers, or exclude nested columns from the memo; if #7223 lands first, we do that on our side. #11957 shares only the test file and the test list with this PR.

AI-assisted: yes (Claude Code)

@MarcZX10 MarcZX10 left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Reviewed exact head f5cf0db16c28ee4a7575c7cd1dda342fd01a9fe6 and the updated PR discussion. The implementation has a focused verify mode and reports zero mismatches in the supplied run, but the remaining validation and overlap questions are material for this shader-driver change.

The required performance report is still missing: the submitted A/B uses a local base with other PRs, local logging, and a modified title executable, and no aps5-summary.jsonl lines or trace pair/digest are attached. CONTRIBUTING.md requires captures from current main and this PR using the same title, scene, and machine, with the traces; the perf label workflow also requests both summary lines and tools/trace_digest.py output. The maintainer's request for a current-main A/B and max RSS is still unanswered with a compliant comparison. Please provide that evidence or remove the performance claim/label and resolve the maintainer's request explicitly.

There is also an exact merge conflict with open #7223 in ResourceMaterializer.cpp (git merge-tree --write-tree reports a content conflict). The description recognizes that nested-table support must be extended or excluded depending on order, but the checklist says Depends on: none. Please agree the order with #7223’s author, record the dependency/plan, and validate the combined behavior before merge.

@github-actions github-actions Bot added build shader core/shader docs agc libSceAgc* labels Oct 28, 2026
@adriadam10 adriadam10 self-assigned this Oct 28, 2026

@adriadam10 adriadam10 left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for the verify mode and the exact content/usage comparison before a replay. Still open on this head:

  • Performance report (labeled perf, CONTRIBUTING): paste the aps5-summary.jsonl lines of a capture on current main and one with this change, same title, scene and machine, plus the tools/trace_digest.py output. The 007 A/B is on a local base (other PRs, local logging, a patched title executable), and its run-validity rule was changed after the first runs (1 valid run of 6 for this change), so it doesn't give a verdict.
  • Max RSS for both sides (the default budget allows 128 MiB of estimated host memory; docs/dev/ memory rules ask for the bound and peak RSS before/after on a big workload).
  • Device memory at the level load: memory outside the texture caches went from 1,033-1,257 MiB to 1,206-2,528 MiB, with host placements in 3 of 6 runs against 1 of 6. Please find the cause or show it is noise with more runs before this lands; a perf change that raises peak memory needs that settled.
  • The tests don't cover placement against earlier columns of the same resolution, eviction by budget/entry count, or the APS5_TABLE_COLUMN_MEMO_WORDS parsing; please add them.

… and budget parsing

agc_shader_table_column_memo_placement and _placement_before resolve thirty
selected single-record tables and one merged column, whose narrowed domain
binds its sixty-five keyed records and record 0, in one resolution, with the
merged column resolved after or before the selected tables. Thirty of its
records equal the selected tables' records: the replayed column must land
them on the elements the selected tables placed, or the selected tables on
the elements the replayed column placed, 66 elements in all, equal to the
plain resolution. _placement_off runs the first order with the memo off.
agc_shader_table_column_memo_evicted_by_count fills the memo to its 4,096
entries and reads through hits and misses that the least recently used entry
leaves first; _evicted_by_budget does the same under
APS5_TABLE_COLUMN_MEMO_WORDS=65536 with the first content replayed after
every insertion, and _oversize_entry checks that an entry over a budget of
0x1 words is never kept. agc_shader_table_column_memo_words*: accepted values
(unset, 1048576, 0x100000) resolve the same column twice and check that the
memo keeps it; refused values (0, -1, empty, abc, 12x, a 20-digit overflow)
check that the first resolution fails with the variable's message.

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
@github-actions github-actions Bot added the needs rebase Conflicts with main, rebase needed label Oct 28, 2026
Resolves docs/dev/ENVIRONMENT.md: main's APS5_STRICT_DESCRIPTOR_WEBS row (now a string) is kept and the APS5_TABLE_COLUMN_MEMO_DIAG and APS5_TABLE_COLUMN_MEMO_WORDS rows follow it. Everything else merged automatically.

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
SleglJan and others added 2 commits October 28, 2026 17:39
A column memo hit compares the stored usage's whole image resource and mode
list (ImageResource's defaulted operator==), while the usage hash lists
fields by name. Two fields were compared and not hashed: `sampledOnly`,
which the image descriptor decode reads since boykopovar#11507 (a cube descriptor
with fewer than six slices is poisoned unless the image is only sampled),
and `optionalDescriptor`. Two usages that differed only in one of them
shared a key; the hit check rejected the entry and the next miss replaced
it, so the two missed in turn instead of replaying. The hash now mixes
both, and the docs/dev/ENVIRONMENT.md row of APS5_NO_TABLE_COLUMN_MEMO says
what a hit compares: every field but the descriptor source, the first use
and the table index.

Test: `agc_shader_table_column_memo_usage` resolves one column under a
sampled-only usage, under the same usage with `sampledOnly` cleared, and
under the same usage with `optionalDescriptor` set, each under its own
variant key: every new usage misses once, and every usage then hits.

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
Every other agc_shader_memory_tests entry prepends libc's directory to PATH
on Windows; the 22 column memo tests did not. They need libc's directory on
PATH there, like the other entries.

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
@SleglJan

Copy link
Copy Markdown
Contributor Author

Thanks for the reviews, @adriadam10 and @MarcZX10, and for the earlier questions, @oneandonlydean. Head is now dc1e7e5 (tests only on f5cf0db). Below: what the PR claims now and the performance report (the capture pair on main, the A/B on main, your asks one by one), max RSS, device memory at the level load, the tests, and #7223. The branch now conflicts with main in docs/dev/ENVIRONMENT.md, so the checklist's "Based on current main" box is unticked for now. The merge comes as a separate commit after these results are posted, so the lines below stay tied to dc1e7e5. Two fixes from the review of that merge come with it: the column usage hash gains the two fields a hit compares but the hash left out (image.sampledOnly from #11507 and image.optionalDescriptor; without them two usages that differ only there share a key and miss in turn instead of replaying; the second gap exists at dc1e7e5 as measured below, where it can only cost misses in the same way), and the column memo tests get libc on their PATH on Windows like the other agc_shader_memory_tests entries.

Performance report. What this PR claims now: the [recompile] Populate time is down on main (171 / 169 / 172 ms per frame against 67 / 69 / 72 in the A/B below); no frame-rate gain on main within the run spread (walk presents per second 0.369 / 0.369 / 0.341 against 0.358 / 0.326 / 0.371); the +11.5 % walk gain was measured only on the local base and does not reproduce on main c547dea. Whether that supports a perf change is for adriadam10 and oneandonlydean to decide; if you prefer, I'll retitle the PR without perf (which takes the label off) and remove the local-base frame-rate figures from the description.

Captured on this machine (CachyOS, kernel 7.2.10, NVIDIA GeForce RTX 3080, driver 615.78.08, Ryzen 9 7950X3D, 64 GB), 007 First Light (PPSA11386), the walk after the resume of the first level, APS5_TRACE_FRAMES=1085:150 on both sides: main at the PR's base c547dea (2026-10-28, 12:04 to 12:47 CET) and this PR at its head dc1e7e5 (12:51 to 13:34 CET), same boot, a build and a test run in between. Not as the form asks: APS5_TRACE_EVENTS=4194304 on both sides, because queue worker 0x0 records about 10,700 events per present here and the default buffer of 262,144 events (docs/dev/BUILD.md) holds about 25 presents; APS5_TRACE_DIR for the output directory; APS5_TIME_SCALE=0.1 (the title's clock at a tenth of real time) and scripted input through APS5_PAD_INPUT_FILE, both visible in the lines' env; and, not visible there, the log written to a file, the NVIDIA shader disk cache on and pointed at a per-run directory copied from a seed run (a 16 GiB size cap, its cleanup skipped), the shader disk cache and the journal warm from that seed run rather than from a restart, and the title in a scope with swap turned off. No other APS5_TRACE_* switch and no APS5_PROFILE_* switch is set. Both sides the same way: main from its own seed; this PR from a copy of the PR's seed with main's journal records (the journal header's source version set to the PR's), so the journal records and the NVIDIA cache are identical on both sides, while the shader disk cache is each side's own because the shader cache source versions differ (41abaa3b8f8b9199 on main, 75f9ad0bc594cabf on this PR).

{"commit":"c547deaacb62","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TIME_SCALE":"0.1","APS5_TRACE_DIR":"<path>","APS5_TRACE_EVENTS":"4194304","APS5_TRACE_FRAMES":"1085:150"},"gpu":"NVIDIA GeForce RTX 3080","driver":"NVIDIA 615.78.08","os":"Linux 7.2.10-1-cachyos","cpu":"AMD Ryzen 9 7950X3D 16-Core Processor","cpu_threads":32,"memory_mib":63428,"title_id":"PPSA11386","title":"007 First Light","content_version":"01.018.000","resolution":"3840x2160","window":{"spec":"frames 1085:150","first_present":1085,"ms":418164.785},"presents":150,"frame_ms":{"p50":2711.721,"p90":3216.898,"p99":3992.038,"max":4422.742},"gpu_busy_ms_per_present":477.688,"worker_busy_pct":{"queue worker 0x0":99.931,"queue worker 0x20":99.869,"queue worker 0x28":99.746,"queue worker 0x30":99.799,"queue worker 0x38":82.472},"top_phases_ms_per_frame":{"Driver.Packet":13395.303,"Driver.Packet.memory_wait":9050.250,"Driver.Packet.dispatch":2341.595,"GpuMutex.wait.hook":2314.830,"Driver.Dispatch":2091.833,"Resources.Complete":1952.857,"Driver.Packet.draw":1763.494,"Driver.Draw":1762.767},"trace_dropped":false,"trace":"aps5-trace-c547deaacb62-2.json.gz"}
{"commit":"dc1e7e5695ab","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TIME_SCALE":"0.1","APS5_TRACE_DIR":"<path>","APS5_TRACE_EVENTS":"4194304","APS5_TRACE_FRAMES":"1085:150"},"gpu":"NVIDIA GeForce RTX 3080","driver":"NVIDIA 615.78.08","os":"Linux 7.2.10-1-cachyos","cpu":"AMD Ryzen 9 7950X3D 16-Core Processor","cpu_threads":32,"memory_mib":63428,"title_id":"PPSA11386","title":"007 First Light","content_version":"01.018.000","resolution":"3840x2160","window":{"spec":"frames 1085:150","first_present":1085,"ms":436633.103},"presents":150,"frame_ms":{"p50":2882.072,"p90":3378.460,"p99":4499.485,"max":7033.048},"gpu_busy_ms_per_present":497.524,"worker_busy_pct":{"queue worker 0x0":99.946,"queue worker 0x20":99.900,"queue worker 0x28":99.815,"queue worker 0x38":82.658,"queue worker 0x30":99.844},"top_phases_ms_per_frame":{"Driver.Packet":13992.217,"Driver.Packet.memory_wait":9511.346,"GpuMutex.wait.hook":2578.339,"Driver.Packet.dispatch":2452.564,"Driver.Dispatch":2167.295,"Resources.Complete":2116.024,"Graphics.Draw":1816.352,"Driver.Packet.draw":1792.957},"trace_dropped":false,"trace":"aps5-trace-dc1e7e5695ab-2.json.gz"}

Digests (python3 tools/trace_digest.py) and the two traces are on a pre-release of my fork, https://github.com/SleglJan/AnyPS5/releases/tag/perf-traces-shader-column-memo, because both files are over the 25 MB attachment limit (31.7 and 32.4 MB); sha256 e44ae16fa69649761e15a3f5cd9a394f8089e4a51db7e34c59d2590ff518e6e5 (main) and 22b1ef75f9c6c30a4c75a5552866af2d790655ae1ede305a18e25a1f5e5d1fd7 (this PR). The two digests:

trace_digest, main c547dea

frames 1085:150 from present 1085: 150 presents, frame p50 2711.7 / p90 3216.9 / p99 3992.0 / max 4422.7 ms, GPU busy 477.7 ms per present
NVIDIA GeForce RTX 3080, NVIDIA 615.78.08, Linux 7.2.10-1-cachyos, 3840x2160, commit c547dea, dropped: no

{"commit":"c547deaacb62","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TIME_SCALE":"0.1","APS5_TRACE_DIR":"<path>","APS5_TRACE_EVENTS":"4194304","APS5_TRACE_FRAMES":"1085:150"},"gpu":"NVIDIA GeForce RTX 3080","driver":"NVIDIA 615.78.08","os":"Linux 7.2.10-1-cachyos","cpu":"AMD Ryzen 9 7950X3D 16-Core Processor","cpu_threads":32,"memory_mib":63428,"title_id":"PPSA11386","title":"007 First Light","content_version":"01.018.000","resolution":"3840x2160","window":{"spec":"frames 1085:150","first_present":1085,"ms":418164.785},"presents":150,"frame_ms":{"p50":2711.721,"p90":3216.898,"p99":3992.038,"max":4422.742},"gpu_busy_ms_per_present":477.688,"worker_busy_pct":{"queue worker 0x0":99.931,"queue worker 0x20":99.869,"queue worker 0x28":99.746,"queue worker 0x30":99.799,"queue worker 0x38":82.472},"top_phases_ms_per_frame":{"Driver.Packet":13395.303,"Driver.Packet.memory_wait":9050.25,"Driver.Packet.dispatch":2341.595,"GpuMutex.wait.hook":2314.83,"Driver.Dispatch":2091.833,"Resources.Complete":1952.857,"Driver.Packet.draw":1763.494,"Driver.Draw":1762.767},"trace_dropped":false,"trace":"aps5-trace-c547deaacb62-2.json.gz"}

Slowest frames (largest slices inside each, inclusive)

  • present 1132: 4422.7 ms at 135551 ms: Driver.Packet (queue worker 0x28) 4422.5, Driver.Packet (queue worker 0x30) 4421.0, Driver.Packet (queue worker 0x20) 4414.4, Driver.Packet (queue worker 0x0) 4363.0
  • present 1111: 3992.0 ms at 79265 ms: Driver.Packet (queue worker 0x30) 3991.8, Driver.Packet (queue worker 0x20) 3991.5, Driver.Packet (queue worker 0x28) 3983.6, Driver.Packet.memory_wait (queue worker 0x28) 3960.9
  • present 1134: 3892.5 ms at 143751 ms: Driver.Packet (queue worker 0x30) 3892.3, Driver.Packet (queue worker 0x28) 3892.3, Driver.Packet (queue worker 0x20) 3892.0, Driver.Packet (queue worker 0x0) 3841.6
  • present 1133: 3777.3 ms at 139974 ms: Driver.Packet (queue worker 0x28) 3777.0, Driver.Packet (queue worker 0x30) 3776.9, Driver.Packet (queue worker 0x20) 3775.7, Driver.Packet (queue worker 0x0) 3730.9
  • present 1112: 3679.7 ms at 83257 ms: Driver.Packet (queue worker 0x28) 3679.5, Driver.Packet (queue worker 0x30) 3679.4, Driver.Packet (queue worker 0x20) 3679.0, Driver.Packet (queue worker 0x0) 3649.5

Threads (ms per frame)

thread busy wait untraced in slices < 20 us largest
shader prepare 0.1 (0 %) 0.0 (0 %) 2787.7 0.0 Vulkan.GraphicsPipelinePrebuild 0.1, Vulkan.ComputePipeline 0.0
shader prepare 0.1 (0 %) 0.0 (0 %) 2787.7 0.0 Vulkan.GraphicsPipelinePrebuild 0.0, Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2787.7 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2787.7 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2787.8 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2787.7 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2787.7 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2787.7 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2787.7 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2787.7 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2787.7 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2787.7 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2787.7 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2787.7 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.1 (0 %) 0.0 (0 %) 2787.7 0.0 Vulkan.ComputePipeline 0.1
shader prepare 0.0 (0 %) 0.0 (0 %) 2787.7 0.0 Vulkan.ComputePipeline 0.0
title 0.8 (0 %) 0.3 (0 %) 2786.6 0.6 Shader.ResolveAbi 0.5, Shader.ResolveGraphicsStagesAbi 0.2
queue worker 0x0 2613.4 (94 %) 165.0 (6 %) 9.4 102.2 Driver.Packet 2752.8, Driver.EndSubmission 25.5
draw committer 1391.1 (50 %) 201.1 (7 %) 1195.5 12.0 Graphics.Draw 1365.7, Recorder.Submit 18.4
presenter 1.3 (0 %) 13.0 (0 %) 2773.5 0.1 VideoOut.Flip 13.9, Driver.Present 0.4
title 0.2 (0 %) 0.0 (0 %) 2787.6 0.3 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.1
title 0.2 (0 %) 0.0 (0 %) 2787.5 0.3 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.1
title 0.2 (0 %) 0.0 (0 %) 2787.6 0.3 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.1
title 0.2 (0 %) 0.0 (0 %) 2787.6 0.3 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.1
title 0.2 (0 %) 0.0 (0 %) 2787.6 0.2 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.0
queue worker 0x20 164.3 (6 %) 2620.5 (94 %) 3.0 3.0 Driver.Packet 2782.4, Driver.EndSubmission 1.2
title 0.2 (0 %) 0.0 (0 %) 2787.6 0.3 Shader.ResolveAbi 0.1, Shader.ResolveGraphicsStagesAbi 0.1
title 0.2 (0 %) 0.0 (0 %) 2787.5 0.3 Shader.ResolveAbi 0.1, Shader.ResolveGraphicsStagesAbi 0.1
title 0.5 (0 %) 0.0 (0 %) 2787.2 0.3 Shader.ResolveAbi 0.3, Shader.ResolveGraphicsStagesAbi 0.2
queue worker 0x28 39.3 (1 %) 2742.6 (98 %) 5.8 1.6 Driver.Packet 2780.3, Driver.EndSubmission 0.2
queue worker 0x30 71.4 (3 %) 2712.6 (97 %) 3.9 1.3 Driver.Packet 2782.0, Driver.EndSubmission 0.0
queue worker 0x38 76.3 (3 %) 2704.3 (97 %) 7.1 2.7 Driver.Packet 2289.1, Driver.EndSubmission 9.6
gpu 479.3 (17 %) 0.0 (0 %) 2308.5 0.0 batch 479.3

Largest slices (ms per frame, inclusive, all threads): Driver.Packet 13386.6, Driver.Packet.memory_wait 9050.1, Driver.Packet.dispatch 2341.1, GpuMutex.wait.hook 2314.6, Driver.Dispatch 2090.7, Resources.Complete 1951.6, Driver.Packet.draw 1762.7, Driver.Draw 1761.9, Graphics.Draw 1730.5, Graphics.Draw.draw_and_resource_release 1677.6

Longest waits

  • Driver.Packet.memory_wait (queue worker 0x38) 2664.5 ms at 77835 ms, present 1110
  • Driver.Packet.memory_wait (queue worker 0x38) 2635.9 ms at 145027 ms, present 1134
  • Driver.Packet.memory_wait (queue worker 0x38) 2596.6 ms at 137385 ms, present 1132
  • Driver.Packet.memory_wait (queue worker 0x38) 2392.2 ms at 141365 ms, present 1133
  • Driver.Packet.memory_wait (queue worker 0x28) 2353.4 ms at 145310 ms, present 1134
  • Driver.Packet.memory_wait (queue worker 0x28) 2346.3 ms at 83293 ms, present 1112
  • Driver.Packet.memory_wait (queue worker 0x28) 2272.3 ms at 78227 ms, present 1110
  • Driver.Packet.memory_wait (queue worker 0x28) 2211.1 ms at 137771 ms, present 1132
  • Driver.Packet.memory_wait (queue worker 0x28) 2156.7 ms at 141606 ms, present 1133
  • Driver.Packet.memory_wait (queue worker 0x28) 2094.5 ms at 378355 ms, present 1221

Largest GPU batches (GPU ranges inside, and the CPU slices that recorded each, inclusive)

  • batch 1818: 161.6 ms at 19146 ms, present 1090: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 94.8, Driver.Packet.dispatch (queue worker 0x0) 94.8, Driver.Dispatch (queue worker 0x0) 94.8, Vulkan.Dispatch (queue worker 0x0) 94.3
  • batch 5909: 134.6 ms at 61099 ms, present 1104: GPU no ranges; recorded by Recorder.Submit (draw committer) 0.1
  • batch 5340: 129.9 ms at 55349 ms, present 1102: GPU no ranges; recorded by no CPU slices
  • batch 40682: 129.4 ms at 390840 ms, present 1224: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 142.0, Driver.Packet.dispatch (queue worker 0x0) 142.0, Driver.Dispatch (queue worker 0x0) 141.9, Vulkan.Dispatch (queue worker 0x0) 141.6
  • batch 2140: 129.2 ms at 22573 ms, present 1091: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 37.6, Driver.Packet.dispatch (queue worker 0x0) 37.6, Driver.Dispatch (queue worker 0x0) 37.5, Vulkan.Dispatch (queue worker 0x0) 37.3
trace_digest, this PR dc1e7e5

frames 1085:150 from present 1085: 150 presents, frame p50 2882.1 / p90 3378.5 / p99 4499.5 / max 7033.0 ms, GPU busy 497.5 ms per present
NVIDIA GeForce RTX 3080, NVIDIA 615.78.08, Linux 7.2.10-1-cachyos, 3840x2160, commit dc1e7e5, dropped: no

{"commit":"dc1e7e5695ab","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TIME_SCALE":"0.1","APS5_TRACE_DIR":"<path>","APS5_TRACE_EVENTS":"4194304","APS5_TRACE_FRAMES":"1085:150"},"gpu":"NVIDIA GeForce RTX 3080","driver":"NVIDIA 615.78.08","os":"Linux 7.2.10-1-cachyos","cpu":"AMD Ryzen 9 7950X3D 16-Core Processor","cpu_threads":32,"memory_mib":63428,"title_id":"PPSA11386","title":"007 First Light","content_version":"01.018.000","resolution":"3840x2160","window":{"spec":"frames 1085:150","first_present":1085,"ms":436633.103},"presents":150,"frame_ms":{"p50":2882.072,"p90":3378.46,"p99":4499.485,"max":7033.048},"gpu_busy_ms_per_present":497.524,"worker_busy_pct":{"queue worker 0x0":99.946,"queue worker 0x20":99.9,"queue worker 0x28":99.815,"queue worker 0x38":82.658,"queue worker 0x30":99.844},"top_phases_ms_per_frame":{"Driver.Packet":13992.217,"Driver.Packet.memory_wait":9511.346,"GpuMutex.wait.hook":2578.339,"Driver.Packet.dispatch":2452.564,"Driver.Dispatch":2167.295,"Resources.Complete":2116.024,"Graphics.Draw":1816.352,"Driver.Packet.draw":1792.957},"trace_dropped":false,"trace":"aps5-trace-dc1e7e5695ab-2.json.gz"}

Slowest frames (largest slices inside each, inclusive)

  • present 1189: 7033.0 ms at 307180 ms: Driver.Packet (queue worker 0x30) 7032.6, Driver.Packet (queue worker 0x20) 7032.5, Driver.Packet (queue worker 0x28) 7031.8, Driver.Packet (queue worker 0x0) 6998.7
  • present 1106: 4499.5 ms at 69555 ms: Driver.Packet (queue worker 0x28) 4499.3, Driver.Packet (queue worker 0x30) 4499.2, Driver.Packet (queue worker 0x20) 4498.9, Driver.Packet (queue worker 0x0) 4449.3
  • present 1116: 4467.2 ms at 101816 ms: Driver.Packet (queue worker 0x30) 4467.0, Driver.Packet (queue worker 0x28) 4467.0, Driver.Packet (queue worker 0x20) 4466.6, Driver.Packet (queue worker 0x0) 4402.2
  • present 1115: 4180.3 ms at 97636 ms: Driver.Packet (queue worker 0x30) 4180.1, Driver.Packet (queue worker 0x28) 4180.1, Driver.Packet (queue worker 0x20) 4179.6, Driver.Packet (queue worker 0x0) 4128.5
  • present 1217: 3772.4 ms at 386946 ms: Driver.Packet (queue worker 0x30) 3772.2, Driver.Packet (queue worker 0x28) 3772.1, Driver.Packet (queue worker 0x20) 3771.7, Driver.Packet (queue worker 0x0) 3723.4

Threads (ms per frame)

thread busy wait untraced in slices < 20 us largest
shader prepare 0.0 (0 %) 0.0 (0 %) 2910.9 0.0 Vulkan.GraphicsPipelinePrebuild 0.0, Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2910.8 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.2 (0 %) 0.0 (0 %) 2910.7 0.0 Vulkan.GraphicsPipelinePrebuild 0.2, Vulkan.ComputePipeline 0.0
shader prepare 0.1 (0 %) 0.0 (0 %) 2910.8 0.0 Vulkan.ComputePipeline 0.1
shader prepare 0.1 (0 %) 0.0 (0 %) 2910.8 0.0 Vulkan.GraphicsPipelinePrebuild 0.1, Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2910.8 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2910.9 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.2 (0 %) 0.0 (0 %) 2910.6 0.0 Vulkan.GraphicsPipelinePrebuild 0.2, Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2910.9 0.0 Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2910.8 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.1 (0 %) 0.0 (0 %) 2910.8 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.1 (0 %) 0.0 (0 %) 2910.8 0.0 Vulkan.ComputePipeline 0.1
shader prepare 0.1 (0 %) 0.0 (0 %) 2910.8 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2910.9 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.1 (0 %) 0.0 (0 %) 2910.8 0.0 Vulkan.ComputePipeline 0.1
shader prepare 0.0 (0 %) 0.0 (0 %) 2910.9 0.0 Vulkan.ComputePipeline 0.0
title 0.8 (0 %) 0.4 (0 %) 2909.7 0.6 Shader.ResolveAbi 0.4, Shader.ResolveGraphicsStagesAbi 0.3
queue worker 0x0 2710.2 (93 %) 191.8 (7 %) 8.9 102.5 Driver.Packet 2874.0, Driver.EndSubmission 27.9
draw committer 1433.8 (49 %) 231.2 (8 %) 1245.9 12.3 Graphics.Draw 1412.5, Recorder.Submit 18.3
presenter 1.1 (0 %) 12.6 (0 %) 2897.1 0.1 VideoOut.Flip 13.7, Driver.Present 0.1
title 0.4 (0 %) 0.0 (0 %) 2910.5 0.2 Shader.ResolveGraphicsStagesAbi 0.2, Shader.ResolveAbi 0.2
title 0.3 (0 %) 0.0 (0 %) 2910.6 0.3 Shader.ResolveGraphicsAbi 0.1, Shader.ResolveGraphicsStagesAbi 0.1
title 0.3 (0 %) 0.0 (0 %) 2910.6 0.3 Shader.ResolveAbi 0.2, Shader.ResolveGraphicsStagesAbi 0.1
title 0.2 (0 %) 0.0 (0 %) 2910.7 0.3 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.1
queue worker 0x20 175.9 (6 %) 2732.7 (94 %) 2.4 3.0 Driver.Packet 2899.0, Driver.EndSubmission 8.5
title 0.2 (0 %) 0.0 (0 %) 2910.7 0.2 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.1
title 0.2 (0 %) 0.0 (0 %) 2910.7 0.3 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.1
title 0.2 (0 %) 0.0 (0 %) 2910.7 0.3 Shader.ResolveAbi 0.1, Shader.ResolveGraphicsStagesAbi 0.1
title 0.2 (0 %) 0.0 (0 %) 2910.7 0.3 Shader.ResolveAbi 0.1, Shader.ResolveGraphicsStagesAbi 0.1
queue worker 0x28 42.0 (1 %) 2865.5 (98 %) 3.4 1.5 Driver.Packet 2905.0, Driver.EndSubmission 0.4
queue worker 0x38 88.4 (3 %) 2815.7 (97 %) 6.8 2.7 Driver.Packet 2399.5, Driver.EndSubmission 6.2
queue worker 0x30 79.6 (3 %) 2828.7 (97 %) 2.6 1.3 Driver.Packet 2906.2, Recorder.Submit 0.0
gpu 499.6 (17 %) 0.0 (0 %) 2411.3 0.0 batch 499.6

Largest slices (ms per frame, inclusive, all threads): Driver.Packet 13983.7, Driver.Packet.memory_wait 9511.2, GpuMutex.wait.hook 2578.1, Driver.Packet.dispatch 2452.1, Driver.Dispatch 2166.2, Resources.Complete 2114.8, Graphics.Draw 1816.3, Driver.Packet.draw 1792.2, Driver.Draw 1791.5, Graphics.Draw.draw_and_resource_release 1765.9

Longest waits

  • Driver.Packet.memory_wait (queue worker 0x38) 5556.9 ms at 308667 ms, present 1189
  • Driver.Packet.memory_wait (queue worker 0x28) 5234.6 ms at 308989 ms, present 1189
  • Driver.Packet.memory_wait (queue worker 0x30) 5094.1 ms at 309130 ms, present 1189
  • Driver.Packet.memory_wait (queue worker 0x38) 2944.8 ms at 103348 ms, present 1116
  • Driver.Packet.memory_wait (queue worker 0x20) 2889.1 ms at 311335 ms, present 1189
  • Driver.Packet.memory_wait (queue worker 0x38) 2781.8 ms at 68001 ms, present 1105
  • Driver.Packet.memory_wait (queue worker 0x38) 2635.5 ms at 99186 ms, present 1115
  • Driver.Packet.memory_wait (queue worker 0x28) 2586.3 ms at 103707 ms, present 1116
  • Driver.Packet.memory_wait (queue worker 0x28) 2436.3 ms at 68346 ms, present 1105
  • Driver.Packet.memory_wait (queue worker 0x20) 2428.1 ms at 308906 ms, present 1189

Largest GPU batches (GPU ranges inside, and the CPU slices that recorded each, inclusive)

  • batch 33553: 182.1 ms at 314023 ms, present 1189: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 73.5, Driver.Packet.dispatch (queue worker 0x0) 73.5, Driver.Dispatch (queue worker 0x0) 73.5, Vulkan.Dispatch (queue worker 0x0) 73.4
  • batch 34380: 125.6 ms at 321825 ms, present 1192: GPU no ranges; recorded by Recorder.Submit (draw committer) 0.0
  • batch 3794: 119.1 ms at 38512 ms, present 1096: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 129.7, Driver.Packet.draw (queue worker 0x0) 120.9, Driver.Draw (queue worker 0x0) 120.9, Driver.Draw.draw_enqueued (queue worker 0x0) 120.5
  • batch 20962: 114.7 ms at 200029 ms, present 1147: GPU no ranges; recorded by Recorder.Sync (queue worker 0x0) 114.3, Driver.Packet (queue worker 0x0) 3.4, Driver.Packet.dispatch (queue worker 0x0) 3.4, Driver.Dispatch (queue worker 0x0) 3.4
  • batch 23679: 113.6 ms at 226857 ms, present 1156: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 88.9, Driver.Packet.dispatch (queue worker 0x0) 88.9, Driver.Dispatch (queue worker 0x0) 88.8, Vulkan.Dispatch (queue worker 0x0) 88.7

tools/performance_compare.py on the two lines reports no configuration difference; this PR minus main: frame p50 +170 ms (+6.3 %), p90 +162 ms (+5.0 %), p99 +507 ms (+12.7 %), max +2,610 ms (+59 %), mean frame +123 ms (+4.4 %), GPU busy per present +20 ms (+4.2 %). One pair, one run per side. Validity under our harness rules, under both readings defined in the A/B paragraph below: both captures are on route with no device faults; collapse cannot be judged on a trace capture (the form's switch set removes the counters our check reads). Under the second reading main's run passes every check readable here (collapse is not readable): [gpu] at least 2 host placements (104 MiB at that count; limit 64 placements), [bufferpool] at least 32 (256 MiB; limit 256 placements), 32 recovered allocation refusal lines over the run (limit 100), peak device memory used 9,550 MiB over the run (limit 9,850) and 9,042 MiB at the level load; this PR's run is invalid: it peaks at 9,883 MiB at frame 1,036, the level load before the walk and outside the trace window, over the 9,850 MiB limit (next-highest 1 s sample 9,782 MiB at frame 1,248, after the window; [gpu] at least 16 placements, 163 MiB; [bufferpool] at least 16, 128 MiB; 69 recovered refusal lines). Under the first reading both runs are invalid, because the staging-shadow refusal lines count as unrecovered refusals there: main 2 (its full count), this PR 4 (a lower bound: at most four are printed per run, and the cumulative count is not printed under this switch set). The placement counts are lower bounds because those lines print at counts 1 to 5 and at powers of two. Both journals loaded 175 pipelines / 185 modules / 884.5 MiB; disk cache 0 misses on both.

The pair's lines as they are: window 418.2 s against 436.6 s over 150 presents, p50 2,711.7 against 2,882.1 ms (p90 3,216.9 / 3,378.5, p99 3,992.0 / 4,499.5, max 4,422.7 / 7,033.0), GPU busy 477.7 against 497.5 ms per present; one pair, one run per side, read next to the three-pair A/B spread below. The Populate figures come from the profiled A/B runs below, not from the capture pair (no APS5_PROFILE_DRAW there): 171 / 169 / 172 → 67 / 69 / 72 ms per frame, with the walk rates 0.369 / 0.369 / 0.341 against 0.358 / 0.326 / 0.371 presents per second. What the frame is spent on, from the two traces through a local script that only reads the trace (the 149 complete frames between the window's presents, ms per frame, main / this PR): the draw committer in Resources.Complete 1,142 / 1,169 and with no scope open 1,195 / 1,246; queue worker 0x0 in Driver.Draw.draw_enqueued (the stage up to the draw's enqueue, including the wait for room) 1,136 / 1,180, in its own Resources.Complete 433 / 522, in Shader.DrawStage.materialize 105 / 41; GPU busy 480 / 499 with idle gaps 2,309 / 2,411. Three GPU busy figures come from three sources: the summary lines' 477.7 / 497.5 are the driver's per-batch busy counters over the window's 150 presents; the digests' 479.3 / 499.6 sum the trace's batch slices over the same 150 presents; the script's 480 / 499 merge overlapping batch slices and clip them to the 149 complete frames.

The 007 A/B on main c547dea behind those figures: three pairs alternated main / this PR (f5cf0db, the same runtime as dc1e7e5) in one session from 2026-10-27 22:41 to 2026-10-28 03:00 CET, APS5_PROFILE_DRAW=1 and APS5_TRACE_SUMMARY_EVERY=60 on, each side from its own seed run's caches, journals unequal (this PR 215 pipelines against main 175), the cache and swap settings as above. Two validity readings. The first, declared before the series, takes any unrecovered allocation refusal as invalid: n = 1 / 1, main 0.341 against this PR 0.326 presents per second on the walk. The second counts staging-shadow refusal lines as handled; it was declared after pair 1's results, which made both its runs invalid only through these lines, while pair 2's first run was running: n = 3 / 3, main 0.369 / 0.369 / 0.341 (mean 0.360) against this PR 0.358 / 0.326 / 0.371 (mean 0.352). Four of the six runs differ between the two readings, all on that line. All six runs pass the route check declared later (the prompt scene reached +213 to +242 frames after the walk start).

Your asks, one by one. oneandonlydean: a same-machine A/B on current main — partly: on c547dea, the PR's base (main on 2026-10-27 at 17:06 CET); main had moved 32 merges past it when the A/B started and 284 when the capture pair ran; without local patches or title-executable edits — yes, plain builds of main and of this PR, the title executable unedited, the harness being scripted input and the environment above; the run-validity rule fixed before the runs — yes for the first reading, no for the second, declared as stated above; max RSS for both — in the next section. MarcZX10: the summary lines, the traces and the digests are above, and the claim is narrowed as stated at the top. adriadam10: the performance report is this section; max RSS, the level load and the tests follow in their own sections, the level-load one with the host placements per run.

Max RSS. The highest VmHWM the 10 s sampler read per run, to the stop at frame 1,720, in MiB. The A/B above (unequal journals): main 23,651 / 24,614 / 24,036 (mean 24,100), this PR 24,460 / 25,557 / 23,802 (mean 24,606). The three-pair series with one shared journal (below): main 24,345, this PR 24,350 / 24,547 / 24,044; two main runs of that series are left out here under the route check declared after that series ended: they never reached the prompt scene and ran the walk 2.2 to 2.6 times faster from its start (0.849 / 0.952 against 0.363-0.394 presents per second), a different run state; the one main run kept, 24,345 MiB, collapsed in scene (its streak window at 0.77 of its walk rate) and is invalid under both readings. They stay in the level-load pairs below because that divergence begins at the walk start, after the window those pairs read. The capture pair: main 24,371, this PR 25,134; both include the trace buffers: at APS5_TRACE_EVENTS=4194304 every thread bound at the default capacity gets one (the five queue workers, the draw committer and the presenter), 160 MiB each at 40 bytes per event (TraceThread::Slice: two pointers, a time point, a duration and a batch id), 1,120 MiB in all, the same on both sides. The memo's host-memory bound from the code: APS5_TABLE_COLUMN_MEMO_WORDS, default 33,554,432 4-byte words (128 MiB) of estimated footprint, counted per entry as sizeof(ColumnResolution) + 160 bytes plus its modes, codes (4 B each), words (sizeof(DescriptorValue) each), decodes and elements, rounded up to words; 4,096 entries at most; least recently used entries leave first; an entry over the budget is never kept. With the sizes on this build (ColumnResolution 248 B, ImageResource 96 B, DescriptorValue 40 B, ColumnDecode 12 B, ColumnResolutionElement 64 B) a 64-record column with 64 distinct elements and 12 runtime modes costs 2,310 words (9,240 bytes): 390 words fixed plus 30 per record. So the 4,096-entry cap binds before the budget for columns of that size (9.5 M words at the cap), and the budget binds first for columns past about 260 records. The estimate counts a snapshot block once per entry that pins it, so it is an upper bound on what the memo keeps alive beyond the snapshot.

Device memory at the level load. Two quantities: adriadam10's figures are the memory outside the texture caches; ours, for the series on main, is the 1 s peak of nvidia-smi memory used by all processes between the resume and frame 1,055, with the memory outside the texture caches read at the [gpu] budget line nearest that peak, and the title process's own device memory as the highest nvidia-smi pmon sample (every 5 s) in the same window. The 1,033-1,257 vs 1,206-2,528 MiB figures (outside the caches) came from the local-base series, a two-seed design: each side had its own shader disk cache, frozen NVIDIA cache and journal contents, so the PR's effect cannot be separated from the seed difference there; its journals were unequal, with the PR side loading the smaller one (base 388 pipelines / 412 modules / 1,808 MiB, this PR 379 / 403 / 1,717 MiB). For that series the cause is not established. On main c547dea, each series in one session on this machine, main always from one seed, this PR minus main:

series journals this PR's commit 1 s peak of memory used, per pair (MiB) outside the texture caches at the nearest budget line (MiB) title's own device memory, pmon (MiB)
the A/B above, three pairs, 2026-10-27 22:41 to 10-28 03:00 CET unequal (this PR 215 pipelines, main 175) f5cf0db +809 / +403 / +373 not read for this series not read for this series
three pairs to frame 1,720, 10-28 07:35-11:13 CET, the A/B's switches shared (175 / 185 / 884.5 MiB) f5cf0db +83 / −434 / +118 −147 / +89 / +1,888 (pair 3's main line is 26 s from the peak) −173 / −123 / −14
five pairs stopped at frame 1,100, 10-28 13:41-16:30 CET, the A/B's switches shared dc1e7e5 −214 / +445 / −77 / −541 / +133 +109 / −187 / −511 / +257 / −62 (pair 5's main line is 37 s from the peak) +226 / +577 / +184 / +101 / +23
the capture pair above, trace switches, one run per side, 10-28 12:04-13:34 CET, reported separately shared dc1e7e5 +841 (9,883 against 9,042) −574 −9

The shared-journal series' PR seed was made with main's journal records and NVIDIA cache and has its own shader disk cache. Over the eight shared-journal pairs main 9,321 MiB (8,878-9,787) against this PR 9,260 MiB (8,990-9,759); without the three-pair series' pair 3, whose main run had six shader disk cache misses, 7 / 7: 9,384 against 9,298. Both groupings, 8 / 8 and 7 / 7, were declared before the five-pair series ran; both include that series' four runs which the same declaration's disk-cache rule makes invalid, and the declaration did not say how to treat them (the 8 / 8 grouping also includes the three-pair series' main run with six misses that the 7 / 7 grouping leaves out). The sign is not consistent across pairs; the one series in which every pair had this PR higher, by +373 to +809 MiB, is the one with unequal journals. Four of the eight pairs have a run on one or both sides with 4 to 6 shader disk cache misses, all in the first 10 s of the run (the boot) and none later; the cause of those misses was not chased. Grouped after seeing the data: the four pairs without such a run give +445 / −541 / +83 / −434 MiB (means main 9,514, this PR 9,402), the four with one give −214 / −77 / +133 / +118 MiB. The capture pair is outside every pair above. Host placements by frame 1,055, the counterpart of the local-base series' 3 of 6 against 1 of 6: main in 2 of its 8 shared-journal runs (five-pair series pair 1, [bufferpool] at least 3; three-pair series pair 1, [bufferpool] at least 1), this PR in 3 of 8 (five-pair series pair 2, [gpu] at least 3 and [bufferpool] at least 1; five-pair series pair 5, [bufferpool] at least 1; three-pair series pair 1, [bufferpool] at least 1); the capture pair: this PR [gpu] at least 8, main none.

Tests. Tests only, no runtime change (dc1e7e5 adds to tests/ShaderMemory.cpp and the registrations; the shader cache source version is unchanged). agc_shader_table_column_memo_placement and _placement_before: thirty selected single-record tables and one merged column in one resolution, the merged column resolved after or before the selected ones; its narrowed domain binds its 65 keyed records and record 0, thirty of its records equal the selected tables' records and must land on the same elements, record 0 gets an element of its own, 66 elements in all, with the replayed resolution equal to the plain one (_placement_off runs the first order with the memo off). agc_shader_table_column_memo_evicted_by_count: 4,096 distinct contents, then a content past the cap evicts the least recently used one, read through hits and misses: the entry replayed just before the cap survives, the oldest unreplayed one misses, a younger one still hits. _evicted_by_budget (APS5_TABLE_COLUMN_MEMO_WORDS=65536): 200 contents with the first one replayed after every insertion; the newest hits, the least recently used one (the second) misses, the first still hits. _oversize_entry (APS5_TABLE_COLUMN_MEMO_WORDS=0x1): the same content misses three times, nothing is kept. agc_shader_table_column_memo_words*: the same column resolved twice per registered value; the memo keeps the column on the second resolution (unset, 1048576, 0x100000) or the first resolution fails with APS5_TABLE_COLUMN_MEMO_WORDS is not a positive word count (0, -1, empty, abc, 12x, a 20-digit overflow). ctest -R '^agc' on this head: 1,073 passed, 10 skipped, 1 failed of 1,084 (the failure is agc_driver_mesh_barycentric_emulation, which fails the same way on main c547dea on this machine); validation layers (VK_INSTANCE_LAYERS=VK_LAYER_KHRONOS_validation ANYPS5_NO_SHADER_CACHE=1 ANYPS5_REQUIRE_VULKAN=1 ctest -R '^agc_shader_' -V): 37/37 on main c547dea and 58/58 on this head (the 21 extra are the column memo tests), no was not found but was requested by env var VK_INSTANCE_LAYERS line, no VUID- line on either.

#7223. My comment on #7223 (#7223 (comment)) describes the conflict (one content conflict in ResourceMaterializer.cpp, four hunks) and proposes what the second of the two to land does: keep the pointer-keyed parent column out of the memo (its child tables still go through the resolution as ordinary columns), or key the memo on the child content; it asks yabanana for a preference on which goes first, and commits to running the column memo tests and the nested-table tests together on the combined tree before merge. The body's checklist will carry Depends on: none; related: #7223 (what the second to land changes, proposed there).

Stack disclosure: in every run on main (the capture pair, the A/B and the two shared-journal series) the title executable is unedited; the local-base series quoted for the 1,033-1,257 / 1,206-2,528 MiB figures ran the executable edit described in #6172. Every run on main: APS5_TIME_SCALE=0.1, scripted input, warm caches copied per run from a seed run per side, the NVIDIA shader disk cache on with a per-run directory, a 16 GiB cap and cleanup skipped, swap off for the title's scope; APS5_PROFILE_DRAW=1 with APS5_TRACE_SUMMARY_EVERY=60 logging in the A/B and the two shared-journal series quoted for Populate, VmHWM and the level load, not in the capture pair.

AI-assisted: yes (Claude Code)

@github-actions github-actions Bot removed perf numbers missing perf pull request without a before and after summary line needs rebase Conflicts with main, rebase needed labels Oct 28, 2026

@adriadam10 adriadam10 left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for the tests and the full report. The tests cover what was asked and the hash fix is right. What is still open is the case for the change itself:

  • No measured gain on main. Your own numbers: Populate drops 171 → 68 ms per frame, but frames are ~2.8 s and the A/B walk rate is 0.360 vs 0.352 presents/s (within spread). The only capture pair on main has this PR slower (p50 +6.3 %, p99 +12.7 %, max +59 %, GPU busy +4.2 %), one run per side. The +11.5 % figure was only on a local base. A perf PR needs a gain that reproduces on main: more capture pairs (or a scene where Populate is on the critical path) showing it beats the spread, not one pair against three.
  • Device memory at the level load is still unexplained. The capture pair peaks at 9,883 MiB against 9,042 MiB (+841 MiB, above your own 9,850 MiB limit) with host placements only on this side; the shared-journal series is mixed in sign. Please show with more pairs that it is noise, or find the cause.
  • Cost vs benefit. The change adds a ~570-line memo in ResourceMaterializer.cpp, a 128 MiB host budget, 4 env switches (APS5_NO_TABLE_COLUMN_MEMO, APS5_VERIFY_TABLE_COLUMN_MEMO, APS5_TABLE_COLUMN_MEMO_DIAG, APS5_TABLE_COLUMN_MEMO_WORDS) and 22 ctest entries. Without a frame-time gain that is not justified; if you can't show one, please close this or reduce it to what pays for itself.
  • Retitling without perf doesn't change this: the memory and complexity cost needs a benefit that is measured.

@SleglJan
SleglJan marked this pull request as draft October 28, 2026 18:39
@SleglJan

Copy link
Copy Markdown
Contributor Author

@adriadam10 thanks, agreed. I'm converting this to draft and running three more capture pairs: main f8f5b24 (the merge base of the current head) against c5dcde9, alternated, one shared journal on both sides, validity rules fixed before the first run. It counts as a gain only if each of this PR's three frame p50s is below the lowest main p50; otherwise I'll close this. I'll post the summary lines, the digests and the level-load peaks either way, and if this PR's peak is above main's in all three pairs I'll look for the cause before asking for another review.

AI-assisted: yes (Claude Code)

@SleglJan

Copy link
Copy Markdown
Contributor Author

@adriadam10 @oneandonlydean The three capture pairs promised in the comment above: main f8f5b24 (the merge base of this PR's head) against this PR at c5dcde9, alternated main / PR three times on 2026-10-29 from 01:33 to 05:44 CET in one boot, one run per side per pair, no build and no other title run between them. Captured on this machine (CachyOS, kernel 7.2.10, NVIDIA GeForce RTX 3080, driver 615.78.08, Ryzen 9 7950X3D, 64 GB, Release builds, both trees clean at their heads), 007 First Light (PPSA11386), the walk after the resume of the first level, the title executable unedited, scripted input, the log written to a file; APS5_TRACE_FRAMES=1085:150, APS5_TRACE_EVENTS=4194304 (buffer size only), APS5_TRACE_DIR (the output directory) and APS5_TIME_SCALE=0.1 on both sides, no other APS5_TRACE_* and no APS5_PROFILE_* switch, SDL_VIDEODRIVER=x11 on both sides, the NVIDIA shader disk cache on, pointed at a per-run directory (16 GiB cap, cleanup skipped), the title in a scope with swap turned off. Caches copied per run from a seed run per side (each run writes only to its copy; the seeds are read-only and matched their sha256 lists before and after every run): main from its own seed; this PR from a copy of its seed whose pipeline journal carries main's records (the header's source version set to this PR's, 2584ed73f4eb855c → c6647b323b4214db, the records byte-identical) and whose NVIDIA shader disk cache is a copy of main's seed's (the two seeds' NVIDIA caches differed in content), so the journal records and the NVIDIA cache are identical on both sides and only the shader disk cache is each side's own. Validity rules V1–V8 were fixed before the first run (listed below); all six runs pass them, and tools/performance_compare.py --require-matching-context accepts each pair's two lines.

Pair main p50 (ms) PR p50 (ms) PR − main (ms) level-load 1 s peak memory.used, main / PR (MiB) PR − main (MiB)
1 2,639.8 2,728.2 +88.4 8,960 / 9,726 +766
2 2,828.5 2,451.6 −376.9 9,246 / 9,810 +564
3 2,605.9 2,684.2 +78.3 8,976 / 9,476 +500

p50 = frame_ms.p50 of the run's window line (150 presents from present 1085), as printed. The level-load 1 s peak is the highest 1 s memory.used sample (all processes) from the Resume press up to the first frame event at or past f1055 (not included), as in the earlier series. The title process's own peak in the same window (nvidia-smi pmon, 5 s samples), PR − main: −65, −48, −111 MiB (main 8,443, 8,433, 8,410; PR 8,378, 8,385, 8,299).

The rule, from that comment: "It counts as a gain only if each of this PR's three frame p50s is below the lowest main p50; otherwise I'll close this." The lowest main p50 is 2,605.9 ms (pair 3); pairs 1 and 3's PR p50s (2,728.2 and 2,684.2 ms) are above it, so the rule is not met. Closing this as stated. The three main p50s span 2,605.9 to 2,828.5 ms. This PR's level-load peak is above main's in all three pairs (+766, +564, +500 MiB). That is the case in which I said I'd look for the cause. The cause is not established by these runs; with this closed, I'm not asking for another review.

Window lines, main first in each pair

Pair 1, main f8f5b24 (cp12051-B-1):

{"commit":"f8f5b24b77ad","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TIME_SCALE":"0.1","APS5_TRACE_DIR":"<path>","APS5_TRACE_EVENTS":"4194304","APS5_TRACE_FRAMES":"1085:150"},"gpu":"NVIDIA GeForce RTX 3080","driver":"NVIDIA 615.78.08","os":"Linux 7.2.10-1-cachyos","cpu":"AMD Ryzen 9 7950X3D 16-Core Processor","cpu_threads":32,"memory_mib":63428,"title_id":"PPSA11386","title":"007 First Light","content_version":"01.018.000","resolution":"3840x2160","window":{"spec":"frames 1085:150","first_present":1085,"ms":407238.833},"presents":150,"frame_ms":{"p50":2639.830,"p90":3155.179,"p99":4478.997,"max":4619.159},"gpu_busy_ms_per_present":465.909,"worker_busy_pct":{"queue worker 0x0":99.939,"queue worker 0x20":99.888,"queue worker 0x28":99.786,"queue worker 0x30":99.825,"queue worker 0x38":87.430},"top_phases_ms_per_frame":{"Driver.Packet":13183.350,"Driver.Packet.memory_wait":8848.245,"GpuMutex.wait.hook":2427.414,"Driver.Packet.dispatch":2406.809,"Driver.Dispatch":2145.158,"Resources.Complete":1926.502,"Driver.Packet.draw":1690.764,"Driver.Draw":1690.066},"trace_dropped":false,"trace":"aps5-trace-f8f5b24b77ad-2.json.gz"}

Pair 1, this PR c5dcde9 (cp12051-C-1):

{"commit":"c5dcde982eb6","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TIME_SCALE":"0.1","APS5_TRACE_DIR":"<path>","APS5_TRACE_EVENTS":"4194304","APS5_TRACE_FRAMES":"1085:150"},"gpu":"NVIDIA GeForce RTX 3080","driver":"NVIDIA 615.78.08","os":"Linux 7.2.10-1-cachyos","cpu":"AMD Ryzen 9 7950X3D 16-Core Processor","cpu_threads":32,"memory_mib":63428,"title_id":"PPSA11386","title":"007 First Light","content_version":"01.018.000","resolution":"3840x2160","window":{"spec":"frames 1085:150","first_present":1085,"ms":411524.710},"presents":150,"frame_ms":{"p50":2728.224,"p90":3171.006,"p99":4191.625,"max":4261.778},"gpu_busy_ms_per_present":472.881,"worker_busy_pct":{"queue worker 0x0":99.920,"queue worker 0x20":99.884,"queue worker 0x28":99.796,"queue worker 0x38":82.066,"queue worker 0x30":99.824},"top_phases_ms_per_frame":{"Driver.Packet":13165.727,"Driver.Packet.memory_wait":8864.371,"GpuMutex.wait.hook":2545.316,"Driver.Packet.dispatch":2326.633,"Driver.Dispatch":2052.613,"Resources.Complete":1983.210,"Graphics.Draw":1751.883,"Driver.Packet.draw":1728.312},"trace_dropped":false,"trace":"aps5-trace-c5dcde982eb6-2.json.gz"}

Pair 2, main f8f5b24 (cp12051-B-2):

{"commit":"f8f5b24b77ad","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TIME_SCALE":"0.1","APS5_TRACE_DIR":"<path>","APS5_TRACE_EVENTS":"4194304","APS5_TRACE_FRAMES":"1085:150"},"gpu":"NVIDIA GeForce RTX 3080","driver":"NVIDIA 615.78.08","os":"Linux 7.2.10-1-cachyos","cpu":"AMD Ryzen 9 7950X3D 16-Core Processor","cpu_threads":32,"memory_mib":63428,"title_id":"PPSA11386","title":"007 First Light","content_version":"01.018.000","resolution":"3840x2160","window":{"spec":"frames 1085:150","first_present":1085,"ms":431649.655},"presents":150,"frame_ms":{"p50":2828.455,"p90":3302.503,"p99":4231.105,"max":4354.292},"gpu_busy_ms_per_present":503.631,"worker_busy_pct":{"queue worker 0x0":99.937,"queue worker 0x20":99.891,"queue worker 0x28":99.795,"queue worker 0x38":82.988,"queue worker 0x30":99.832},"top_phases_ms_per_frame":{"Driver.Packet":13847.888,"Driver.Packet.memory_wait":9462.661,"GpuMutex.wait.hook":2474.951,"Driver.Packet.dispatch":2279.130,"Driver.Dispatch":2038.701,"Resources.Complete":2011.380,"Driver.Packet.draw":1852.938,"Driver.Draw":1852.213},"trace_dropped":false,"trace":"aps5-trace-f8f5b24b77ad-2.json.gz"}

Pair 2, this PR c5dcde9 (cp12051-C-2):

{"commit":"c5dcde982eb6","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TIME_SCALE":"0.1","APS5_TRACE_DIR":"<path>","APS5_TRACE_EVENTS":"4194304","APS5_TRACE_FRAMES":"1085:150"},"gpu":"NVIDIA GeForce RTX 3080","driver":"NVIDIA 615.78.08","os":"Linux 7.2.10-1-cachyos","cpu":"AMD Ryzen 9 7950X3D 16-Core Processor","cpu_threads":32,"memory_mib":63428,"title_id":"PPSA11386","title":"007 First Light","content_version":"01.018.000","resolution":"3840x2160","window":{"spec":"frames 1085:150","first_present":1085,"ms":375957.074},"presents":150,"frame_ms":{"p50":2451.578,"p90":2926.542,"p99":3471.788,"max":4043.945},"gpu_busy_ms_per_present":418.902,"worker_busy_pct":{"queue worker 0x0":99.938,"queue worker 0x20":99.903,"queue worker 0x28":99.809,"queue worker 0x30":99.843,"queue worker 0x38":85.649},"top_phases_ms_per_frame":{"Driver.Packet":12119.899,"Driver.Packet.memory_wait":8117.253,"GpuMutex.wait.hook":2322.025,"Driver.Packet.dispatch":2184.985,"Driver.Dispatch":1945.673,"Resources.Complete":1827.441,"Graphics.Draw":1577.501,"Driver.Packet.draw":1561.313},"trace_dropped":false,"trace":"aps5-trace-c5dcde982eb6-2.json.gz"}

Pair 3, main f8f5b24 (cp12051-B-3):

{"commit":"f8f5b24b77ad","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TIME_SCALE":"0.1","APS5_TRACE_DIR":"<path>","APS5_TRACE_EVENTS":"4194304","APS5_TRACE_FRAMES":"1085:150"},"gpu":"NVIDIA GeForce RTX 3080","driver":"NVIDIA 615.78.08","os":"Linux 7.2.10-1-cachyos","cpu":"AMD Ryzen 9 7950X3D 16-Core Processor","cpu_threads":32,"memory_mib":63428,"title_id":"PPSA11386","title":"007 First Light","content_version":"01.018.000","resolution":"3840x2160","window":{"spec":"frames 1085:150","first_present":1085,"ms":396172.640},"presents":150,"frame_ms":{"p50":2605.890,"p90":3040.989,"p99":3369.986,"max":4454.722},"gpu_busy_ms_per_present":441.490,"worker_busy_pct":{"queue worker 0x0":99.940,"queue worker 0x20":99.892,"queue worker 0x28":99.780,"queue worker 0x30":99.819,"queue worker 0x38":85.230},"top_phases_ms_per_frame":{"Driver.Packet":12768.100,"Driver.Packet.memory_wait":8637.775,"GpuMutex.wait.hook":2291.509,"Driver.Packet.dispatch":2227.289,"Driver.Dispatch":1985.304,"Resources.Complete":1856.957,"Driver.Packet.draw":1660.973,"Driver.Draw":1660.274},"trace_dropped":false,"trace":"aps5-trace-f8f5b24b77ad-2.json.gz"}

Pair 3, this PR c5dcde9 (cp12051-C-3):

{"commit":"c5dcde982eb6","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TIME_SCALE":"0.1","APS5_TRACE_DIR":"<path>","APS5_TRACE_EVENTS":"4194304","APS5_TRACE_FRAMES":"1085:150"},"gpu":"NVIDIA GeForce RTX 3080","driver":"NVIDIA 615.78.08","os":"Linux 7.2.10-1-cachyos","cpu":"AMD Ryzen 9 7950X3D 16-Core Processor","cpu_threads":32,"memory_mib":63428,"title_id":"PPSA11386","title":"007 First Light","content_version":"01.018.000","resolution":"3840x2160","window":{"spec":"frames 1085:150","first_present":1085,"ms":409847.870},"presents":150,"frame_ms":{"p50":2684.171,"p90":3184.105,"p99":3644.970,"max":4145.218},"gpu_busy_ms_per_present":467.834,"worker_busy_pct":{"queue worker 0x0":99.941,"queue worker 0x20":99.922,"queue worker 0x38":80.339,"queue worker 0x28":99.827,"queue worker 0x30":99.855},"top_phases_ms_per_frame":{"Driver.Packet":13072.828,"Driver.Packet.memory_wait":8937.961,"GpuMutex.wait.hook":2419.026,"Driver.Packet.dispatch":2149.819,"Resources.Complete":1961.375,"Driver.Dispatch":1886.346,"Graphics.Draw":1753.861,"Driver.Packet.draw":1750.046},"trace_dropped":false,"trace":"aps5-trace-c5dcde982eb6-2.json.gz"}
Per run: route and trace window (validity), memory (recorded only)

Six runs in order, each a fresh title start from the copied caches; times CET. Level-load window = Resume press to the first frame event at or past f1055. Memory counts are given twice: in that window and over the whole run (title start to exit).

Run Title ran Resume → gameplay start (s; added after the data) Route Walk start (first lit shot) Prompt onset from Trace window f1086–f1235 (V7) Level-load 1 s peak MiB (s from the title's start, frame) Title peak MiB in the same window (nvidia-smi pmon, 5 s samples; its s) Outside the texture caches at the budget line nearest the peak, MiB (offset s) Host placements at f1055 Recovered −2 / other vkAllocateMemory failure lines, level-load window The same, whole run Staging-shadow refusal lines, whole run Max RSS MiB (highest VmHWM, 10 s samples, whole run)
cp12051-B-1, main f8f5b24 01:33–02:15 30 on route f1066 f1283 holds (after f1066, before f1283) 8,960 (734 s, f1050) 8,443 (733 s) 2,649 (−13) none 9 / 0 22 / 0 0 21,634
cp12051-C-1, this PR c5dcde9 02:16–02:59 31 on route f1050 f1280 holds (after f1050, before f1280) 9,726 (663 s, f1017) 8,378 (702 s) 2,380 (0) [gpu] 2 (2 MiB) 8 / 0 73 / 2 2 22,388
cp12051-B-2, main f8f5b24 03:01–03:40 61 on route f1066 f1278 holds (after f1066, before f1278) 9,246 (685 s, f1038) 8,433 (712 s) 1,077 (0) none 5 / 0 55 / 4 4 22,687
cp12051-C-2, this PR c5dcde9 03:42–04:20 30 on route f1060 f1298 holds (after f1060, before f1298) 9,810 (684 s, f1035) 8,385 (727 s) 2,484 (−1) [bufferpool] 2 (20 MiB), [gpu] 1 (36 MiB) 15 / 3 102 / 4 4 21,689
cp12051-B-3, main f8f5b24 04:22–05:00 30 on route f1064 f1303 holds (after f1064, before f1303) 8,976 (694 s, f1049) 8,410 (692 s) 2,714 (−5) none 3 / 0 29 / 4 4 21,406
cp12051-C-3, this PR c5dcde9 05:01–05:44 61 on route f1075 f1313 holds (after f1075, before f1313) 9,476 (671 s, f1049) 8,299 (642 s) 2,516 (−1) none 10 / 0 72 / 2 2 22,713

Exhaustion triggers (1 s memory.used ≥ 9,850 MiB, recovered −2 ≥ 100, [gpu] placements ≥ 64, [bufferpool] ≥ 256, any other unrecovered vkAllocateMemory failure) are recorded, not validity rules. In the level-load window C-2 trips the last one (3 lines) and no run trips any other. Over the whole run C-2 trips recovered −2 ≥ 100 (102 lines), and C-1, B-2, C-2, B-3 and C-3 trip the last one (2, 4, 4, 4, 2 lines); the whole-run 1 s peaks are 9,661 / 9,726 / 9,571 / 9,810 / 9,493 / 9,745 MiB in run order, and no placement count reaches its limit. In every run the other failure lines are the staging-shadow refusal lines ([buffers] staging shadow of … refused); the source prints at most four of those per run and, without APS5_PROFILE_DRAW, not their cumulative count, so the counts of 4 are lower bounds. Host placements at f1055 are the count and size in the source's last "N such allocations, M MiB" line by then, counted from the title's start; those lines print at counts 1 to 5 and at powers of two, so counts up to 4 are exact. "Outside the texture caches" is the budget line's heap use minus its sampled textures and cached storage images, on the [gpu] sampled texture cache budget line nearest the peak second (it prints on budget moves, so the offset says how far from the peak that line is). Every run: 0 signal lines, 0 NVRM Xid lines, no device loss; one pipeline-journal load line ("loaded 228 pipelines and 243 modules (928.2 MiB)") with no suffix; shader disk cache misses only on the first 10 s line (main 4 misses against 2,209 hits on each run; this PR 4, 0, 0 against 2,213) and 0 on every later line; the harness's exit code 2 with only the two known check failures of V1; desktop baseline 424 MiB before each run.

Declared extras, not tests (PR − main per pair; then per-side mean (min–max), main / PR): frame p90 +15.8 / −376.0 / +143.1 ms, 3,166.2 (3,041.0–3,302.5) / 3,093.9 (2,926.5–3,184.1); mean frame (window ms / presents) +28.6 / −371.3 / +91.2 ms, 2,744.6 (2,641.2–2,877.7) / 2,660.7 (2,506.4–2,743.5); GPU busy per present +7.0 / −84.7 / +26.3 ms, 470.3 (441.5–503.6) / 453.2 (418.9–472.9); presents per second over the trace window (150 / window s) −0.004 / +0.051 / −0.013, 0.365 (0.348–0.379) / 0.376 (0.364–0.399). The earlier shared-journal series on main c547dea (the three pairs to frame 1,720, the five pairs stopped at frame 1,100 and the capture pair) are in the reply above, on different builds; they are not pooled with these.

Validity rules, fixed before the first run
  • V1 harness exit: exit code 0, or exit code 2 whose only check failures are the two known ones of these captures: the switch-set check (the harness's record of the title's environment writes the APS5_TRACE_DIR path as <path>) and the memo-line check (the [recompile] result memo lines print only with APS5_PROFILE_DRAW).
  • V2 faults: 0 signal lines, 0 NVRM Xid lines, no device loss.
  • V3 shader disk cache: misses only on the first 10 s line (boot), at most 16; any later miss invalidates the run (more misses than hits on a line stays a hard failure under V1).
  • V4 journal: exactly one "loaded N pipelines and M modules" line with no suffix, N / M / size the same on every run of both sides (B-1 sets them).
  • V5 desktop: baseline ≤ 430 MiB before the run, no Discord / remote-desktop flag.
  • V6 route: on route by the shot check (prompt onset found, the +50 shot matches the reference), walk start from the first lit shot.
  • V7 trace capture: one window line with the build's revision, dirty false, 150 presents, nothing dropped; the window starts at or after the first lit shot and ends before the prompt onset's first frame.
  • V8 line check: tools/performance_compare.py <main line> <PR line> --require-matching-context accepts the pair.
  • Recorded, never a validity item: exhaustion triggers, host placements, recovered −2 lines, staging-shadow lines, and collapse (not judgeable on these captures). They are outcomes of the build under test, and the level-load peak is the memory question itself; this differs from the earlier capture pair, where these limits decided validity. With fewer than three valid pairs after pair 3, up to two extra pairs would have run; none was needed.
Two other GPU jobs between title runs

Two jobs of ours ran on the RTX 3080 between title runs, each one run of two prebuilt #10333 test binaries (agc_write_tracking_tests and agc_driver_recorder_tests --repeated-neighbour-stores-only; no build, no title): 01:32:19–01:32:29 CET, after this PR's seed run and before pair 1, and 03:00:19–03:00:29 CET, between pair 1 and pair 2. Otherwise our job queue ran only the six title runs and the series' own file steps between them (copying outputs, validity checks, digests), none of which uses the GPU.

The six trace digests (tools/trace_digest.py) follow in the next comment; the traces are not posted (the comment above promised the summary lines, the digests and the level-load peaks).

AI-assisted: yes (Claude Code)

@SleglJan

Copy link
Copy Markdown
Contributor Author

The six digests of the capture pairs in the comment above (python3 tools/trace_digest.py on each trace). The traces are not posted; the earlier comment promised the summary lines, the digests and the level-load peaks:

trace_digest, pair 1, main f8f5b24 (cp12051-B-1)

frames 1085:150 from present 1085: 150 presents, frame p50 2639.8 / p90 3155.2 / p99 4479.0 / max 4619.2 ms, GPU busy 465.9 ms per present
NVIDIA GeForce RTX 3080, NVIDIA 615.78.08, Linux 7.2.10-1-cachyos, 3840x2160, commit f8f5b24, dropped: no

{"commit":"f8f5b24b77ad","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TIME_SCALE":"0.1","APS5_TRACE_DIR":"<path>","APS5_TRACE_EVENTS":"4194304","APS5_TRACE_FRAMES":"1085:150"},"gpu":"NVIDIA GeForce RTX 3080","driver":"NVIDIA 615.78.08","os":"Linux 7.2.10-1-cachyos","cpu":"AMD Ryzen 9 7950X3D 16-Core Processor","cpu_threads":32,"memory_mib":63428,"title_id":"PPSA11386","title":"007 First Light","content_version":"01.018.000","resolution":"3840x2160","window":{"spec":"frames 1085:150","first_present":1085,"ms":407238.833},"presents":150,"frame_ms":{"p50":2639.83,"p90":3155.179,"p99":4478.997,"max":4619.159},"gpu_busy_ms_per_present":465.909,"worker_busy_pct":{"queue worker 0x0":99.939,"queue worker 0x20":99.888,"queue worker 0x28":99.786,"queue worker 0x30":99.825,"queue worker 0x38":87.43},"top_phases_ms_per_frame":{"Driver.Packet":13183.35,"Driver.Packet.memory_wait":8848.245,"GpuMutex.wait.hook":2427.414,"Driver.Packet.dispatch":2406.809,"Driver.Dispatch":2145.158,"Resources.Complete":1926.502,"Driver.Packet.draw":1690.764,"Driver.Draw":1690.066},"trace_dropped":false,"trace":"aps5-trace-f8f5b24b77ad-2.json.gz"}

Slowest frames (largest slices inside each, inclusive)

  • present 1225: 4619.2 ms at 373314 ms: Driver.Packet (queue worker 0x30) 4618.9, Driver.Packet (queue worker 0x28) 4618.8, Driver.Packet (queue worker 0x20) 4618.5, Driver.Packet (queue worker 0x0) 4532.0
  • present 1227: 4479.0 ms at 381893 ms: Driver.Packet (queue worker 0x28) 4478.8, Driver.Packet (queue worker 0x30) 4478.7, Driver.Packet (queue worker 0x20) 4478.4, Driver.Packet (queue worker 0x0) 4397.7
  • present 1112: 4185.3 ms at 77329 ms: Driver.Packet (queue worker 0x30) 4185.1, Driver.Packet (queue worker 0x28) 4185.1, Driver.Packet (queue worker 0x20) 4184.7, Driver.Packet (queue worker 0x0) 4148.0
  • present 1229: 4096.8 ms at 389570 ms: Driver.Packet (queue worker 0x28) 4096.6, Driver.Packet (queue worker 0x30) 4096.4, Driver.Packet (queue worker 0x20) 4096.2, Driver.Packet (queue worker 0x0) 4015.2
  • present 1226: 3959.4 ms at 377933 ms: Driver.Packet (queue worker 0x28) 3959.0, Driver.Packet (queue worker 0x20) 3958.8, Driver.Packet (queue worker 0x30) 3956.8, Driver.Packet.memory_wait (queue worker 0x28) 3897.4

Threads (ms per frame)

thread busy wait untraced in slices < 20 us largest
shader prepare 0.1 (0 %) 0.0 (0 %) 2714.8 0.0 Vulkan.GraphicsPipelinePrebuild 0.1, Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2714.9 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.3 (0 %) 0.0 (0 %) 2714.7 0.0 Vulkan.ComputePipeline 0.2, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2714.9 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2714.9 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2714.9 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.1 (0 %) 0.0 (0 %) 2714.9 0.0 Vulkan.ComputePipeline 0.1
shader prepare 0.1 (0 %) 0.0 (0 %) 2714.8 0.0 Vulkan.GraphicsPipelinePrebuild 0.1, Vulkan.ComputePipeline 0.0
shader prepare 0.1 (0 %) 0.0 (0 %) 2714.9 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2714.9 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.1 (0 %) 0.0 (0 %) 2714.9 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2714.9 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2714.9 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2714.9 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2714.9 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2714.9 0.0 Vulkan.GraphicsPipelinePrebuild 0.0, Vulkan.ComputePipeline 0.0
title 0.9 (0 %) 0.1 (0 %) 2714.0 0.6 Shader.ResolveAbi 0.4, Shader.ResolveGraphicsStagesAbi 0.3
queue worker 0x0 2540.6 (94 %) 164.9 (6 %) 9.4 99.9 Driver.Packet 2678.5, Driver.EndSubmission 27.1
draw committer 1437.0 (53 %) 204.6 (8 %) 1073.3 12.1 Graphics.Draw 1409.6, Recorder.Submit 19.6
presenter 1.3 (0 %) 11.8 (0 %) 2701.8 0.1 VideoOut.Flip 13.1, Driver.Present 0.1
title 0.4 (0 %) 0.0 (0 %) 2714.5 0.3 Shader.ResolveAbi 0.2, Shader.ResolveGraphicsStagesAbi 0.1
title 0.3 (0 %) 0.0 (0 %) 2714.6 0.3 Shader.ResolveGraphicsStagesAbi 0.2, Shader.ResolveGraphicsAbi 0.0
title 0.1 (0 %) 0.0 (0 %) 2714.8 0.3 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveGraphicsAbi 0.0
queue worker 0x20 170.8 (6 %) 2541.2 (94 %) 2.9 3.0 Driver.Packet 2710.4, Driver.EndSubmission 1.0
title 0.2 (0 %) 0.0 (0 %) 2714.7 0.3 Shader.ResolveGraphicsAbi 0.1, Shader.ResolveGraphicsStagesAbi 0.1
title 0.3 (0 %) 0.0 (0 %) 2714.7 0.3 Shader.ResolveGraphicsStagesAbi 0.2, Shader.ResolveAbi 0.1
title 0.2 (0 %) 0.0 (0 %) 2714.7 0.3 Shader.ResolveAbi 0.1, Shader.ResolveGraphicsStagesAbi 0.1
title 0.3 (0 %) 0.0 (0 %) 2714.6 0.3 Shader.ResolveGraphicsStagesAbi 0.2, Shader.ResolveAbi 0.1
queue worker 0x28 35.6 (1 %) 2674.1 (98 %) 5.2 1.6 Driver.Packet 2708.5, Driver.EndSubmission 0.4
queue worker 0x30 72.2 (3 %) 2639.0 (97 %) 3.7 1.3 Driver.Packet 2710.0, Driver.EndSubmission 0.0
queue worker 0x38 75.4 (3 %) 2631.8 (97 %) 7.7 2.7 Driver.Packet 2367.1, Driver.EndSubmission 6.1
title 0.3 (0 %) 0.0 (0 %) 2714.6 0.3 Shader.ResolveAbi 0.2, Shader.ResolveGraphicsStagesAbi 0.1
gpu 469.1 (17 %) 0.0 (0 %) 2245.9 0.0 batch 469.1

Largest slices (ms per frame, inclusive, all threads): Driver.Packet 13174.5, Driver.Packet.memory_wait 8848.0, GpuMutex.wait.hook 2427.2, Driver.Packet.dispatch 2406.3, Driver.Dispatch 2144.0, Resources.Complete 1925.3, Driver.Packet.draw 1689.7, Driver.Draw 1689.0, Graphics.Draw 1677.7, Graphics.Draw.draw_and_resource_release 1642.4

Longest waits

  • Driver.Packet.memory_wait (queue worker 0x38) 3107.0 ms at 383286 ms, present 1227
  • Driver.Packet.memory_wait (queue worker 0x38) 2966.6 ms at 374985 ms, present 1225
  • Driver.Packet.memory_wait (queue worker 0x28) 2734.8 ms at 383658 ms, present 1227
  • Driver.Packet.memory_wait (queue worker 0x38) 2647.4 ms at 391035 ms, present 1229
  • Driver.Packet.memory_wait (queue worker 0x28) 2526.2 ms at 375425 ms, present 1225
  • Driver.Packet.memory_wait (queue worker 0x28) 2346.3 ms at 391336 ms, present 1229
  • Driver.Packet.memory_wait (queue worker 0x38) 2340.9 ms at 379563 ms, present 1226
  • Driver.Packet.memory_wait (queue worker 0x20) 2324.7 ms at 383549 ms, present 1227
  • Driver.Packet.memory_wait (queue worker 0x38) 2292.2 ms at 76175 ms, present 1111
  • Driver.Packet.memory_wait (queue worker 0x38) 2249.9 ms at 292464 ms, present 1194

Largest GPU batches (GPU ranges inside, and the CPU slices that recorded each, inclusive)

  • batch 41685: 117.2 ms at 375540 ms, present 1225: GPU no ranges; recorded by Vulkan.Dispatch.shader_resources (queue worker 0x0) 105.9, Resources.Complete (queue worker 0x0) 105.4, Driver.Packet (queue worker 0x0) 62.3, Driver.Packet.dispatch (queue worker 0x0) 62.3
  • batch 12346: 114.2 ms at 116541 ms, present 1125: GPU no ranges; recorded by Recorder.Sync (queue worker 0x0) 114.3, Driver.Packet (queue worker 0x0) 31.9, Driver.Packet.dispatch (queue worker 0x0) 30.8, Driver.Dispatch (queue worker 0x0) 30.1
  • batch 41145: 111.0 ms at 370471 ms, present 1223: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 80.2, Driver.Packet.dispatch (queue worker 0x0) 80.2, Driver.Dispatch (queue worker 0x0) 80.2, Vulkan.Dispatch (queue worker 0x0) 80.1
  • batch 34086: 108.1 ms at 308591 ms, present 1199: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 7.6, Driver.Packet.dispatch (queue worker 0x0) 7.6, Driver.Dispatch (queue worker 0x0) 7.6, Vulkan.Dispatch (queue worker 0x0) 7.4
  • batch 14431: 101.2 ms at 136662 ms, present 1132: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 33.0, Driver.Packet.dispatch (queue worker 0x0) 33.0, Driver.Dispatch (queue worker 0x0) 33.0, Vulkan.Dispatch (queue worker 0x0) 32.9
trace_digest, pair 1, this PR c5dcde9 (cp12051-C-1)

frames 1085:150 from present 1085: 150 presents, frame p50 2728.2 / p90 3171.0 / p99 4191.6 / max 4261.8 ms, GPU busy 472.9 ms per present
NVIDIA GeForce RTX 3080, NVIDIA 615.78.08, Linux 7.2.10-1-cachyos, 3840x2160, commit c5dcde9, dropped: no

{"commit":"c5dcde982eb6","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TIME_SCALE":"0.1","APS5_TRACE_DIR":"<path>","APS5_TRACE_EVENTS":"4194304","APS5_TRACE_FRAMES":"1085:150"},"gpu":"NVIDIA GeForce RTX 3080","driver":"NVIDIA 615.78.08","os":"Linux 7.2.10-1-cachyos","cpu":"AMD Ryzen 9 7950X3D 16-Core Processor","cpu_threads":32,"memory_mib":63428,"title_id":"PPSA11386","title":"007 First Light","content_version":"01.018.000","resolution":"3840x2160","window":{"spec":"frames 1085:150","first_present":1085,"ms":411524.71},"presents":150,"frame_ms":{"p50":2728.224,"p90":3171.006,"p99":4191.625,"max":4261.778},"gpu_busy_ms_per_present":472.881,"worker_busy_pct":{"queue worker 0x0":99.92,"queue worker 0x20":99.884,"queue worker 0x28":99.796,"queue worker 0x38":82.066,"queue worker 0x30":99.824},"top_phases_ms_per_frame":{"Driver.Packet":13165.727,"Driver.Packet.memory_wait":8864.371,"GpuMutex.wait.hook":2545.316,"Driver.Packet.dispatch":2326.633,"Driver.Dispatch":2052.613,"Resources.Complete":1983.21,"Graphics.Draw":1751.883,"Driver.Packet.draw":1728.312},"trace_dropped":false,"trace":"aps5-trace-c5dcde982eb6-2.json.gz"}

Slowest frames (largest slices inside each, inclusive)

  • present 1097: 4261.8 ms at 37529 ms: Driver.Packet (queue worker 0x30) 4261.6, Driver.Packet (queue worker 0x28) 4261.6, Driver.Packet (queue worker 0x20) 4245.0, Driver.Packet (queue worker 0x0) 4227.0
  • present 1229: 4191.6 ms at 393371 ms: Driver.Packet (queue worker 0x28) 4191.4, Driver.Packet (queue worker 0x30) 4191.3, Driver.Packet (queue worker 0x20) 4177.8, Driver.Packet.memory_wait (queue worker 0x28) 4149.3
  • present 1087: 3537.5 ms at 6551 ms: Driver.Packet (queue worker 0x30) 3537.3, Driver.Packet (queue worker 0x28) 3537.2, Driver.Packet (queue worker 0x20) 3536.8, Driver.Packet (queue worker 0x0) 3471.7
  • present 1144: 3402.1 ms at 165170 ms: Driver.Packet (queue worker 0x28) 3401.8, Driver.Packet (queue worker 0x30) 3401.8, Driver.Packet (queue worker 0x20) 3385.1, Driver.Packet (queue worker 0x0) 3356.0
  • present 1085: 3295.0 ms at 0 ms: Driver.Packet (queue worker 0x30) 3187.1, Driver.Packet (queue worker 0x28) 3187.0, Driver.Packet (queue worker 0x0) 3175.3, Driver.Packet (queue worker 0x20) 3169.7

Threads (ms per frame)

thread busy wait untraced in slices < 20 us largest
shader prepare 0.0 (0 %) 0.0 (0 %) 2743.5 0.0 Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.2 (0 %) 0.0 (0 %) 2743.3 0.0 Vulkan.GraphicsPipelinePrebuild 0.2
shader prepare 0.0 (0 %) 0.0 (0 %) 2743.5 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2743.5 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2743.5 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.1 (0 %) 0.0 (0 %) 2743.4 0.0 Vulkan.GraphicsPipelinePrebuild 0.1
shader prepare 0.0 (0 %) 0.0 (0 %) 2743.5 0.0 Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2743.5 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2743.5 0.0 Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2743.5 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2743.5 0.0 Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2743.5 0.0 Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.2 (0 %) 0.0 (0 %) 2743.3 0.0 Vulkan.GraphicsPipelinePrebuild 0.2
shader prepare 0.0 (0 %) 0.0 (0 %) 2743.5 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2743.5 0.0 Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2743.5 0.0 Vulkan.GraphicsPipelinePrebuild 0.0
title 0.8 (0 %) 0.7 (0 %) 2742.0 0.6 Shader.ResolveAbi 0.4, Shader.ResolveGraphicsStagesAbi 0.2
queue worker 0x0 2559.5 (93 %) 174.4 (6 %) 9.6 102.9 Driver.Packet 2706.5, Driver.EndSubmission 27.4
draw committer 1405.2 (51 %) 214.7 (8 %) 1123.6 12.0 Graphics.Draw 1378.1, Recorder.Submit 18.6
presenter 1.2 (0 %) 11.5 (0 %) 2730.8 0.1 VideoOut.Flip 12.2, Driver.Present 0.6
title 0.3 (0 %) 0.0 (0 %) 2743.2 0.3 Shader.ResolveGraphicsStagesAbi 0.2, Shader.ResolveGraphicsAbi 0.1
title 0.2 (0 %) 0.0 (0 %) 2743.3 0.3 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.1
title 0.2 (0 %) 0.0 (0 %) 2743.3 0.3 Shader.ResolveAbi 0.1, Shader.ResolveGraphicsStagesAbi 0.1
title 0.1 (0 %) 0.0 (0 %) 2743.4 0.2 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.0
title 0.2 (0 %) 0.0 (0 %) 2743.3 0.3 Shader.ResolveGraphicsStagesAbi 0.2, Shader.ResolveAbi 0.1
queue worker 0x20 171.4 (6 %) 2569.4 (94 %) 2.7 3.0 Driver.Packet 2731.2, Driver.EndSubmission 8.7
title 0.5 (0 %) 0.0 (0 %) 2743.0 0.2 Shader.ResolveAbi 0.4, Shader.ResolveGraphicsStagesAbi 0.1
title 0.2 (0 %) 0.0 (0 %) 2743.3 0.3 Shader.ResolveAbi 0.1, Shader.ResolveGraphicsStagesAbi 0.1
title 0.1 (0 %) 0.0 (0 %) 2743.4 0.3 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveGraphicsAbi 0.0
queue worker 0x28 40.1 (1 %) 2699.1 (98 %) 4.3 1.5 Driver.Packet 2737.2, Driver.EndSubmission 0.5
queue worker 0x38 80.9 (3 %) 2656.2 (97 %) 6.5 2.7 Driver.Packet 2243.8, Driver.EndSubmission 7.3
queue worker 0x30 70.6 (3 %) 2669.0 (97 %) 3.8 1.3 Driver.Packet 2738.5, Driver.EndSubmission 0.0
gpu 474.9 (17 %) 0.0 (0 %) 2268.6 0.0 batch 474.9

Largest slices (ms per frame, inclusive, all threads): Driver.Packet 13157.1, Driver.Packet.memory_wait 8864.2, GpuMutex.wait.hook 2545.1, Driver.Packet.dispatch 2326.2, Driver.Dispatch 2051.5, Resources.Complete 1982.0, Graphics.Draw 1751.7, Driver.Packet.draw 1727.5, Driver.Draw 1726.8, Graphics.Draw.draw_and_resource_release 1698.7

Longest waits

  • Driver.Packet.memory_wait (queue worker 0x38) 2528.4 ms at 392082 ms, present 1228
  • Driver.Packet.memory_wait (queue worker 0x38) 2393.3 ms at 36360 ms, present 1096
  • Driver.Packet.memory_wait (queue worker 0x28) 2159.8 ms at 376619 ms, present 1223
  • Driver.Packet.memory_wait (queue worker 0x28) 2133.4 ms at 392477 ms, present 1228
  • Driver.Packet.memory_wait (queue worker 0x28) 2126.2 ms at 36627 ms, present 1096
  • Driver.Packet.memory_wait (queue worker 0x28) 2109.3 ms at 168666 ms, present 1145
  • Driver.Packet.memory_wait (queue worker 0x28) 2097.4 ms at 6839 ms, present 1087
  • Driver.Packet.memory_wait (queue worker 0x28) 2084.4 ms at 165460 ms, present 1144
  • Driver.Packet.memory_wait (queue worker 0x28) 2079.8 ms at 154082 ms, present 1140
  • Driver.Packet.memory_wait (queue worker 0x28) 2067.7 ms at 214 ms, present 1085

Largest GPU batches (GPU ranges inside, and the CPU slices that recorded each, inclusive)

  • batch 39147: 118.8 ms at 360527 ms, present 1216: GPU no ranges; recorded by Recorder.Submit (draw committer) 0.0
  • batch 29692: 108.4 ms at 269139 ms, present 1183: GPU no ranges; recorded by no CPU slices
  • batch 10234: 105.6 ms at 96082 ms, present 1117: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 26.5, Driver.Packet.dispatch (queue worker 0x0) 26.5, Driver.Dispatch (queue worker 0x0) 26.5, Vulkan.Dispatch (queue worker 0x0) 26.3
  • batch 38560: 104.6 ms at 354794 ms, present 1214: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 26.9, Driver.Packet.dispatch (queue worker 0x0) 26.9, Driver.Dispatch (queue worker 0x0) 26.9, Vulkan.Dispatch (queue worker 0x0) 26.8
  • batch 16952: 100.9 ms at 157036 ms, present 1140: GPU no ranges; recorded by no CPU slices
trace_digest, pair 2, main f8f5b24 (cp12051-B-2)

frames 1085:150 from present 1085: 150 presents, frame p50 2828.5 / p90 3302.5 / p99 4231.1 / max 4354.3 ms, GPU busy 503.6 ms per present
NVIDIA GeForce RTX 3080, NVIDIA 615.78.08, Linux 7.2.10-1-cachyos, 3840x2160, commit f8f5b24, dropped: no

{"commit":"f8f5b24b77ad","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TIME_SCALE":"0.1","APS5_TRACE_DIR":"<path>","APS5_TRACE_EVENTS":"4194304","APS5_TRACE_FRAMES":"1085:150"},"gpu":"NVIDIA GeForce RTX 3080","driver":"NVIDIA 615.78.08","os":"Linux 7.2.10-1-cachyos","cpu":"AMD Ryzen 9 7950X3D 16-Core Processor","cpu_threads":32,"memory_mib":63428,"title_id":"PPSA11386","title":"007 First Light","content_version":"01.018.000","resolution":"3840x2160","window":{"spec":"frames 1085:150","first_present":1085,"ms":431649.655},"presents":150,"frame_ms":{"p50":2828.455,"p90":3302.503,"p99":4231.105,"max":4354.292},"gpu_busy_ms_per_present":503.631,"worker_busy_pct":{"queue worker 0x0":99.937,"queue worker 0x20":99.891,"queue worker 0x28":99.795,"queue worker 0x38":82.988,"queue worker 0x30":99.832},"top_phases_ms_per_frame":{"Driver.Packet":13847.888,"Driver.Packet.memory_wait":9462.661,"GpuMutex.wait.hook":2474.951,"Driver.Packet.dispatch":2279.13,"Driver.Dispatch":2038.701,"Resources.Complete":2011.38,"Driver.Packet.draw":1852.938,"Driver.Draw":1852.213},"trace_dropped":false,"trace":"aps5-trace-f8f5b24b77ad-2.json.gz"}

Slowest frames (largest slices inside each, inclusive)

  • present 1186: 4354.3 ms at 283514 ms: Driver.Packet (queue worker 0x28) 4354.1, Driver.Packet (queue worker 0x30) 4354.0, Driver.Packet (queue worker 0x20) 4353.6, Driver.Packet (queue worker 0x0) 4306.2
  • present 1187: 4231.1 ms at 287868 ms: Driver.Packet (queue worker 0x30) 4230.9, Driver.Packet (queue worker 0x28) 4230.6, Driver.Packet (queue worker 0x20) 4199.9, Driver.Packet (queue worker 0x0) 4185.8
  • present 1188: 4197.5 ms at 292100 ms: Driver.Packet (queue worker 0x28) 4197.3, Driver.Packet (queue worker 0x30) 4197.3, Driver.Packet (queue worker 0x20) 4196.8, Driver.Packet (queue worker 0x0) 4141.1
  • present 1189: 4142.3 ms at 296297 ms: Driver.Packet (queue worker 0x28) 4142.1, Driver.Packet (queue worker 0x30) 4142.1, Driver.Packet (queue worker 0x20) 4141.7, Driver.Packet (queue worker 0x0) 4086.9
  • present 1184: 4114.3 ms at 275400 ms: Driver.Packet (queue worker 0x28) 4114.1, Driver.Packet (queue worker 0x30) 4114.0, Driver.Packet (queue worker 0x20) 4113.7, Driver.Packet (queue worker 0x0) 4070.2

Threads (ms per frame)

thread busy wait untraced in slices < 20 us largest
shader prepare 0.0 (0 %) 0.0 (0 %) 2877.6 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2877.6 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2877.6 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2877.7 0.0 Vulkan.GraphicsPipelinePrebuild 0.0, Vulkan.ComputePipeline 0.0
shader prepare 0.1 (0 %) 0.0 (0 %) 2877.6 0.0 Vulkan.GraphicsPipelinePrebuild 0.1
shader prepare 0.0 (0 %) 0.0 (0 %) 2877.6 0.0 Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2877.7 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.2 (0 %) 0.0 (0 %) 2877.5 0.0 Vulkan.GraphicsPipelinePrebuild 0.2, Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2877.6 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2877.7 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2877.7 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.1 (0 %) 0.0 (0 %) 2877.6 0.0 Vulkan.ComputePipeline 0.1
shader prepare 0.0 (0 %) 0.0 (0 %) 2877.7 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2877.6 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2877.7 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2877.6 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
title 0.7 (0 %) 1.9 (0 %) 2875.0 0.6 Shader.ResolveAbi 0.4, Shader.ResolveGraphicsStagesAbi 0.3
queue worker 0x0 2705.6 (94 %) 162.4 (6 %) 9.7 105.7 Driver.Packet 2840.5, Driver.EndSubmission 27.5
draw committer 1421.3 (49 %) 203.9 (7 %) 1252.5 12.1 Graphics.Draw 1393.9, Recorder.Submit 19.4
presenter 1.2 (0 %) 11.6 (0 %) 2864.9 0.1 VideoOut.Flip 12.6, Driver.Present 0.1
title 0.2 (0 %) 0.0 (0 %) 2877.5 0.3 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveGraphicsAbi 0.0
title 0.1 (0 %) 0.0 (0 %) 2877.5 0.3 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.0
title 0.3 (0 %) 0.0 (0 %) 2877.4 0.3 Shader.ResolveGraphicsStagesAbi 0.2, Shader.ResolveAbi 0.1
queue worker 0x20 164.2 (6 %) 2710.7 (94 %) 2.8 3.0 Driver.Packet 2872.8, Driver.EndSubmission 1.2
title 0.2 (0 %) 0.0 (0 %) 2877.4 0.3 Shader.ResolveGraphicsAbi 0.1, Shader.ResolveGraphicsStagesAbi 0.1
title 0.2 (0 %) 0.0 (0 %) 2877.4 0.3 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.1
title 0.2 (0 %) 0.0 (0 %) 2877.4 0.3 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.1
title 0.2 (0 %) 0.0 (0 %) 2877.5 0.2 Shader.ResolveAbi 0.1, Shader.ResolveGraphicsStagesAbi 0.1
title 0.9 (0 %) 0.0 (0 %) 2876.7 0.3 Shader.ResolveAbi 0.7, Shader.ResolveGraphicsStagesAbi 0.2
queue worker 0x28 34.7 (1 %) 2838.4 (99 %) 4.5 1.6 Driver.Packet 2871.1, Driver.EndSubmission 0.5
queue worker 0x38 81.8 (3 %) 2789.4 (97 %) 6.4 2.7 Driver.Packet 2381.9, Driver.EndSubmission 5.8
queue worker 0x30 68.5 (2 %) 2805.5 (97 %) 3.7 1.3 Driver.Packet 2872.5, Driver.EndSubmission 0.1
gpu 504.6 (18 %) 0.0 (0 %) 2373.1 0.0 batch 504.6

Largest slices (ms per frame, inclusive, all threads): Driver.Packet 13838.8, Driver.Packet.memory_wait 9462.4, GpuMutex.wait.hook 2474.7, Driver.Packet.dispatch 2278.7, Driver.Dispatch 2037.6, Resources.Complete 2010.2, Driver.Packet.draw 1852.1, Driver.Draw 1851.4, Graphics.Draw 1814.7, Graphics.Draw.draw_and_resource_release 1730.4

Longest waits

  • Driver.Packet.memory_wait (queue worker 0x38) 2720.9 ms at 289483 ms, present 1187
  • Driver.Packet.memory_wait (queue worker 0x38) 2702.6 ms at 280830 ms, present 1185
  • Driver.Packet.memory_wait (queue worker 0x38) 2626.3 ms at 285249 ms, present 1186
  • Driver.Packet.memory_wait (queue worker 0x28) 2606.9 ms at 77196 ms, present 1110
  • Driver.Packet.memory_wait (queue worker 0x38) 2578.5 ms at 293728 ms, present 1188
  • Driver.Packet.memory_wait (queue worker 0x38) 2567.4 ms at 297892 ms, present 1189
  • Driver.Packet.memory_wait (queue worker 0x38) 2563.9 ms at 276960 ms, present 1184
  • Driver.Packet.memory_wait (queue worker 0x38) 2523.2 ms at 301839 ms, present 1190
  • Driver.Packet.memory_wait (queue worker 0x28) 2291.7 ms at 289912 ms, present 1187
  • Driver.Packet.memory_wait (queue worker 0x28) 2278.6 ms at 281254 ms, present 1185

Largest GPU batches (GPU ranges inside, and the CPU slices that recorded each, inclusive)

  • batch 37750: 126.2 ms at 367488 ms, present 1212: GPU no ranges; recorded by no CPU slices
  • batch 32305: 125.5 ms at 313095 ms, present 1193: GPU no ranges; recorded by no CPU slices
  • batch 39481: 120.1 ms at 384833 ms, present 1218: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 130.0, Driver.Packet.draw (queue worker 0x0) 122.4, Driver.Draw (queue worker 0x0) 122.4, Driver.Draw.draw_enqueued (queue worker 0x0) 122.3
  • batch 19110: 117.1 ms at 184145 ms, present 1149: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 5.0, Driver.Packet.dispatch (queue worker 0x0) 5.0, Driver.Dispatch (queue worker 0x0) 5.0, Vulkan.Dispatch (queue worker 0x0) 4.9
  • batch 38872: 109.6 ms at 378915 ms, present 1216: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 9.0, Driver.Packet.dispatch (queue worker 0x0) 9.0, Driver.Dispatch (queue worker 0x0) 8.9, Vulkan.Dispatch (queue worker 0x0) 8.6
trace_digest, pair 2, this PR c5dcde9 (cp12051-C-2)

frames 1085:150 from present 1085: 150 presents, frame p50 2451.6 / p90 2926.5 / p99 3471.8 / max 4043.9 ms, GPU busy 418.9 ms per present
NVIDIA GeForce RTX 3080, NVIDIA 615.78.08, Linux 7.2.10-1-cachyos, 3840x2160, commit c5dcde9, dropped: no

{"commit":"c5dcde982eb6","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TIME_SCALE":"0.1","APS5_TRACE_DIR":"<path>","APS5_TRACE_EVENTS":"4194304","APS5_TRACE_FRAMES":"1085:150"},"gpu":"NVIDIA GeForce RTX 3080","driver":"NVIDIA 615.78.08","os":"Linux 7.2.10-1-cachyos","cpu":"AMD Ryzen 9 7950X3D 16-Core Processor","cpu_threads":32,"memory_mib":63428,"title_id":"PPSA11386","title":"007 First Light","content_version":"01.018.000","resolution":"3840x2160","window":{"spec":"frames 1085:150","first_present":1085,"ms":375957.074},"presents":150,"frame_ms":{"p50":2451.578,"p90":2926.542,"p99":3471.788,"max":4043.945},"gpu_busy_ms_per_present":418.902,"worker_busy_pct":{"queue worker 0x0":99.938,"queue worker 0x20":99.903,"queue worker 0x28":99.809,"queue worker 0x30":99.843,"queue worker 0x38":85.649},"top_phases_ms_per_frame":{"Driver.Packet":12119.899,"Driver.Packet.memory_wait":8117.253,"GpuMutex.wait.hook":2322.025,"Driver.Packet.dispatch":2184.985,"Driver.Dispatch":1945.673,"Resources.Complete":1827.441,"Graphics.Draw":1577.501,"Driver.Packet.draw":1561.313},"trace_dropped":false,"trace":"aps5-trace-c5dcde982eb6-2.json.gz"}

Slowest frames (largest slices inside each, inclusive)

  • present 1107: 4043.9 ms at 63399 ms: Driver.Packet (queue worker 0x30) 4043.6, Driver.Packet (queue worker 0x28) 4043.2, Driver.Packet (queue worker 0x20) 4022.2, Driver.Packet (queue worker 0x0) 3999.4
  • present 1086: 3471.8 ms at 3130 ms: Driver.Packet (queue worker 0x30) 3471.5, Driver.Packet (queue worker 0x28) 3471.4, Driver.Packet (queue worker 0x20) 3470.2, Driver.Packet (queue worker 0x0) 3433.4
  • present 1096: 3368.9 ms at 32722 ms: Driver.Packet (queue worker 0x30) 3368.6, Driver.Packet (queue worker 0x28) 3368.6, Driver.Packet (queue worker 0x20) 3352.1, Driver.Packet (queue worker 0x0) 3330.8
  • present 1102: 3279.4 ms at 49963 ms: Driver.Packet (queue worker 0x28) 3279.2, Driver.Packet (queue worker 0x30) 3279.2, Driver.Packet (queue worker 0x20) 3263.5, Driver.Packet (queue worker 0x0) 3240.0
  • present 1154: 3221.2 ms at 180888 ms: Driver.Packet (queue worker 0x28) 3220.8, Driver.Packet (queue worker 0x30) 3220.7, Driver.Packet (queue worker 0x20) 3220.7, Driver.Packet (queue worker 0x0) 3166.9

Threads (ms per frame)

thread busy wait untraced in slices < 20 us largest
shader prepare 0.0 (0 %) 0.0 (0 %) 2506.3 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2506.3 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.1 (0 %) 0.0 (0 %) 2506.3 0.0 Vulkan.ComputePipeline 0.1
shader prepare 0.0 (0 %) 0.0 (0 %) 2506.4 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2506.3 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2506.4 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2506.4 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2506.4 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2506.4 0.0 Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2506.4 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2506.4 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2506.4 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2506.4 0.0 Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2506.3 0.0 Vulkan.GraphicsPipelinePrebuild 0.0, Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2506.4 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2506.4 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
title 0.8 (0 %) 0.0 (0 %) 2505.5 0.5 Shader.ResolveAbi 0.4, Shader.ResolveGraphicsStagesAbi 0.3
queue worker 0x0 2343.4 (93 %) 153.9 (6 %) 9.0 99.0 Driver.Packet 2470.5, Driver.EndSubmission 26.9
draw committer 1367.7 (55 %) 200.2 (8 %) 938.5 12.0 Graphics.Draw 1338.6, Recorder.Submit 17.7
presenter 1.2 (0 %) 11.0 (0 %) 2494.1 0.1 VideoOut.Flip 12.2, Driver.Present 0.1
title 0.2 (0 %) 0.0 (0 %) 2506.1 0.2 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.1
title 0.1 (0 %) 0.0 (0 %) 2506.3 0.3 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveGraphicsAbi 0.0
title 0.1 (0 %) 0.0 (0 %) 2506.3 0.3 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.0
queue worker 0x20 166.6 (7 %) 2337.5 (93 %) 2.3 3.0 Driver.Packet 2496.2, Driver.EndSubmission 7.3
title 0.3 (0 %) 0.0 (0 %) 2506.1 0.2 Shader.ResolveAbi 0.2, Shader.ResolveGraphicsStagesAbi 0.1
title 0.1 (0 %) 0.0 (0 %) 2506.3 0.3 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveGraphicsAbi 0.0
title 0.3 (0 %) 0.0 (0 %) 2506.1 0.2 Shader.ResolveGraphicsStagesAbi 0.2, Shader.ResolveAbi 0.1
title 0.3 (0 %) 0.0 (0 %) 2506.1 0.2 Shader.ResolveGraphicsStagesAbi 0.2, Shader.ResolveAbi 0.1
title 0.5 (0 %) 0.0 (0 %) 2505.9 0.2 Shader.ResolveAbi 0.4, Shader.ResolveGraphicsStagesAbi 0.1
queue worker 0x28 30.9 (1 %) 2471.8 (99 %) 3.6 1.5 Driver.Packet 2501.1, Driver.EndSubmission 0.4
queue worker 0x30 71.3 (3 %) 2432.2 (97 %) 2.9 1.3 Driver.Packet 2502.2, Driver.EndSubmission 0.0
queue worker 0x38 81.8 (3 %) 2418.9 (97 %) 5.7 2.7 Driver.Packet 2141.3, Driver.EndSubmission 5.0
gpu 421.7 (17 %) 0.0 (0 %) 2084.7 0.0 batch 421.7

Largest slices (ms per frame, inclusive, all threads): Driver.Packet 12111.2, Driver.Packet.memory_wait 8117.1, GpuMutex.wait.hook 2321.8, Driver.Packet.dispatch 2184.5, Driver.Dispatch 1944.6, Resources.Complete 1826.2, Graphics.Draw 1577.3, Driver.Packet.draw 1560.2, Driver.Draw 1559.6, Graphics.Draw.draw_and_resource_release 1540.5

Longest waits

  • Driver.Packet.memory_wait (queue worker 0x38) 2204.7 ms at 62388 ms, present 1106
  • Driver.Packet.memory_wait (queue worker 0x28) 2073.8 ms at 17925 ms, present 1091
  • Driver.Packet.memory_wait (queue worker 0x28) 1994.6 ms at 50057 ms, present 1102
  • Driver.Packet.memory_wait (queue worker 0x28) 1973.3 ms at 33031 ms, present 1096
  • Driver.Packet.memory_wait (queue worker 0x28) 1952.8 ms at 38928 ms, present 1098
  • Driver.Packet.memory_wait (queue worker 0x28) 1945.8 ms at 114715 ms, present 1127
  • Driver.Packet.memory_wait (queue worker 0x28) 1914.2 ms at 14927 ms, present 1090
  • Driver.Packet.memory_wait (queue worker 0x28) 1903.8 ms at 62689 ms, present 1106
  • Driver.Packet.memory_wait (queue worker 0x28) 1901.3 ms at 26978 ms, present 1094
  • Driver.Packet.memory_wait (queue worker 0x28) 1884.9 ms at 9265 ms, present 1088

Largest GPU batches (GPU ranges inside, and the CPU slices that recorded each, inclusive)

  • batch 645: 107.2 ms at 6471 ms, present 1086: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 113.2, Driver.Packet.dispatch (queue worker 0x0) 113.2, Driver.Dispatch (queue worker 0x0) 113.1, Vulkan.Dispatch (queue worker 0x0) 112.9
  • batch 13742: 104.1 ms at 122901 ms, present 1129: GPU no ranges; recorded by Resources.Complete (queue worker 0x0) 116.6, Recorder.Sync (queue worker 0x0) 104.4, Driver.Packet (queue worker 0x0) 23.2, Driver.Packet.dispatch (queue worker 0x0) 23.2
  • batch 4646: 92.5 ms at 44478 ms, present 1099: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 102.1, Driver.Packet.dispatch (queue worker 0x0) 102.1, Driver.Dispatch (queue worker 0x0) 102.1, Vulkan.Dispatch (queue worker 0x0) 101.3
  • batch 3779: 92.4 ms at 35908 ms, present 1096: GPU no ranges; recorded by no CPU slices
  • batch 39915: 90.4 ms at 339096 ms, present 1219: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 8.5, Driver.Packet.dispatch (queue worker 0x0) 8.5, Driver.Dispatch (queue worker 0x0) 8.5, Vulkan.Dispatch (queue worker 0x0) 8.2
trace_digest, pair 3, main f8f5b24 (cp12051-B-3)

frames 1085:150 from present 1085: 150 presents, frame p50 2605.9 / p90 3041.0 / p99 3370.0 / max 4454.7 ms, GPU busy 441.5 ms per present
NVIDIA GeForce RTX 3080, NVIDIA 615.78.08, Linux 7.2.10-1-cachyos, 3840x2160, commit f8f5b24, dropped: no

{"commit":"f8f5b24b77ad","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TIME_SCALE":"0.1","APS5_TRACE_DIR":"<path>","APS5_TRACE_EVENTS":"4194304","APS5_TRACE_FRAMES":"1085:150"},"gpu":"NVIDIA GeForce RTX 3080","driver":"NVIDIA 615.78.08","os":"Linux 7.2.10-1-cachyos","cpu":"AMD Ryzen 9 7950X3D 16-Core Processor","cpu_threads":32,"memory_mib":63428,"title_id":"PPSA11386","title":"007 First Light","content_version":"01.018.000","resolution":"3840x2160","window":{"spec":"frames 1085:150","first_present":1085,"ms":396172.64},"presents":150,"frame_ms":{"p50":2605.89,"p90":3040.989,"p99":3369.986,"max":4454.722},"gpu_busy_ms_per_present":441.49,"worker_busy_pct":{"queue worker 0x0":99.94,"queue worker 0x20":99.892,"queue worker 0x28":99.78,"queue worker 0x30":99.819,"queue worker 0x38":85.23},"top_phases_ms_per_frame":{"Driver.Packet":12768.1,"Driver.Packet.memory_wait":8637.775,"GpuMutex.wait.hook":2291.509,"Driver.Packet.dispatch":2227.289,"Driver.Dispatch":1985.304,"Resources.Complete":1856.957,"Driver.Packet.draw":1660.973,"Driver.Draw":1660.274},"trace_dropped":false,"trace":"aps5-trace-f8f5b24b77ad-2.json.gz"}

Slowest frames (largest slices inside each, inclusive)

  • present 1110: 4454.7 ms at 72829 ms: Driver.Packet (queue worker 0x28) 4454.5, Driver.Packet (queue worker 0x30) 4454.4, Driver.Packet (queue worker 0x20) 4454.1, Driver.Packet (queue worker 0x0) 4407.0
  • present 1105: 3370.0 ms at 58186 ms: Driver.Packet (queue worker 0x28) 3369.8, Driver.Packet (queue worker 0x30) 3369.8, Driver.Packet (queue worker 0x20) 3369.5, Driver.Packet (queue worker 0x0) 3333.8
  • present 1149: 3337.0 ms at 177908 ms: Driver.Packet (queue worker 0x30) 3336.7, Driver.Packet (queue worker 0x28) 3336.6, Driver.Packet (queue worker 0x20) 3336.4, Driver.Packet (queue worker 0x0) 3286.9
  • present 1090: 3303.1 ms at 13951 ms: Driver.Packet (queue worker 0x30) 3302.9, Driver.Packet (queue worker 0x28) 3302.6, Driver.Packet (queue worker 0x20) 3302.4, Driver.Packet (queue worker 0x0) 3265.5
  • present 1091: 3128.6 ms at 17254 ms: Driver.Packet (queue worker 0x30) 3128.3, Driver.Packet (queue worker 0x28) 3128.2, Driver.Packet (queue worker 0x20) 3127.8, Driver.Packet (queue worker 0x0) 3090.8

Threads (ms per frame)

thread busy wait untraced in slices < 20 us largest
shader prepare 0.1 (0 %) 0.0 (0 %) 2641.1 0.0 Vulkan.ComputePipeline 0.1
shader prepare 0.0 (0 %) 0.0 (0 %) 2641.1 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2641.1 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2641.1 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2641.1 0.0 Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2641.1 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2641.1 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2641.1 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2641.1 0.0 Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2641.1 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.2 (0 %) 0.0 (0 %) 2641.0 0.0 Vulkan.GraphicsPipelinePrebuild 0.2, Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2641.1 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2641.1 0.0 Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2641.1 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.2 (0 %) 0.0 (0 %) 2641.0 0.0 Vulkan.GraphicsPipelinePrebuild 0.2, Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2641.1 0.0 Vulkan.ComputePipeline 0.0
title 0.8 (0 %) 1.8 (0 %) 2638.6 0.6 Shader.ResolveAbi 0.4, Shader.ResolveGraphicsStagesAbi 0.2
queue worker 0x0 2469.1 (93 %) 162.8 (6 %) 9.3 100.1 Driver.Packet 2605.5, Driver.EndSubmission 26.3
draw committer 1408.4 (53 %) 194.8 (7 %) 1038.0 12.1 Graphics.Draw 1381.4, Recorder.Submit 19.1
presenter 1.2 (0 %) 10.4 (0 %) 2629.6 0.1 VideoOut.Flip 11.3, Driver.Present 0.2
title 0.1 (0 %) 0.0 (0 %) 2641.0 0.3 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveGraphicsAbi 0.0
title 0.4 (0 %) 0.0 (0 %) 2640.8 0.3 Shader.ResolveAbi 0.2, Shader.ResolveGraphicsAbi 0.1
title 0.3 (0 %) 0.0 (0 %) 2640.9 0.2 Shader.ResolveAbi 0.1, Shader.ResolveGraphicsStagesAbi 0.1
title 0.2 (0 %) 0.0 (0 %) 2641.0 0.3 Shader.ResolveAbi 0.1, Shader.ResolveGraphicsStagesAbi 0.1
queue worker 0x20 165.5 (6 %) 2473.5 (94 %) 2.2 2.9 Driver.Packet 2636.8, Driver.EndSubmission 1.0
title 0.2 (0 %) 0.0 (0 %) 2641.0 0.3 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.1
title 0.1 (0 %) 0.0 (0 %) 2641.0 0.3 Shader.ResolveGraphicsStagesAbi 0.0, Shader.ResolveAbi 0.0
title 0.1 (0 %) 0.0 (0 %) 2641.0 0.3 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.0
queue worker 0x28 32.4 (1 %) 2604.6 (99 %) 4.2 1.6 Driver.Packet 2635.0, Driver.EndSubmission 0.2
queue worker 0x30 65.8 (2 %) 2572.0 (97 %) 3.3 1.3 Driver.Packet 2636.2, Recorder.Submit 0.0
queue worker 0x38 78.2 (3 %) 2557.0 (97 %) 6.0 2.7 Driver.Packet 2245.8, Driver.EndSubmission 4.9
title 0.7 (0 %) 0.0 (0 %) 2640.5 0.3 Shader.ResolveAbi 0.4, Shader.ResolveGraphicsStagesAbi 0.2
gpu 444.1 (17 %) 0.0 (0 %) 2197.1 0.0 batch 444.1

Largest slices (ms per frame, inclusive, all threads): Driver.Packet 12759.3, Driver.Packet.memory_wait 8637.6, GpuMutex.wait.hook 2291.3, Driver.Packet.dispatch 2226.8, Driver.Dispatch 1984.2, Resources.Complete 1855.8, Driver.Packet.draw 1659.9, Driver.Draw 1659.2, Graphics.Draw 1632.9, Graphics.Draw.draw_and_resource_release 1597.3

Longest waits

  • Driver.Packet.memory_wait (queue worker 0x38) 2234.6 ms at 71620 ms, present 1109
  • Driver.Packet.memory_wait (queue worker 0x28) 2172.6 ms at 73856 ms, present 1110
  • Driver.Packet.memory_wait (queue worker 0x28) 2031.2 ms at 58222 ms, present 1105
  • Driver.Packet.memory_wait (queue worker 0x28) 1986.2 ms at 71869 ms, present 1109
  • Driver.Packet.memory_wait (queue worker 0x28) 1962.8 ms at 127967 ms, present 1130
  • Driver.Packet.memory_wait (queue worker 0x28) 1941.4 ms at 136340 ms, present 1133
  • Driver.Packet.memory_wait (queue worker 0x28) 1890.9 ms at 28682 ms, present 1095
  • Driver.Packet.memory_wait (queue worker 0x28) 1882.1 ms at 14185 ms, present 1090
  • Driver.Packet.memory_wait (queue worker 0x28) 1831.2 ms at 61582 ms, present 1106
  • Driver.Packet.memory_wait (queue worker 0x28) 1817.5 ms at 52456 ms, present 1103

Largest GPU batches (GPU ranges inside, and the CPU slices that recorded each, inclusive)

  • batch 13630: 120.2 ms at 130840 ms, present 1130: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 129.9, Driver.Packet.dispatch (queue worker 0x0) 129.9, Driver.Dispatch (queue worker 0x0) 129.8, Vulkan.Dispatch (queue worker 0x0) 129.5
  • batch 35821: 116.6 ms at 326080 ms, present 1207: GPU no ranges; recorded by no CPU slices
  • batch 42804: 109.3 ms at 388424 ms, present 1231: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 35.1, Driver.Packet.dispatch (queue worker 0x0) 35.1, Driver.Dispatch (queue worker 0x0) 35.1, Vulkan.Dispatch (queue worker 0x0) 35.0
  • batch 39895: 104.6 ms at 361989 ms, present 1221: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 31.9, Driver.Packet.dispatch (queue worker 0x0) 31.9, Driver.Dispatch (queue worker 0x0) 31.9, Vulkan.Dispatch (queue worker 0x0) 31.7
  • batch 40729: 103.7 ms at 370284 ms, present 1224: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 154.2, Driver.Packet.dispatch (queue worker 0x0) 153.5, Driver.Dispatch (queue worker 0x0) 39.8, Vulkan.Dispatch (queue worker 0x0) 39.3
trace_digest, pair 3, this PR c5dcde9 (cp12051-C-3)

frames 1085:150 from present 1085: 150 presents, frame p50 2684.2 / p90 3184.1 / p99 3645.0 / max 4145.2 ms, GPU busy 467.8 ms per present
NVIDIA GeForce RTX 3080, NVIDIA 615.78.08, Linux 7.2.10-1-cachyos, 3840x2160, commit c5dcde9, dropped: no

{"commit":"c5dcde982eb6","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TIME_SCALE":"0.1","APS5_TRACE_DIR":"<path>","APS5_TRACE_EVENTS":"4194304","APS5_TRACE_FRAMES":"1085:150"},"gpu":"NVIDIA GeForce RTX 3080","driver":"NVIDIA 615.78.08","os":"Linux 7.2.10-1-cachyos","cpu":"AMD Ryzen 9 7950X3D 16-Core Processor","cpu_threads":32,"memory_mib":63428,"title_id":"PPSA11386","title":"007 First Light","content_version":"01.018.000","resolution":"3840x2160","window":{"spec":"frames 1085:150","first_present":1085,"ms":409847.87},"presents":150,"frame_ms":{"p50":2684.171,"p90":3184.105,"p99":3644.97,"max":4145.218},"gpu_busy_ms_per_present":467.834,"worker_busy_pct":{"queue worker 0x0":99.941,"queue worker 0x20":99.922,"queue worker 0x38":80.339,"queue worker 0x28":99.827,"queue worker 0x30":99.855},"top_phases_ms_per_frame":{"Driver.Packet":13072.828,"Driver.Packet.memory_wait":8937.961,"GpuMutex.wait.hook":2419.026,"Driver.Packet.dispatch":2149.819,"Resources.Complete":1961.375,"Driver.Dispatch":1886.346,"Graphics.Draw":1753.861,"Driver.Packet.draw":1750.046},"trace_dropped":false,"trace":"aps5-trace-c5dcde982eb6-2.json.gz"}

Slowest frames (largest slices inside each, inclusive)

  • present 1119: 4145.2 ms at 97957 ms: Driver.Packet (queue worker 0x30) 4145.0, Driver.Packet (queue worker 0x28) 4145.0, Driver.Packet (queue worker 0x20) 4135.1, Driver.Packet.memory_wait (queue worker 0x28) 4107.3
  • present 1115: 3645.0 ms at 85691 ms: Driver.Packet (queue worker 0x30) 3644.8, Driver.Packet (queue worker 0x20) 3644.4, Driver.Packet (queue worker 0x28) 3643.8, Driver.Packet (queue worker 0x0) 3605.0
  • present 1204: 3579.4 ms at 323291 ms: Driver.Packet (queue worker 0x30) 3579.2, Driver.Packet (queue worker 0x28) 3579.1, Driver.Packet (queue worker 0x20) 3577.7, Driver.Packet (queue worker 0x0) 3544.7
  • present 1099: 3572.7 ms at 37374 ms: Driver.Packet (queue worker 0x30) 3572.4, Driver.Packet (queue worker 0x28) 3572.4, Driver.Packet (queue worker 0x20) 3572.1, Driver.Packet (queue worker 0x0) 3537.5
  • present 1107: 3541.1 ms at 62045 ms: Driver.Packet (queue worker 0x30) 3540.8, Driver.Packet (queue worker 0x20) 3540.4, Driver.Packet (queue worker 0x28) 3540.1, Driver.Packet (queue worker 0x0) 3504.6

Threads (ms per frame)

thread busy wait untraced in slices < 20 us largest
shader prepare 0.1 (0 %) 0.0 (0 %) 2732.3 0.0 Vulkan.ComputePipeline 0.1
shader prepare 0.0 (0 %) 0.0 (0 %) 2732.3 0.0 Vulkan.GraphicsPipelinePrebuild 0.0, Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2732.3 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2732.3 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2732.3 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2732.3 0.0 Vulkan.GraphicsPipelinePrebuild 0.0, Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2732.3 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.1 (0 %) 0.0 (0 %) 2732.3 0.0 Vulkan.GraphicsPipelinePrebuild 0.0, Vulkan.ComputePipeline 0.0
shader prepare 0.1 (0 %) 0.0 (0 %) 2732.3 0.0 Vulkan.GraphicsPipelinePrebuild 0.0, Vulkan.ComputePipeline 0.0
shader prepare 0.1 (0 %) 0.0 (0 %) 2732.2 0.0 Vulkan.ComputePipeline 0.1
shader prepare 0.0 (0 %) 0.0 (0 %) 2732.3 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2732.3 0.0 Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2732.3 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2732.3 0.0 Vulkan.ComputePipeline 0.0, Vulkan.GraphicsPipelinePrebuild 0.0
shader prepare 0.1 (0 %) 0.0 (0 %) 2732.2 0.0 Vulkan.GraphicsPipelinePrebuild 0.1, Vulkan.ComputePipeline 0.0
shader prepare 0.0 (0 %) 0.0 (0 %) 2732.3 0.0 Vulkan.ComputePipeline 0.0
title 0.8 (0 %) 0.0 (0 %) 2731.5 0.6 Shader.ResolveAbi 0.4, Shader.ResolveGraphicsStagesAbi 0.2
queue worker 0x0 2560.4 (94 %) 162.8 (6 %) 9.1 104.2 Driver.Packet 2698.1, Driver.EndSubmission 25.1
draw committer 1376.8 (50 %) 223.9 (8 %) 1131.6 12.1 Graphics.Draw 1352.7, Recorder.Submit 19.6
presenter 1.2 (0 %) 9.1 (0 %) 2722.0 0.1 VideoOut.Flip 10.2, Driver.Present 0.1
title 0.2 (0 %) 0.0 (0 %) 2732.1 0.3 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.1
title 0.2 (0 %) 0.0 (0 %) 2732.1 0.3 Shader.ResolveAbi 0.1, Shader.ResolveGraphicsStagesAbi 0.1
title 0.3 (0 %) 0.0 (0 %) 2732.0 0.3 Shader.ResolveGraphicsStagesAbi 0.2, Shader.ResolveAbi 0.1
queue worker 0x20 169.1 (6 %) 2560.9 (94 %) 2.3 3.0 Driver.Packet 2722.3, Driver.EndSubmission 7.5
title 0.3 (0 %) 0.0 (0 %) 2732.1 0.3 Shader.ResolveAbi 0.1, Shader.ResolveGraphicsStagesAbi 0.1
title 0.4 (0 %) 0.0 (0 %) 2731.9 0.3 Shader.ResolveAbi 0.3, Shader.ResolveGraphicsStagesAbi 0.1
title 0.4 (0 %) 0.0 (0 %) 2731.9 0.3 Shader.ResolveAbi 0.2, Shader.ResolveGraphicsStagesAbi 0.1
title 0.1 (0 %) 0.0 (0 %) 2732.2 0.3 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveGraphicsAbi 0.0
title 0.2 (0 %) 0.0 (0 %) 2732.2 0.2 Shader.ResolveGraphicsStagesAbi 0.1, Shader.ResolveAbi 0.1
queue worker 0x38 81.9 (3 %) 2645.1 (97 %) 5.4 2.7 Driver.Packet 2188.6, Driver.EndSubmission 6.1
queue worker 0x28 38.2 (1 %) 2690.1 (98 %) 4.0 1.6 Driver.Packet 2727.0, Driver.EndSubmission 0.4
queue worker 0x30 68.3 (3 %) 2661.5 (97 %) 2.4 1.3 Driver.Packet 2728.2, Driver.EndSubmission 0.0
gpu 470.5 (17 %) 0.0 (0 %) 2261.8 0.0 batch 470.5

Largest slices (ms per frame, inclusive, all threads): Driver.Packet 13064.1, Driver.Packet.memory_wait 8937.7, GpuMutex.wait.hook 2418.8, Driver.Packet.dispatch 2149.3, Resources.Complete 1960.2, Driver.Dispatch 1885.2, Graphics.Draw 1753.7, Driver.Packet.draw 1749.3, Driver.Draw 1748.5, Graphics.Draw.draw_and_resource_release 1689.2

Longest waits

  • Driver.Packet.memory_wait (queue worker 0x28) 2354.5 ms at 37596 ms, present 1099
  • Driver.Packet.memory_wait (queue worker 0x38) 2232.4 ms at 96949 ms, present 1118
  • Driver.Packet.memory_wait (queue worker 0x28) 2133.7 ms at 46712 ms, present 1102
  • Driver.Packet.memory_wait (queue worker 0x28) 2125.5 ms at 62336 ms, present 1107
  • Driver.Packet.memory_wait (queue worker 0x28) 2111.6 ms at 406756 ms, present 1234
  • Driver.Packet.memory_wait (queue worker 0x28) 2106.1 ms at 85720 ms, present 1115
  • Driver.Packet.memory_wait (queue worker 0x28) 2105.7 ms at 323413 ms, present 1204
  • Driver.Packet.memory_wait (queue worker 0x28) 2084.3 ms at 89360 ms, present 1116
  • Driver.Packet.memory_wait (queue worker 0x28) 2079.1 ms at 82494 ms, present 1114
  • Driver.Packet.memory_wait (queue worker 0x28) 2077.8 ms at 49886 ms, present 1103

Largest GPU batches (GPU ranges inside, and the CPU slices that recorded each, inclusive)

  • batch 42273: 116.9 ms at 397070 ms, present 1230: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 7.4, Driver.Packet.dispatch (queue worker 0x0) 7.4, Driver.Dispatch (queue worker 0x0) 7.4, Vulkan.Dispatch (queue worker 0x0) 7.1
  • batch 8805: 110.3 ms at 85532 ms, present 1114: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 147.5, Driver.Packet.draw (queue worker 0x0) 110.6, Driver.Draw (queue worker 0x0) 110.6, Driver.Draw.draw_enqueued (queue worker 0x0) 110.3
  • batch 39918: 102.3 ms at 375740 ms, present 1222: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 11.4, Driver.Packet.dispatch (queue worker 0x0) 10.1, Driver.Dispatch (queue worker 0x0) 10.1, Vulkan.Dispatch (queue worker 0x0) 9.7
  • batch 39340: 101.1 ms at 370101 ms, present 1220: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 5.1, Driver.Packet.dispatch (queue worker 0x0) 5.1, Driver.Dispatch (queue worker 0x0) 5.0, Vulkan.Dispatch (queue worker 0x0) 4.9
  • batch 43503: 100.5 ms at 409735 ms, present 1234: GPU no ranges; recorded by Driver.Packet (queue worker 0x0) 6.6, Driver.Packet.dispatch (queue worker 0x0) 6.6, Driver.Dispatch (queue worker 0x0) 6.6, Vulkan.Dispatch (queue worker 0x0) 6.3

AI-assisted: yes (Claude Code)

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

Labels

agc libSceAgc* build docs perf Performance change shader core/shader

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants