feat(vk): time a capture's GPU wait for its late pages apart in the log #1243

Merged

Nitnek merged 1 commit from fix/capture-wait-log into main

2026-11-09 23:03:25 +00:00

Nitnek commented

2026-11-09 18:45:08 +00:00

(Migrated from github.com)

What changed

take_capture waits for the GPU (vk_timeline_wait(c->late_value)) before it copies the pages that a submission still on the GPU writes back. That wait was counted in "retires and stamps". So the 600-take log line could not tell the replay thread waiting for the GPU from its own bookkeeping.

The wait and the pools_mu acquisition are now timed apart, and the line reads:

vk: a capture taken (ms): all 1.932; GPU wait for late pages 1.806 (99 of 600 takes), pools lock 0.000, retires and stamps 0.112, bytes copied 0.000; ...

"Retires and stamps" now starts once pools_mu is held. Nothing else changes: no new switch, no behaviour change.

Why

This is the cost behind part of #995 (low FPS with low GPU use). The fewer pools have a VRAM mirror, the more often a submit waits for the GPU here, about six captures a frame. Until now it only showed as an unexplained "retires and stamps". With this line a player's hookshot_log.txt tells at once whether a small mirror budget is what holds the frame rate. That covers RX_VK_MIRROR_MB set low, the VRAM/8 default of 6 GB cards, and the 4GB preset's 256 MB. Measurements are in this #995 comment.

How it was tested

RTX 3070 8 GB, Windows 11, main at 09e4eb5 plus this commit. Scripted Hyrule Field run: load the save, run the same 45 s route.

`RX_VK_MIRROR_MB`	avg FPS	GPU wait for late pages	all
1024	40.9	0.64-1.81 ms (~100 of 600 takes)	0.83-1.93 ms
2048 (the 8 GB default)	52.1	0.04-0.12 ms	0.21-0.27 ms

tests/test_capture_wait_log.py (new) checks that the wait is timed on its own, that "retires and stamps" starts after the lock, and that the line names and resets both. It fails on main and passes here. The other tests reading vk_memory.cpp still pass: bind_memo, capture_copy_runs, mem_trim, parallel_rb_refresh, pool_span, report_words, submitted_page, vertex_bind, wb_diff_split, wb_pages (tests/run_all.py, llvm-mingw).

No game data included.

🤖 Generated with Claude Code

## What changed `take_capture` waits for the GPU (`vk_timeline_wait(c->late_value)`) before it copies the pages that a submission still on the GPU writes back. That wait was counted in "retires and stamps". So the 600-take log line could not tell the replay thread waiting for the GPU from its own bookkeeping. The wait and the `pools_mu` acquisition are now timed apart, and the line reads: ``` vk: a capture taken (ms): all 1.932; GPU wait for late pages 1.806 (99 of 600 takes), pools lock 0.000, retires and stamps 0.112, bytes copied 0.000; ... ``` "Retires and stamps" now starts once `pools_mu` is held. Nothing else changes: no new switch, no behaviour change. ## Why This is the cost behind part of #995 (low FPS with low GPU use). The fewer pools have a VRAM mirror, the more often a submit waits for the GPU here, about six captures a frame. Until now it only showed as an unexplained "retires and stamps". With this line a player's `hookshot_log.txt` tells at once whether a small mirror budget is what holds the frame rate. That covers `RX_VK_MIRROR_MB` set low, the VRAM/8 default of 6 GB cards, and the 4GB preset's 256 MB. Measurements are in [this #995 comment](https://git.magicbean.dev/MagicBeanDev/Hookshot/issues/995). ## How it was tested RTX 3070 8 GB, Windows 11, main at 09e4eb5 plus this commit. Scripted Hyrule Field run: load the save, run the same 45 s route. | `RX_VK_MIRROR_MB` | avg FPS | GPU wait for late pages | all | |---|---|---|---| | 1024 | 40.9 | 0.64-1.81 ms (~100 of 600 takes) | 0.83-1.93 ms | | 2048 (the 8 GB default) | 52.1 | 0.04-0.12 ms | 0.21-0.27 ms | `tests/test_capture_wait_log.py` (new) checks that the wait is timed on its own, that "retires and stamps" starts after the lock, and that the line names and resets both. It fails on main and passes here. The other tests reading `vk_memory.cpp` still pass: `bind_memo`, `capture_copy_runs`, `mem_trim`, `parallel_rb_refresh`, `pool_span`, `report_words`, `submitted_page`, `vertex_bind`, `wb_diff_split`, `wb_pages` (`tests/run_all.py`, llvm-mingw). No game data included. 🤖 Generated with [Claude Code](https://claude.com/claude-code)

Nitnek commented

2026-11-09 19:00:26 +00:00

(Migrated from github.com)

The two red "Python source checks" jobs fail on tests/test_output_resolution.py, not on this change. That test fails the same way on main (09e4eb5 and 5d1fe99, run locally): it still expects hos_rt_pool_size(305 MB) == 305 MB, while #1202 gave the render-target pool a 512 MiB minimum. #1254 updates the test. tests/test_capture_wait_log.py and the other vk_memory.cpp tests pass on both runners.

The two red "Python source checks" jobs fail on `tests/test_output_resolution.py`, not on this change. That test fails the same way on main (09e4eb5 and 5d1fe99, run locally): it still expects `hos_rt_pool_size(305 MB) == 305 MB`, while #1202 gave the render-target pool a 512 MiB minimum. #1254 updates the test. `tests/test_capture_wait_log.py` and the other `vk_memory.cpp` tests pass on both runners.

hckrman101 (Migrated from github.com) approved these changes

2026-11-09 22:42:59 +00:00

hckrman101 (Migrated from github.com) left a comment

Looks good. I checked the timing split in take_capture: tk1 is still taken after the lock, so measuring retires and stamps from tk_locked is right, and the wait and lock are now separate counters that reset together with the late-take count. The new test is picked up by run_all.py's tests/test_*.py glob and passes on both runners.

The two red Python source checks are only tests/test_output_resolution.py, which is the known failure on main (not this PR).

Commenting is not possible because the repository is archived.

No reviewers

hckrman101