MagicBeanDev/Hookshot

Archived

Watch

Fork 0

Performance: replay submit cost scales with draw count; pipeline-creation bursts cause hitches (NVIDIA, full session log) #384

Closed

opened 2026-11-07 23:19:50 +00:00 by Bronnzy · 2 comments

Bronnzy commented

2026-11-07 23:19:50 +00:00

(Migrated from github.com)

Builder version

foliage-linux-updater (source build of ba594da)

How you built

From source: nx2/make_game.py pipeline equivalent — dump extracted, lift 100 %, test_insn.py PASS (44172 cases), 0 failed compile units, MSVC target, RX_CPM at the bundled CPM cache

Game files given to it

A .nup (build e0f3ccfa, v131072)

The error

About 2 h of windowed play (Kokiri Forest → Lost Woods → Great Deku Tree interior), 118080 presents, RTX 5070 Ti, driver reports mesh shaders + host memory import + pipeline libraries. No crash, no DEVICE_LOST the whole session. Every number below is from the run's own vk: log lines.

Session: mean 53.4 fps, median 57.7. The fps loss splits cleanly by scene density, and the limiter is the CPU replay, not the GPU:

	frames ≥50 fps (n=696)	frames <50 fps (n=288)
draws/frame	632	1627
submit (CPU replay)	5.9 ms	12.7 ms
GPU time	4.2 ms	11.7 ms (longest submission 25.9 ms)

At 30–40 fps the frame budget is 25–33 ms but GPU time is only ~12 ms — submit-side replay (draw walk + descriptors + commands + dispatch) grows roughly linearly with draw count. Hyrule Field-scale scenes will hit this harder.

Pipeline-creation bursts mid-play. The seed hookshot_shaders.bin does not cover what progression builds. Over the session: 2551 pipelines / 33.5 s cumulative build time, in bursts, each one a hitch:

present #	burst	fps then
1680	+567	8.1
18480	+272	13.8
20280	+64	37.5
20400	+65	41.7

A second run (warm mkw_vk_pipelines.bin, 97 MB) had translation 0 ms at boot — so the cold-start experience is entirely cache warm-up, but the bursts during new areas still happen on the warm run (+1693 pipelines, 31 s).

Related: #326, #334 (shareable pipeline manifest would fix the burst problem), #254.

Visual Studio or Build Tools version, and Windows SDK version

VS Build Tools 2022, MSVC 14.44, Windows SDK 10.0.26100

Operating system and free space on the output drive

Windows 11, ~60 GB free on D:

Confirmations

On the newest release, and it still fails there.
Open issues searched before filing.
No game files or anything built from them is attached.

### Builder version foliage-linux-updater (source build of `ba594da`) ### How you built From source: `nx2/make_game.py` pipeline equivalent — dump extracted, lift 100 %, `test_insn.py` PASS (44172 cases), 0 failed compile units, MSVC target, `RX_CPM` at the bundled CPM cache ### Game files given to it A .nup (build `e0f3ccfa`, v131072) ### The error About 2 h of windowed play (Kokiri Forest → Lost Woods → Great Deku Tree interior), 118080 presents, RTX 5070 Ti, driver reports mesh shaders + host memory import + pipeline libraries. **No crash, no DEVICE_LOST the whole session.** Every number below is from the run's own `vk:` log lines. Session: mean 53.4 fps, median 57.7. The fps loss splits cleanly by scene density, and the limiter is the CPU replay, not the GPU: | | frames ≥50 fps (n=696) | frames <50 fps (n=288) | |---|---|---| | draws/frame | 632 | 1627 | | submit (CPU replay) | 5.9 ms | 12.7 ms | | GPU time | 4.2 ms | 11.7 ms (longest submission 25.9 ms) | At 30–40 fps the frame budget is 25–33 ms but GPU time is only ~12 ms — submit-side replay (draw walk + descriptors + commands + dispatch) grows roughly linearly with draw count. Hyrule Field-scale scenes will hit this harder. **Pipeline-creation bursts mid-play.** The seed `hookshot_shaders.bin` does not cover what progression builds. Over the session: 2551 pipelines / 33.5 s cumulative build time, in bursts, each one a hitch: | present # | burst | fps then | |---|---|---| | 1680 | +567 | 8.1 | | 18480 | +272 | 13.8 | | 20280 | +64 | 37.5 | | 20400 | +65 | 41.7 | A second run (warm `mkw_vk_pipelines.bin`, 97 MB) had `translation 0 ms` at boot — so the cold-start experience is entirely cache warm-up, but the bursts during *new areas* still happen on the warm run (+1693 pipelines, 31 s). Related: #326, #334 (shareable pipeline manifest would fix the burst problem), #254. ### Visual Studio or Build Tools version, and Windows SDK version VS Build Tools 2022, MSVC 14.44, Windows SDK 10.0.26100 ### Operating system and free space on the output drive Windows 11, ~60 GB free on D: ### Confirmations - On the newest release, and it still fails there. - Open issues searched before filing. - No game files or anything built from them is attached.

MMajor87 commented

2026-11-09 00:44:05 +00:00

(Migrated from github.com)

Where the frame goes on a fast NVIDIA desktop: half the GPU's time is write-back copies, and they sit on the frame's critical path

Setup: RTX 4080 16 GB, i9-14900KF, 32 GB RAM, Windows 11, 2560x1440. v2.0.5 with PR #761 merged locally (renderer DLL built from source with the release builder's toolchain). In-game: resolution 100%, frame generation off, frame pacing on, robust buffers off. EDEN_NX2_GM_LEGACY=1 and HOS_PIN=MainThread=FFFF,Presentation=FFFF,ModuleSystemWorker=FFFF (busiest threads on the P-cores) in every run. Same busy outdoor spot in every run (~3,000-3,500 draws a frame). Numbers are from the runs' own vk: log lines; fps = the 2 s log windows with more than 300 draws.

1. Nothing is saturated, and the in-game settings change nothing

	value
fps	~45 (frame ~22.4 ms)
replay (CPU, `submit`)	15.2 ms
GPU time	13.4 ms
`GPU-bound wait`	0.0-0.1 ms

Resolution 100% -> 50% and frame pacing off: fps unchanged (44-45 throughout), GPU time unchanged (13.4 ms).

2. `RX_VK_GPU_PROFILE=1`: the write-back copies are half the GPU's time

Per frame at ~3,530 draws:

kind	ms	share	per frame
`m wb` (mirror -> guest memory)	7.08	52.8%	10.3 spans, 68.5 MB
`m pass` (all draws)	3.55	26.4%	170 passes, 3,489 draws
`m dispatch`	1.80	13.4%	132
`m barrier`	0.73	5.5%	338
`u msync`	0.65		12 MB

That is why resolution does nothing here: the drawing itself is ~3.5 ms. gpu_buffer_bind queues every written storage buffer range for a copy back at the submission's end (vk_memory.cpp, writebacks.push_back), whether or not the CPU ever reads it.

3. `RX_VK_LOG_WRITEBACK=1`: what is copied back

Per write-back submission (~3,180 draws, 45 fps): ~6.6 MB, almost all from pool 0x116b000000 (144 MB pool, ~5.3 MB in 5 runs) and 0x112e000000 (32 MB pool, ~1 MB). Pool 0x116b... is where the foliage culling keeps its per-category draw lists / task arguments (the 0x116ba70000 region discussed in #763), read by GPU task shaders, not by the CPU as far as I can tell. Big written storage buffers logged:

15.2 MB at 0x116d5d6000: compute 102f5b0abb0f1e63, 78ccf14779ec3efb, 7650519f88e59b19, abccf81b45c5eb50
15.8 MB in pool 0x1065000000: compute e409733c45530d75, 8306877b7dc8784b, 14140d4c1dbe754f
149.6 MB at 0x107f7e8000: compute 4b03b3040d7cf076, 26fe0c70ab9fc547 (ssbo 0 of 3, c0+0x880)
9.5 MB at 0x112e896000: compute 7984161db3e053b5

Possibly unrelated but odd: mesh program 43ec86f35fd937b9 binds a "3109.2 MB" written storage buffer at 0x42f3478ac208f7f5 (c5+0x100, stage 7), which looks like a bad pointer read.

4. `RX_VK_NO_WRITEBACK=1` (experiment): 45 -> 57 fps

Same spot, ~3,480 draws: 56.6-57.5 fps (was ~45). GPU time spent drawing 3.95 ms, replay unchanged at 15.0 ms. The picture had extreme bloom / washout, as expected: the exposure meter's result never reaches the CPU. So the write-back is on the critical path: the frame was roughly replay (~15 ms) + the write-back at its end (~7 ms) that the next frame waits for.

5. Local patch: leave big written ranges out (`RX_VK_WB_MAX_KB=1024`)

Ranges over 1 MB are not queued for write-back; small ones (the exposure meter and other results the CPU reads) still are.

same spot, ~3,100-3,200 draws	before	`RX_VK_WB_MAX_KB=1024`
fps	45	55-56
written back a frame	68.6 MB	8.6 MB
GPU time in `m wb`	7.1 ms	0.84 ms

Picture correct: no bloom, lighting normal, no visible glitches in that session (tester's report). What it left out: 4-15.8 MB ranges in pools 0x116b/0x1170 (the culling lists), 0x1065, 0x112e.

This is a blunt rule, posted as data rather than as a proposed fix. Two risks I can see: a skipped range's guest copy goes stale, so a CPU write into the same page (mirror syncs copy whole pages) or a mirror made again would bring stale data back; and a big buffer the CPU does read would break. A precise rule (ranges only GPU stages read, or a write-back done lazily on CPU access) would be the real fix.

The patch (vk_memory.cpp, on v2.0.5)

diff --git a/gpu/vk/vk_memory.cpp b/gpu/vk/vk_memory.cpp
index c699311..d124cd9 100644
--- a/gpu/vk/vk_memory.cpp
+++ b/gpu/vk/vk_memory.cpp
@@ -2303,7 +2303,32 @@ BufferRef gpu_buffer_bind(uint64_t gpu, uint64_t size, bool written) {
         return remember({p->buffer, off, size, 0});
     }
     if (p->synced_epoch != mirror_epoch || p->sync_seg > texture_segment()) mirror_sync(*p);
-    if (written) writebacks.push_back({p, off, std::min(off + size, p->hi - p->lo)});
+    if (written) {
+        // (RX_VK_WB_MAX_KB=<n>: a written range bigger than n KB is not copied back to guest memory.
+        // The big ones are GPU-only data (the foliage culling's lists, 15-150 MB storage buffers): 26-68 MB a frame, half the
+        // GPU's time at 3500 draws, on the frame's critical path (45 -> 57 fps with no write-back at all). The small ones
+        // stay: the exposure meter and the other results the CPU reads. 0 or unset: all, as before)
+        static const uint64_t wb_max = getenv("RX_VK_WB_MAX_KB") ? strtoull(getenv("RX_VK_WB_MAX_KB"), nullptr, 10) << 10 : 0;
+        const uint64_t hi = std::min(off + size, p->hi - p->lo);
+        if (wb_max && hi - off > wb_max) {
+            static int64_t skipped_b, skipped_n;
+            static int logged;
+            skipped_b += (int64_t)(hi - off), skipped_n++;
+            if (logged < 40) {
+                static std::vector<uint64_t> seen;
+                if (std::find(seen.begin(), seen.end(), p->lo + off) == seen.end()) {
+                    seen.push_back(p->lo + off), logged++;
+                    logf("vk: write-back left out (RX_VK_WB_MAX_KB): %.1f MB at %#llx (pool %#llx)", (hi - off) / 1048576.0,
+                         (unsigned long long)(p->lo + off), (unsigned long long)p->lo);
+                }
+            }
+            if (skipped_n % 20000 == 0)
+                logf("vk: write-back left out (RX_VK_WB_MAX_KB): %lld ranges, %.0f MB so far; %.0f MB written back so far",
+                     (long long)skipped_n, skipped_b / 1048576.0, st_wb_bytes / 1048576.0);
+        } else {
+            writebacks.push_back({p, off, hi});
+        }
+    }
     return remember({p->mirror, off, size, 0});
 }

6. What is left: the CPU replay (~5 us a draw, no single hot spot)

With the write-back limit, same spot, 3,010 draws, 55.5 fps (RX_VK_PROF_FINE=1): replay 15.2 ms = draw 9.0 (descriptors 3.9, commands 3.0, program picks 1.5, pipelines 0.2) + memory sync 2.3 (~2,870 page copies a frame) + dispatch 1.0 + queue submit 0.6 + ~2 not named. Fine sections: textures 1.76 ms, bind descriptors 0.95, user uniform buffers 0.66, storage buffers 0.45, vertex+index binds 0.40.

Descriptors are built again for ~98% of draws, ~16 writes each, of which only ~4.3 differ from what was pushed last. Two local changes on top:

Sampler cache: sampler_for took reg_mu, copied and hashed the sampler registration and did a map lookup for every texture slot (~48,000 a frame). PR #901.
Stage texture reuse (experimental, not proposed yet): a graphics stage whose texture handles all come from c2 copies its image descriptors from the program's last build in the same recording when tex_gen[stage], the texture and sampler registration generations and the texture destroy generation are unchanged (gpu_written checked again for the hazard list). Kept for 62-63% of stage builds.

With both: same spot (~3,155 draws) 55.5 -> 59-60 fps (the 60 cap), replay 15.2 -> 13.8 ms, descriptors 3.87 -> 3.24 ms, fine textures 1.76 -> 1.17 ms, no visual issues in one session, no device errors. The two weren't measured separately. I can share the texture-reuse patch once it has had more play time across areas.

7. The pipeline-hitch half of this issue

Mostly gone here on v2.0.5 + #761: 0 compute pipelines built in play, ~850 graphics pipelines built in play in 0.65 s in all over the session, slow submits 2.4 s in all, the worst 0.3 s, mostly area loads (draw/descriptor/upload work), not pipeline creation. The NVIDIA shader cache size was raised to 10 GB before these runs.

Overall at that spot: ~45 fps on v2.0.5 + #761 -> a steady 60 with the write-back limit and the descriptor changes.

**Where the frame goes on a fast NVIDIA desktop: half the GPU's time is write-back copies, and they sit on the frame's critical path** Setup: RTX 4080 16 GB, i9-14900KF, 32 GB RAM, Windows 11, 2560x1440. v2.0.5 with PR #761 merged locally (renderer DLL built from source with the release builder's toolchain). In-game: resolution 100%, frame generation off, frame pacing on, robust buffers off. `EDEN_NX2_GM_LEGACY=1` and `HOS_PIN=MainThread=FFFF,Presentation=FFFF,ModuleSystemWorker=FFFF` (busiest threads on the P-cores) in every run. Same busy outdoor spot in every run (~3,000-3,500 draws a frame). Numbers are from the runs' own `vk:` log lines; fps = the 2 s log windows with more than 300 draws. ### 1. Nothing is saturated, and the in-game settings change nothing | | value | |---|---| | fps | ~45 (frame ~22.4 ms) | | replay (CPU, `submit`) | 15.2 ms | | GPU time | 13.4 ms | | `GPU-bound wait` | 0.0-0.1 ms | Resolution 100% -> 50% and frame pacing off: fps unchanged (44-45 throughout), GPU time unchanged (13.4 ms). ### 2. `RX_VK_GPU_PROFILE=1`: the write-back copies are half the GPU's time Per frame at ~3,530 draws: | kind | ms | share | per frame | |---|---|---|---| | `m wb` (mirror -> guest memory) | 7.08 | 52.8% | 10.3 spans, 68.5 MB | | `m pass` (all draws) | 3.55 | 26.4% | 170 passes, 3,489 draws | | `m dispatch` | 1.80 | 13.4% | 132 | | `m barrier` | 0.73 | 5.5% | 338 | | `u msync` | 0.65 | | 12 MB | That is why resolution does nothing here: the drawing itself is ~3.5 ms. `gpu_buffer_bind` queues every written storage buffer range for a copy back at the submission's end (`vk_memory.cpp`, `writebacks.push_back`), whether or not the CPU ever reads it. ### 3. `RX_VK_LOG_WRITEBACK=1`: what is copied back Per write-back submission (~3,180 draws, 45 fps): ~6.6 MB, almost all from pool `0x116b000000` (144 MB pool, ~5.3 MB in 5 runs) and `0x112e000000` (32 MB pool, ~1 MB). Pool `0x116b...` is where the foliage culling keeps its per-category draw lists / task arguments (the `0x116ba70000` region discussed in #763), read by GPU task shaders, not by the CPU as far as I can tell. Big written storage buffers logged: - 15.2 MB at `0x116d5d6000`: compute `102f5b0abb0f1e63`, `78ccf14779ec3efb`, `7650519f88e59b19`, `abccf81b45c5eb50` - 15.8 MB in pool `0x1065000000`: compute `e409733c45530d75`, `8306877b7dc8784b`, `14140d4c1dbe754f` - 149.6 MB at `0x107f7e8000`: compute `4b03b3040d7cf076`, `26fe0c70ab9fc547` (ssbo 0 of 3, c0+0x880) - 9.5 MB at `0x112e896000`: compute `7984161db3e053b5` Possibly unrelated but odd: mesh program `43ec86f35fd937b9` binds a "3109.2 MB" written storage buffer at `0x42f3478ac208f7f5` (c5+0x100, stage 7), which looks like a bad pointer read. ### 4. `RX_VK_NO_WRITEBACK=1` (experiment): 45 -> 57 fps Same spot, ~3,480 draws: **56.6-57.5 fps** (was ~45). GPU time spent drawing 3.95 ms, replay unchanged at 15.0 ms. The picture had extreme bloom / washout, as expected: the exposure meter's result never reaches the CPU. So the write-back is on the critical path: the frame was roughly replay (~15 ms) + the write-back at its end (~7 ms) that the next frame waits for. ### 5. Local patch: leave big written ranges out (`RX_VK_WB_MAX_KB=1024`) Ranges over 1 MB are not queued for write-back; small ones (the exposure meter and other results the CPU reads) still are. | same spot, ~3,100-3,200 draws | before | `RX_VK_WB_MAX_KB=1024` | |---|---|---| | fps | 45 | **55-56** | | written back a frame | 68.6 MB | 8.6 MB | | GPU time in `m wb` | 7.1 ms | 0.84 ms | Picture correct: no bloom, lighting normal, no visible glitches in that session (tester's report). What it left out: 4-15.8 MB ranges in pools `0x116b`/`0x1170` (the culling lists), `0x1065`, `0x112e`. This is a blunt rule, posted as data rather than as a proposed fix. Two risks I can see: a skipped range's guest copy goes stale, so a CPU write into the same page (mirror syncs copy whole pages) or a mirror made again would bring stale data back; and a big buffer the CPU does read would break. A precise rule (ranges only GPU stages read, or a write-back done lazily on CPU access) would be the real fix. <details><summary>The patch (vk_memory.cpp, on v2.0.5)</summary> ```diff diff --git a/gpu/vk/vk_memory.cpp b/gpu/vk/vk_memory.cpp index c699311..d124cd9 100644 --- a/gpu/vk/vk_memory.cpp +++ b/gpu/vk/vk_memory.cpp @@ -2303,7 +2303,32 @@ BufferRef gpu_buffer_bind(uint64_t gpu, uint64_t size, bool written) { return remember({p->buffer, off, size, 0}); } if (p->synced_epoch != mirror_epoch || p->sync_seg > texture_segment()) mirror_sync(*p); - if (written) writebacks.push_back({p, off, std::min(off + size, p->hi - p->lo)}); + if (written) { + // (RX_VK_WB_MAX_KB=<n>: a written range bigger than n KB is not copied back to guest memory. + // The big ones are GPU-only data (the foliage culling's lists, 15-150 MB storage buffers): 26-68 MB a frame, half the + // GPU's time at 3500 draws, on the frame's critical path (45 -> 57 fps with no write-back at all). The small ones + // stay: the exposure meter and the other results the CPU reads. 0 or unset: all, as before) + static const uint64_t wb_max = getenv("RX_VK_WB_MAX_KB") ? strtoull(getenv("RX_VK_WB_MAX_KB"), nullptr, 10) << 10 : 0; + const uint64_t hi = std::min(off + size, p->hi - p->lo); + if (wb_max && hi - off > wb_max) { + static int64_t skipped_b, skipped_n; + static int logged; + skipped_b += (int64_t)(hi - off), skipped_n++; + if (logged < 40) { + static std::vector<uint64_t> seen; + if (std::find(seen.begin(), seen.end(), p->lo + off) == seen.end()) { + seen.push_back(p->lo + off), logged++; + logf("vk: write-back left out (RX_VK_WB_MAX_KB): %.1f MB at %#llx (pool %#llx)", (hi - off) / 1048576.0, + (unsigned long long)(p->lo + off), (unsigned long long)p->lo); + } + } + if (skipped_n % 20000 == 0) + logf("vk: write-back left out (RX_VK_WB_MAX_KB): %lld ranges, %.0f MB so far; %.0f MB written back so far", + (long long)skipped_n, skipped_b / 1048576.0, st_wb_bytes / 1048576.0); + } else { + writebacks.push_back({p, off, hi}); + } + } return remember({p->mirror, off, size, 0}); } ``` </details> ### 6. What is left: the CPU replay (~5 us a draw, no single hot spot) With the write-back limit, same spot, 3,010 draws, 55.5 fps (`RX_VK_PROF_FINE=1`): replay 15.2 ms = draw 9.0 (descriptors 3.9, commands 3.0, program picks 1.5, pipelines 0.2) + memory sync 2.3 (~2,870 page copies a frame) + dispatch 1.0 + queue submit 0.6 + ~2 not named. Fine sections: textures 1.76 ms, bind descriptors 0.95, user uniform buffers 0.66, storage buffers 0.45, vertex+index binds 0.40. Descriptors are built again for ~98% of draws, ~16 writes each, of which only ~4.3 differ from what was pushed last. Two local changes on top: 1. **Sampler cache**: `sampler_for` took `reg_mu`, copied and hashed the sampler registration and did a map lookup for every texture slot (~48,000 a frame). PR #901. 2. **Stage texture reuse** (experimental, not proposed yet): a graphics stage whose texture handles all come from c2 copies its image descriptors from the program's last build in the same recording when `tex_gen[stage]`, the texture and sampler registration generations and the texture destroy generation are unchanged (`gpu_written` checked again for the hazard list). Kept for 62-63% of stage builds. With both: same spot (~3,155 draws) **55.5 -> 59-60 fps (the 60 cap)**, replay 15.2 -> 13.8 ms, descriptors 3.87 -> 3.24 ms, fine textures 1.76 -> 1.17 ms, no visual issues in one session, no device errors. The two weren't measured separately. I can share the texture-reuse patch once it has had more play time across areas. ### 7. The pipeline-hitch half of this issue Mostly gone here on v2.0.5 + #761: 0 compute pipelines built in play, ~850 graphics pipelines built in play in 0.65 s in all over the session, slow submits 2.4 s in all, the worst 0.3 s, mostly area loads (draw/descriptor/upload work), not pipeline creation. The NVIDIA shader cache size was raised to 10 GB before these runs. Overall at that spot: ~45 fps on v2.0.5 + #761 -> a steady 60 with the write-back limit and the descriptor changes.

NotRexed commented

2026-11-09 05:48:02 +00:00

(Migrated from github.com)

Tracked in #995, follow there. That issue collects every report of low FPS while the GPU is not fully used, and shader stutter, and this one is linked from it with its GPU, version and log details. If it still happens on v2.0.6 (https://github.com/NotRexed/Hookshot/releases/tag/v2.0.6; Update next to Play in the launcher), please add a comment there with your hookshot_log.txt.