Repository navigation
perf: a frame critical-path recorder (HOS_CHAIN), and an opt-in presenter thread that takes NVIDIA's present wait off the game's thread - #2325
Conversation
…reads
A diagnostic switch for where a frame's time goes once it is not one thread's: HOS_CHAIN=<file> records, while
<file>.go exists, every wait of a game thread that blocks (events, semaphores, message queues, mutexes, condition
variables, multi-waits, the kernel's waits, a virtual core), every signal that can end one, every guest sleep and every
present, with the time, the thread, the object and the guest caller. scripts/chain.py walks each frame back from its
present through those waits and the signals that ended them, and prints the frame's critical path by thread: its
stretches (a thread from the wake-up that put it on the path to the signal that handed it on), running time, wake-ups,
waits for a virtual core, sleeps; with an HOS_SAMPLE_ALL file of the same run (each sample then carries its own time),
the functions on that path.
scripts/crit.py (and chain.py) no longer count a sample whose leaf is outside Hookshot as blocked: libc's copies and the
driver's own work are the thread's CPU time; a sample is blocked only under a known wait (prof.WAIT_FRAMES). prof.py
keeps anonymous-namespace names (mkwvk::{anon}::present) instead of cutting them to mkwvk::.
Off, it costs a load and a branch per blocking wait and per signal.
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
… then presents (RX_VK_PRESENT_THREAD=1) With NVIDIA's driver on Wayland, vkQueuePresentKHR waits on the CPU until the frame's copy into the window is done on the GPU: about 2 ms a frame on the game's presentation thread, on the frame's critical path, since the game's main thread waits for that present to return before it starts the next frame's commands (HOS_CHAIN). With the switch, the present goes to a thread of its own, which waits for the copy's fence (1.75-1.92 ms) and then presents (0.18-0.22 ms); the game's present call returns in about 0.1 ms. RTX 3090, Kokiri Forest, recording on: 22.1 and 22.9 ms a frame off against 20.1 and 19.0 on. One present out at most, presents in order; on the replay's queue the presenter takes the queue's lock only for vkQueuePresentKHR, and a swapchain is made again only with the presenter idle (the wait comes before the queue's lock). Not for frame interpolation's paced presents or with Reflex on. Off by default. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
… the frame's copy as a GPU wait On NVIDIA's driver on Linux, vkQueuePresentKHR waits on the CPU until the frame's copy into the window's image is done, ~2 ms a frame on an RTX 3090. The Breakdown counted the whole present as pacing. Now a present whose copy was not done when it was called and was done when it returned counts as a GPU wait (two fence reads while the Breakdown shows, nothing waited for); any other present stays pacing (vsync). With RX_VK_PRESENT_THREAD=1 the game thread's wait for the presenter is split where the presenter's wait for the copy ended. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…for its present to be shown under FIFO, and is on by default The presenter thread presented on the replay's queue under its lock, and a vkQueuePresentKHR that blocked there (up to hundreds of ms after a map load) held the replay's submits and uploads: stalls in Hyrule Field that the game's own present did not have. The device now gets a queue for the presenter alone: a second queue of the replay's family where it has one, else a compute-only family's (its swapchain images shared concurrently). A device without one, or whose queue cannot present to the window, keeps the presents on the game's thread. One present is out at most. Under FIFO, with VK_KHR_present_id and VK_KHR_present_wait, the next hand-off waits until the present is shown; under mailbox and immediate it does not (that would cap Uncapped at the refresh rate). Every wait is bounded: the copy's fence in 100 ms steps up to 5 s, the present wait in 20 ms steps, a drain gives up after 5 s. vkDeviceWaitIdle takes the presenter's queue lock too. On by default; RX_VK_PRESENT_THREAD=0 turns it off. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…#2354) **What this is for:** frame times from headless runs, the kind scripted tests and measurements use. `RX_VK_FRAME_LOG=<csv>` ("A CSV line per present: frame, seconds, frame time in ms", docs/development.md) writes nothing in a headless run (`HOS_HEADLESS`): the file is never even created. Fixes #2353. **What is measured:** on Linux (RTX 4090, NVIDIA 615.78.08) a headless run with the change wrote 6480 lines over 108.9 s, and its first interval equals the game's own present trace of the same run; none of 23 headless runs of main left a file; a game-free test that fails on main; the whole of the checks. **Not measured:** a windowed run with the change (that path calls the same code at the same place as before), Windows game runtime, AMD, the Steam Deck under gamescope. ## What changed - `gpu/vk/vk_replay.cpp`: the writer was only in `present_out`, after `vkQueuePresentKHR`. Without a window a present copies the picture into the offscreen image and `do_present` returns before `present_image`, so it never got there. The writer is now `frame_log_present()`, unchanged (same file, header, columns and flush every 60 lines), called where it was and at the end of a headless `do_present`, once the copy into the offscreen image is submitted. - Frame generation is off without a window (`framegen_on`), so a headless run writes one line per game frame, as a window does without frame generation. - The times are the same steady clock as before. A headless run has no swapchain to wait on, so they show the game's and the replay's pace without the display's (V-Sync, the compositor). - `tests/test_frame_log_headless.py` (game-free): compiles the actual `frame_log_present` and checks its CSV header, sequence numbers, elapsed/interval times, and disabled output. It does not infer execution from call-site spelling. - `docs/development.md`: documents headless CPU intervals and the absence of swapchain/display waits. ## How it was tested Latest refresh, 2026-11-11: head `e3119ce0` on `47ed9f14`, including the merged #2397 Windows ASTC fixture repair. The `present_native_pq` conflict was resolved by retaining main’s moved declaration and this PR’s logger. The compiled CSV writer passes with GCC and Clang. No new game run or full local suite was made for this refresh; [Source-regression CI](https://github.com/NotRexed/Hookshot/actions/runs/43093270209) now passes on this head: both Windows and both Ubuntu shards. RTX 4090, NVIDIA 615.78.08, Arch Linux; headless (`HOS_HEADLESS=1`, the log says `vk: no window: presents render offscreen (1920x1080)`), from a fresh profile, no input, 120 s, muted, `RX_VK_FRAME_LOG` and `HOS_PRESENT_TRACE` set. - Main: none of 23 such headless runs left a frame log (the switch was set in every one). - With this change: `frames.csv` holds the header and 6480 lines, frames 0 to 6479 over 108.9 s, times rising from 0; the frame times average 16.80 ms (59.5 fps; the last 30 s 59.9 fps) with the game at its 60 cap through the intro movie and the title screen (pictures of the run looked at). The game's own present trace of the same run has the same first interval (43.28 ms) and 6432 presents over 108.1 s. (Not a frame-rate claim: other work ran beside it.) - That run was of this change on main bdfe09c (commit 7da36252). Rebased onto 49f75dc the change is the same apart from one blank line. Added 2026-11-11 16:27 UTC: the rebased build (cc36308 on 49f75dc, `hookshot v2.1.0-rc.3-54-gcc363089`) ran the same way, 150 s: `frames.csv` holds the header and 5880 lines, frames 0 to 5879 over 98.4 s, times rising from 0; its first interval (32.909 ms) equals the game's own present trace of that run (32,908,677 ns); no FATAL or device-lost line, no driver line in the kernel log. (Load average 22 falling to 9: not a frame-rate claim.) - Updated 2026-11-11: rebased onto `7759a6f3`, head `5ce5970f`. #1995 changed `present_out` to return `bool`; the old test pinned its full signature. The source-text call-site assertions are removed rather than repinned. The compiled writer check passes with GCC 16.2.1 and Clang 23.1.3: `PASS: frame log CSV header, sequence, elapsed/interval times, and disabled output`. Against main it fails because main has no extracted `frame_log_present` helper; that is not a headless integration test. Headless integration evidence is the two older game runs above. - On `5ce5970f`, `tests/run_all.py`: `385 passed, 2 failed, 10 skipped in 141 s`. `test_updater_asset_digest.py` cannot resolve the .NET 8 reference packs on this machine. `nx2/test_texture_phi_dominance.py` had a compiler killed by SIGKILL; its narrow rerun alone passed (`1 passed, 0 failed, 0 skipped in 20 s`). No second full suite was run. - Earlier suite on `cc363089` (load 57 to 113), `python -I -B tests/run_all.py`: `362 passed, 3 failed, 10 skipped in 193 s (linux, 32 at once)`. Two of the failures are this machine's and fail on main as well, each with a pull request of its own: `tests/test_updater_asset_digest.py` (only a .NET 10 SDK here, #2294) and `tests/test_wayland_libdecor_hint.py` (Clang 23, #2290). The third, `tests/test_display_pointer.py`, failed under that load at `reads > 0` (its reader thread had made no read yet when the check ended) and passes when run alone (3 of 3, at load 55). Added 2026-11-11: [Windows part 2/2](https://github.com/NotRexed/Hookshot/actions/runs/43072060527/job/130702262513) passes `tests/test_frame_log_headless.py`. The job fails only on the unrelated ASTC fixture’s `scanf` deprecation, fixed by #2397, which has now merged and is included in the latest refresh. This is Windows coverage of the compiled writer, not a game run. ## Not tested - No new game build/run after the subsequent rebases, including `47ed9f14`; the game runs above name their earlier heads. The renderer patch remains the same; #1995's surface-loss return stays before the existing window log position. - A windowed run of this branch: the window's path calls the same function at the same place as before; not run here. - Windows game runtime, AMD, the Steam Deck under gamescope (the switch's first use). ## Risks - A windowed run writes exactly what it wrote: the same function is called at the same place in `present_out`. - A headless line is written when the offscreen copy is submitted, not when a display shows it: there is no display. Its times are the game's and the replay's pace. Nobody should read them as presentation times, which the description of the switch does not promise either. - The file is opened at the first present, as before; a run without the switch pays one `getenv` at its first present and a null check after that. ## Overlaps Updated 2026-11-11 after the refresh: 49 open PRs touch one of this branch’s three files; one additional text conflict was reported, and its hunk was read. - #2325 (frame critical-path recorder / asynchronous presenter): its presenter-specific surface-loss and deferred-resize handling meets the old inline frame logger in `present_out`. Keep that handling and call the extracted logger once at the corresponding present boundary; do not restore a second inline writer. No combined runtime test was made. - The earlier `present_native_pq` declaration conflict is resolved in this rebase. Assisted-by: Claude Opus 5.5 Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Assisted-by: GPT-6 Astra Co-Authored-By: GPT-6 Astra <noreply@openai.com> --------- Co-authored-by: Claude Opus 5.5 <noreply@anthropic.com> Co-authored-by: GPT-6 Astra <noreply@openai.com>
…ly (#2251 follow-up) (#2490) `tests/test_recorder_sync.py` still fails now and then on the Windows "Python source checks" job after #2251 (for example on #2325 and #2447), with `FAIL thread oversize: 0 calls made directly, 1 expected`. The cause is in `vk_recorder.h`, not in the test: whether a packet bigger than its room was made directly depended on how far the recorder thread had got. ## Why it flaked The failure is not a late read of `g_rec.direct`. The producer thread bumps that counter itself, before the `vkCmd*` returns. Also, the failing process never logged `did not fit in the room a packet is given`, so the 4 KB `vkCmdUpdateBuffer` never took the direct path at all. It was written into the ring. `Recorder::reserve()` waits until `room` bytes are free, but then lets the packet use everything free and contiguous ahead of it, `min(tail, cap - (w - r_seen))`. In the oversize scenario (8 KB ring, 2 KB room) that means: - If the recorder is behind, only about the room is free, so the 4 KB packet does not fit and is made directly. This is the usual case, and what the test expects. - If the recorder has caught up and the producer has just re-read `R` (a loaded runner that preempts the producer), up to 8 KB is free. The packet then fits, is packed, and `direct` stays at 0. The log matched either way, which is why only the counter check failed. The header comment, `g_ring_room`'s comment and the stats line all say a packet bigger than its room is made directly. ## What changes - `reserve()` hands out exactly `room` bytes (`lim = base + off + room`). Those bytes are free and contiguous because `wait_room()` already waited for them, so the packet's size alone decides. In the renderer the room is 80 KB, sized so a 64 KB `vkCmdUpdateBuffer` fits. A larger packet now always takes the direct path, where before it was sometimes packed. - `recorder_sync_test.cpp` runs the oversize packet a second time, as the first packet in an empty ring: the recorder is stopped and its counters are moved to the ring's start. With the old `reserve()` the packet is packed there on every run, so the check no longer depends on timing to catch this. - `test_recorder_sync.py` adds a broken variant with the old limit, which must fail (caught). The "no backpressure" variant now matches the new line. ## How it was verified - `python -I -B tests/test_recorder_sync.py --headers <Vulkan-Headers>` passes on Linux (clang++), with every broken variant caught, the new one included. - The new test against the old header (`--only thread`) failed 50 of 50 runs with `FAIL thread oversize, ring empty: 0 calls made directly, 1 expected`. That is the CI message, now deterministic. - Loaded runs of `--only thread`, 200 runs each for the old and new code, in two setups: lanes pinned to 1 CPU with a busy-loop on the same CPU, and lanes of 2 CPUs with a busy-loop on one of them. Every run passed. I could not reproduce the old flake on Linux, so the deterministic check above is the evidence for the cause. The 1e6-packet stress check still passes with every frame packet on the recorder. - The test compiles warning-free (`-Werror`) with llvm-mingw (`x86_64-w64-mingw32-clang++`) before and after the change. It was not run on Windows. - The change has no effect on calls that fit in the room, shown from the code. A packet is one vkCmd* call: each packer opens one `Enc`, which reserves once and emits once. `publish()` moves `w` by the packet's own size, not by `lim`, so the cap never ends an encoder early or splits a call. `reserve()`'s waits (`wait_room(room)`, or `tail + room` at the wrap) and its `r_seen` refreshes are unchanged, and the old `lim` was never below `room` (`tail >= room`, and `wait_room()` had made `room` bytes free). So for every packet of `room` bytes or less, the same bytes go to the same place, with the same publishes, ring waits and no direct call, exactly as before. Only a single call whose packet is bigger than the room behaves differently: it is now always made directly (counted in the stats line's "calls made directly (no room)"), instead of being packed when the recorder happened to be far enough ahead. In the renderer the room is 80 KB. The test's frame still runs all 267 of its vkCmd* on the recorder thread, and the 1e6-packet stress check passes. I did not do a game run. Co-authored-by: Claude Opus 5.5 <noreply@anthropic.com>
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
|
Reviewed the diff and ran the presenter thread on a second NVIDIA setup, which the PR lists as untested. ReviewThe presenter thread holds up. I traced each lock path:
Small things:
The PR's own tests pass here: Measured: RTX 4070 Ti, Ryzen 7 9800X3D, Linux, NVIDIA 595.99.02Branch head Median frame time, ms:
* That off run never stood in the scene (4.2 ms frames), so it is left out.
Caveat: another game build and its shader preparation ran on the same PC during both series, and this CPU is a single core complex, so I could not give the game cores of its own. The pairs alternate, so both arms carry the same noise, but the absolute numbers are noisier than the PR's. So on a faster, nearly GPU-bound setup the presenter thread does not help. It looks right to keep it opt-in, and the "check other GPUs before default" step in the PR should probably include a GPU-bound case like this one. |
…IA's and RADV's queue family layouts The choice moves to gpu/vk/presenter_queue.h, and tests/presenter_queue_test.cpp runs it on NVIDIA's layout (a second queue of the 16-queue graphics family) and RADV's (one graphics queue: queue 0 of the compute family, or queue 1 when the presents' own queue, RX_VK_PRESENT_QUEUE, takes queue 0). It also covers a one-queue compute family that is already taken and a lone queue: no presenter queue, so the presents stay on the game's thread. The presenter never shares a VkQueue with the replay or the presents' own queue. On the RX 580 its queue was compute family 1, queue 0, a queue nothing else uses when RX_VK_PRESENT_QUEUE is off. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
A review of the presenter thread merged in #2325 found two problems that make it unsafe as a default, so this turns it off again until they are fixed. - **The swapchain is used from two threads with no lock between them.** The game thread's `vkAcquireNextImageKHR` runs while the presenter thread calls `vkQueuePresentKHR` and `vkWaitForPresentKHR` on the same swapchain. All three need the swapchain externally synchronized. The overlap happens every frame, by design. - **The drain before a swapchain remake gives up after 5 s.** Its callers then destroy the swapchain and semaphores the presenter may still be using. The presenter's own worst case (the copy's fence for 5 s, then the present) is longer than that. The same limit in `present_out` lets two presents go out of order. ## What changes - `RX_VK_PRESENT_THREAD` is off unless set to `1`. Off, the device makes no queue for the presenter, so the device and the presents are as they were before #2325. - The docs row and `tests/test_present_thread.py` say it is off by default. The test also checks that no queue is made for it while it is off. The fixes (one lock or an idle wait around the swapchain's acquire and present, a drain that never gives up and leaves the swapchain alone, and the smaller findings) follow in their own PR. That PR turns the default back on only if every fix holds and is tested. Tested: `tests/test_present_thread.py`, `tests/test_fps_stats.py` and `tests/test_present_semaphores.py` pass, and the Vulkan back end builds. Co-authored-by: Claude Opus 5.5 <noreply@anthropic.com>
A dGPU has its own fast memory and a slower bus to system RAM; stock mirrors every guest pool into VRAM and keeps both copies coherent with captures, shadows and write-backs. At 4K that coherence is CPU-bound: the write-back diff compares ~3.1 GB per 600 submits and mirror syncs move ~137k dirty pages, for 35.6 fps where 1080p runs 60 (issue NotRexed#2099). Under RX_VK_DGPU=1 a pool's first binding makes no mirror (MIRROR_REFUSED, the state iGPU runs use today): reads take the lock-free TLS path and GPU reads/writes land in the imported guest memory, coherent by construction - no mirror sync, no write-back. Every 600-submit window the heaviest guest-memory-read pool with >=1 MB of reads and not write-dominated runs a measured trial (120 frames direct -> 12 settle, held until the mirror is really on -> 120 mirrored, on the recordings' own timestamps); the mirror stays only when the win is both >10% (RX_VK_DGPU_GAIN) and >0.25 ms (RX_VK_DGPU_FLOOR) on present-to-present frame time, so the verdict sees the mirror's CPU cost and its PCIe benefit alike. Trials whose windows did not measure the same workload (zero binds, a >2x bind shift, a mirror that never came) abort with no verdict and no skip line; a pool that aborts three times sits out the session, and iGPUs run no trials. A lost verdict persists to hookshot_mirror_skip.txt beside the game's own state files, keyed to the device and driver (a foreign or header-less file is ignored and re-trialled). RX_VK_DGPU_TRIALS=0 is pure direct. Trials need serial replay (documented); under RX_VK_PARALLEL the policy runs trial-less. Unset = stock exactly: the added counters and logging are gated on the switch. Refused pools read uniform buffers as submitted (NotRexed#1795's per-pool form: the snapshot engages for mirror-less pools at the read, trial-won pools keep in-place mirror binds), so the artifact class the issue documents on mirror-less GPUs is covered under the policy too. Measured on RX 9070 XT / RADV, 4K, Uncapped frame cap, warp-normalized adjacent pairs (Hyrule Field): 70.2->78.0, 71.0->77.0, 59.6->76.6 fps (+9.7% median), draw parity 705 vs 709, GPU 9.2 ms of a ~14 ms frame. Mirror-sync dirty pages 136,872 -> 0; write-back diff 3.06-3.13 GB -> 330 MB or less per 600 submits. Review round 2 (external): RX_VK_DGPU_TRIALS=0's predicate was inverted and now matches the docs (=0 is pure direct); the window's read counter moved off a shared map into the pool (dgpu_read, both direct paths); Settle holds until the mirror is actually live; zero-bind baselines and >2x bind drift between the direct and mirrored windows abort the trial un-blacklisted; keep_line refuses signed and trailing-garbage lines. Review round 3 (hckrman101, Joey-Magnus): refused pools read UBs as submitted (NotRexed#1795 per-pool, live-smoked at 1.26M copies fault-free); verdicts decide on present-to-present frame time instead of GPU-only time (the mirror's CPU and upload-buffer cost is what the frame pays); the policy runs trial-less under RX_VK_PARALLEL and its fast-path counters are parallel-safe; no trials on iGPUs and a 3-abort cap; the skip list carries a device+driver header and ignores foreign files; the test driver uses {cxx}. Follow-up fix: the drift check counted served volume, so a working mirror's read collapse voided 40+ trials a run and trials never converged; binds now count once at the serving path and the drift rule compares the scene's pool set, with a three-no-verdict cap. Rebased onto main's env_on switch rule (NotRexed#2042) and the split-submission fence work (NotRexed#2419); the trials' functions sit outside the write-back observation's compile-span check (NotRexed#2131) and the GCN mirror-less default (NotRexed#2343) composes unchanged (on GCN the switch runs trial-less direct plus the UB snapshot). After the presenter-thread refactor (NotRexed#2325) the present-to-present tick lives in present_finish, which every made present passes exactly once in either threading mode, with a headless twin so offscreen runs stay measurable. Co-authored-by: GLM-5.3-Flash <glm-5.3-flash@opencode.noreply.github.com>
A dGPU has its own fast memory and a slower bus to system RAM; stock mirrors every guest pool into VRAM and keeps both copies coherent with captures, shadows and write-backs. At 4K that coherence is CPU-bound: the write-back diff compares ~3.1 GB per 600 submits and mirror syncs move ~137k dirty pages, for 35.6 fps where 1080p runs 60 (issue NotRexed#2099). Under RX_VK_DGPU=1 a pool's first binding makes no mirror (MIRROR_REFUSED, the state iGPU runs use today): reads take the lock-free TLS path and GPU reads/writes land in the imported guest memory, coherent by construction - no mirror sync, no write-back. Every 600-submit window the heaviest guest-memory-read pool with >=1 MB of reads and not write-dominated runs a measured trial (120 frames direct -> 12 settle, held until the mirror is really on -> 120 mirrored, on the recordings' own timestamps); the mirror stays only when the win is both >10% (RX_VK_DGPU_GAIN) and >0.25 ms (RX_VK_DGPU_FLOOR) on present-to-present frame time, so the verdict sees the mirror's CPU cost and its PCIe benefit alike. Trials whose windows did not measure the same workload (zero binds, a >2x bind shift, a mirror that never came) abort with no verdict and no skip line; a pool that aborts three times sits out the session, and iGPUs run no trials. A lost verdict persists to hookshot_mirror_skip.txt beside the game's own state files, keyed to the device and driver (a foreign or header-less file is ignored and re-trialled). RX_VK_DGPU_TRIALS=0 is pure direct. Trials need serial replay (documented); under RX_VK_PARALLEL the policy runs trial-less. Unset = stock exactly: the added counters and logging are gated on the switch. Refused pools read uniform buffers as submitted (NotRexed#1795's per-pool form: the snapshot engages for mirror-less pools at the read, trial-won pools keep in-place mirror binds), so the artifact class the issue documents on mirror-less GPUs is covered under the policy too. Measured on RX 9070 XT / RADV, 4K, Uncapped frame cap, warp-normalized adjacent pairs (Hyrule Field): 70.2->78.0, 71.0->77.0, 59.6->76.6 fps (+9.7% median), draw parity 705 vs 709, GPU 9.2 ms of a ~14 ms frame. Mirror-sync dirty pages 136,872 -> 0; write-back diff 3.06-3.13 GB -> 330 MB or less per 600 submits. Review round 2 (external): RX_VK_DGPU_TRIALS=0's predicate was inverted and now matches the docs (=0 is pure direct); the window's read counter moved off a shared map into the pool (dgpu_read, both direct paths); Settle holds until the mirror is actually live; zero-bind baselines and >2x bind drift between the direct and mirrored windows abort the trial un-blacklisted; keep_line refuses signed and trailing-garbage lines. Review round 3 (hckrman101, Joey-Magnus): refused pools read UBs as submitted (NotRexed#1795 per-pool, live-smoked at 1.26M copies fault-free); verdicts decide on present-to-present frame time instead of GPU-only time (the mirror's CPU and upload-buffer cost is what the frame pays); the policy runs trial-less under RX_VK_PARALLEL and its fast-path counters are parallel-safe; no trials on iGPUs and a 3-abort cap; the skip list carries a device+driver header and ignores foreign files; the test driver uses {cxx}. Follow-up fix: the drift check counted served volume, so a working mirror's read collapse voided 40+ trials a run and trials never converged; binds now count once at the serving path and the drift rule compares the scene's pool set, with a three-no-verdict cap. The set rule still voided every trial in a streaming scene, so anchors now match by guest range (a recycled pool is the same anchor), anchor at 4x the floor, void only when a substantial fraction of the scene moves, and the candidate floor rose to 256 MB of reads a window (the verdict floor is unreachable below it - a trial there is churn by construction). Rebased onto main's env_on switch rule (NotRexed#2042) and the split-submission fence work (NotRexed#2419); the trials' functions sit outside the write-back observation's compile-span check (NotRexed#2131) and the GCN mirror-less default (NotRexed#2343) composes unchanged (on GCN the switch runs trial-less direct plus the UB snapshot). After the presenter-thread refactor (NotRexed#2325) the present-to-present tick lives in present_finish, which every made present passes exactly once in either threading mode, with a headless twin so offscreen runs stay measurable. Co-authored-by: GLM-5.3-Flash <glm-5.3-flash@opencode.noreply.github.com>
…the state files The ledger records the sync at upstream's 3e32949 (pull request 3), upstream's own CPU profile (NotRexed#2424) and the open pull requests found since: NotRexed#2470 (sound and the physics step above 60), NotRexed#2325 (the frame's chain of waits), NotRexed#2433 (fast float regions), NotRexed#2487 (wake-ups on Linux). correctness.json takes the water ripples as fixed upstream (NotRexed#2409), the Deku Tree platform's cause as reported in NotRexed#2470, and a new entry for the sound loss. Co-Authored-By: Claude Fable 5.2 <noreply@anthropic.com>
…the state files The ledger records the sync at upstream's 3e32949 (pull request 3), upstream's own CPU profile (NotRexed#2424) and the open pull requests found since: NotRexed#2470 (sound and the physics step above 60), NotRexed#2325 (the frame's chain of waits), NotRexed#2433 (fast float regions), NotRexed#2487 (wake-ups on Linux). correctness.json takes the water ripples as fixed upstream (NotRexed#2409), the Deku Tree platform's cause as reported in NotRexed#2470, and a new entry for the sound loss. Co-Authored-By: Claude Fable 5.2 <noreply@anthropic.com>
…the state files The ledger records the sync at upstream's 3e32949 (pull request 3), upstream's own CPU profile (NotRexed#2424) and the open pull requests found since: NotRexed#2470 (sound and the physics step above 60), NotRexed#2325 (the frame's chain of waits), NotRexed#2433 (fast float regions), NotRexed#2487 (wake-ups on Linux). correctness.json takes the water ripples as fixed upstream (NotRexed#2409), the Deku Tree platform's cause as reported in NotRexed#2470, and a new entry for the sound loss. Co-Authored-By: Claude Fable 5.2 <noreply@anthropic.com>
It was guesswork where a frame's time goes once it is spread over several threads. The samplers say what each thread runs, but not which of them the frame was waiting for. This PR adds a switch that records the game threads' waits and wake-ups, and a script that follows each frame back from its present along them. It also moves the biggest single wait the walk found, the present's wait for the GPU, off the game's thread: a presenter thread with a queue of its own, on by default.
What changes
HOS_CHAIN=<file>(diagnostic, off by default). While<file>.goexists, it records:Each record has the time, the thread, the object's address and the guest caller. The records go to
<file>when<file>.gois removed (about 2 million records at most, 64 MB). When the switch is off, the cost is one load and one branch per blocking wait and per signal.scripts/chain.py <file> [<HOS_SAMPLE_ALL file>]walks each frame back from its present: the thread that ran, the wait that stopped it, the signal that ended that wait and the thread that sent it, and so on back to the frame before. It prints:HOS_SAMPLE_ALLfile of the same run, the functions on the path. In aHOS_CHAINrun every sample carries its own time (# atlines, which the other scripts skip).A wait for a virtual core counts as the waiting thread's own time (contention, not a dependency).
scripts/crit.pyno longer counts a sample whose leaf is outside Hookshot as blocked. libc's copies and the driver's own work are CPU time; a sample is blocked only under a known wait (prof.WAIT_FRAMES). In Kokiri this moves the presentation thread from "running 45%" to "running 70%".A presenter thread, on by default (
RX_VK_PRESENT_THREAD=0turns it off):present_imagehands the present to a thread of its own. That thread waits for the copy's fence, then callsvkQueuePresentKHRon a queue of its own, and the game's thread goes on at once.VK_SHARING_MODE_CONCURRENT). The presenter never takes the replay's queue lock. A device with no second queue that can present to the window (checked on each new surface) keeps the presents on the game's thread, as before.VK_KHR_present_id+VK_KHR_present_wait, the hand-off waits until that present is shown, and the log says how long after the present that was. Under mailbox and immediate it does not wait for the present to be shown: that would cap Uncapped (feat(menu): an Uncapped choice for the Game frame rate cap #2122) at the refresh rate, since a replaced mailbox present counts as shown only at the next refresh. There the depth is the present call's return, as on the game's thread before.The FPS counter's Breakdown (feat(menu): FPS counter levels: frame time, a graph and where the time goes #2181) counted the present's whole wait as Pacing. On NVIDIA's driver on Linux most of it is the GPU finishing the frame's copy (below), so it now goes to GPU wait when the present waited for it: the copy was not done when
vkQueuePresentKHRwas called and was done when it returned (two zero-timeout fence reads, only while the Breakdown shows; nothing waits). Any other present stays Pacing (vsync). With the presenter thread, the game thread's wait for it is split where the presenter's wait for the copy ended.Tests:
tests/test_chain.py;tests/test_present_thread.pywithtests/presenter_queue_test.cpp(the queue choice on NVIDIA's and RADV's family layouts, a taken compute queue, a lone queue);test_fps_stats.pyfor the Breakdown's split. Stubs forHOS_CHAINin the host fixtures that cuthost/code (test_multiwait_wake,test_present_trace,test_short_sleep_timer,test_vcore_escape), andtest_present_semaphorescutspresent_outup topresent_finish.Docs:
docs/development.mdlists both switches, anddocs/design.mdhas the findings below.What the walk found
Setup: RTX 3090, Ryzen 9 7900X, Linux, NVIDIA 620.70, Kokiri Forest standing, 2560x1440, about 1250 draws, recording on. Every frame is one loop through two threads:
vkQueuePresentKHR, in the driver)vkQueuePresentKHR. None of these changed it:RX_VK_NO_WRITEBACK=1, a 1280x720 output, a 240 Hz compositor,RX_VK_IMMEDIATE=1.Measured
Same PC and scene, in a private headless sway with a 240 Hz output and
HOS_FPS_MAX=240. Every timed run went through the timing lock (its own CPU complex). Other work on the machine moved single runs by 10-30%, so these are alternating runs.Presenter thread on its own queue (this version), alternating off/on under the timing lock, 25 s each. The PC was short of memory during all of these (other jobs; pages swapped in during every run), so single runs moved by 10-30% and the stalls over 100 ms include paging:
Frames over 100 ms in each 15 s after arriving in Hyrule Field: 3, 23, 14, 4, 7, 4 off; 11, 13, 6, 2, 2, 2 on. No texture upload went over its budget after the teleport in either run. Flashes (
RX_VK_FRAMELOG+scripts/framelog.py): 0 events in 2,119 frames off and 2,882 on over these four runs.The first version presented on the replay's queue under its lock. In Hyrule Field its
vkQueuePresentKHRblocked for up to hundreds of ms after the map loaded, the replay's submits waited on that lock, and the stalls went on past the load (15-60 s after arriving: 21-25 frames over 100 ms per 15 s, against 2-3 off). That is why the presenter now has a queue of its own.On an RX 580 with RADV (a correctness run, not timed: GPU-bound at ~27 fps there), the presenter took compute family 1, queue 0 with
VK_KHR_present_wait. The picture was right with it on and off, through V-Sync On, fullscreen, three resizes and minimize/restore; every swapchain was made again cleanly, with no device lost and no failed present.Presenter thread, first version (it presented on the replay's queue;
HOS_CHAINstretches, 10 s each, alternating off/on/off/on):With the present off the path, the main thread's job waits start to show on it.
Presenter thread, frame times without recording (30 s each, 4 alternating pairs):
Flashes (
RX_VK_FRAMELOG+scripts/framelog.py, same runs): 0 events in 4,945 frames off; 1 event in 6,199 frames on. That one was a single 20x20 block, darker, peak 14: not a frame-wide flash. Four more 30 s runs of this version (Kokiri, off/on/off/on): 0 events in 3,338 frames off and 3,641 on.HOS_CHAINcompiled in but off, against main (30 s each, 3 alternating pairs): median frame 18.4 / 18.7, 19.8 / 17.3 and 21.0 / 19.4 ms (main / this). The replay's submit time is the same within noise (14.0 / 14.0, 14.2 / 13.5, 17.4 / 14.8 ms). No cost shows.Tests: game-free suite 425 passed, 1 failed (
test_linux_saves_move.py, which passes when run on its own; the branch does not touch the saves).Not tested
host/uses, and the Windows sampler writes the# t0_nsline.# attimes are Linux only; on Windowschain.pyfalls back to the samples' millisecond stamps.vkQueuePresentKHRwaits for the GPU there is not known. The presenter thread is on there too (its own queue, the same rules), so it moves whatever the present waits for off the game's thread, or nothing.ParallelDecompThread) are left out of the sample attribution, since samples carry names, not thread ids.Relation to #2172
#2172 (
RX_VK_ASYNC_PRESENT=1) moves the whole native present (frame fence, acquire, blit and present) to a worker. Frames are queued in three owned images, so it adds a copy a frame and up to three frames of buffering. Its measured gain is for the combination with an external layer and a second graphics queue. The presenter thread here moves only the wait for the frame's copy and thevkQueuePresentKHRcall, one present at a time, with no extra images or copies. The two touch the same functions (present_imageandpresent_out). If both land, the presenter thread should stay off for #2172's worker presents (they report the present's result back).Next steps