fix(vk): with the render thread off, a frame is no longer drawn before the data the game writes after its submit (Link dark for a frame) #769
No reviewers
Labels
No labels
area/accessibility
area/audio
area/input
area/install
area/menu
area/renderer
area/saves
area/upscaling
beanstalk: approved @ 1697603
beanstalk: approved @ 2c5a62e
beanstalk: approved @ 4fd82b7
beanstalk: approved @ 64d6d09
beanstalk: approved @ 6f91fae
beanstalk: approved @ 70a78f9
beanstalk: approved @ 8d361dc
beanstalk: approved @ 9d8356e
beanstalk: approved @ abf2227
beanstalk: approved @ d82f202
beanstalk: approved @ e5f1e40
beanstalk: approved @ ee8ab5f
ci: approved
good first issue
gpu/amd
gpu/igpu
gpu/intel
gpu/nvidia
help wanted
kind
bug
kind
chore
kind
docs
kind
feature
kind
performance
kind
question
needs measurements
platform/linux
platform/macos
platform/steam-deck
platform/windows
preview
priority
critical
priority
high
priority
low
regression
status
blocked
status
confirmed
status
duplicate
status
invalid
status
needs-info
status
wontfix
testing wanted
ci: approved
No milestone
No project
No assignees
2 participants
Notifications
Due date
No due date set.
Dependencies
No dependencies set
Reference
MagicBeanDev/Longshot!769
Loading…
Reference in a new issue
No description provided.
Delete branch "GummiNaomi/Longshot:fix/met-wait-capture-pr"
Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?
Type: fix · Risk: medium · Tested on: Windows 11, RTX 4070 SUPER (NVIDIA 617.42) · Needs: Linux; AMD; Intel; a PC under 12 logical processors
Why
With Threaded rendering off (what Auto picks under 12 logical processors, and the Off setting), the lit scene and Link go
dark for single frames: 21 to 40 times in a 140 s run at Castle Town's gate here, uncapped. It is the black flash of #366 on
the path the render thread does not cover. The render thread itself shows none in the same runs.
It is still there on nightly 178 (
e090cc48) and on maina00c485c, which answers the question on #366 whether a nightlyfrom 164 on still shows it: with Threaded rendering on, no; with it off, yes.
See #366. Not the same cause as #526 (the late pages' fix writing older words over newer ones): this one is a capture taken
too early, or not at all. The two were not run together. #759 changes the same two files and will need a rebase by
whichever of the two goes in second.
How to reproduce
Seen on: Windows 11 Pro 26200, RTX 4070 SUPER 12 GB, NVIDIA 617.42
Settings and switches:
RX_VK_ASYNC=0(or Threaded rendering: Off), frame rate cap Uncapped; 2560x1440, DLAASteps: Castle Town's south gate: walk out to the drawbridge and back through the gate a few times
Expected: Link and the ground lit in every frame
Actual: on main, Link and the lit scene are black for one frame, about once every 600 frames; more right after a loading screen
What changed
Two causes, both of the same kind: the game writes part of a frame's data (the scene buffer's light grid among it) after
it has submitted the frame's work, then signals the event that work waits for, and the replay went ahead without that data.
gpu/vk/vk_replay.cpp,NOP_WAIT_EVENT,cpu_signal_uncaptured,resume_queue;gpu/vk/vk_memory.cppcapture_make,memory_captures_begun). A queue stopped at the wait gets a capture when it goes on.A wait the replay found met went on with its submit's capture, and when the signal had come after that capture was begun
the frame was lit with an empty light grid. Such a wait now stops there once and goes on through
resume_queue's capture.Whether the signal came after: each capture is counted as begun before it collects the written pages, and
event_signal_queuednotes that count on the signalling thread. A signal an older capture already follows stops nothing.gpu/vk/hold_gpu.h,sync_watchandwait()ingpu/vk/vk_replay.cpp). The game's main thread waits once a frame for the GPU to finish the frame before, and makes itssignal after that wait. When the GPU took over
RX_VK_HOLD_MS(50) for that frame, as after a load, the watch threadmade the stopped queues go past their waits and they drew without the data. They are now held on while such a wait is
under way and for
RX_VK_HOLD_MSafter it, 1000 ms at most.Reviewers: start with the comment above
ev_cpu_capturesinvk_replay.cpp, thenhold_gpu.h.Measurements
Verdict: dark frames on the submitting thread go from 126 in four runs (median 32.5 a run) to 0 in four runs; no cost
in frame rate or in long frames that these runs can show.
Hardware: Windows 11 Pro 26200, RTX 4070 SUPER 12 GB, NVIDIA 617.42, Ryzen 9 9950X3D (16 cores, SMT off), 32 GB
Scene: Castle Town's south gate, out to the drawbridge and back several times (each run crosses a few loading screens), day,
then night at 90 s; 2560x1440, DLAA, no frame generation, uncapped
Method: 140 s scripted runs, three sides in turn, four rounds. A dark frame is counted by a local counter (not in this PR):
a frame in which the main scene buffer (the 0x3500-byte
c3) had an empty light grid word at every one of its bindings;single frames or pairs only. Frame rate: mean over the run from
HOS_PRESENT_TRACE, loads included. Hold timeouts: the50 mscount of the log'squeues ordered by their eventsline.How to reproduce: save set "First Step into Hyrule Town", the route above, the switches in the column headers.
Builds: this PR's source (the working tree that became
8d516bf5) plus the local counter. Rounds 1 to 3 on maine090cc48,round 4 on main
a00c485c. The commit itself is on mainaa95d35f(#761 came in between and also changesvk_replay.cpp):that build was run once on the same route to see it start and play, without the counter, so it has no dark-frame count.
Baseline: the same build with both changes switched off, because the count needs the local counter in the build; main
without this PR was run the same way on
6c9edffe(six rounds, below).RX_VK_ASYNC=0 RX_VK_MET_WAIT_CAPTURE=0 RX_VK_HOLD_GPU_WAIT=0: this PR @8d516bf5RX_VK_ASYNC=0: this PR @8d516bf5RX_VK_ASYNC=1(the render thread): this PR @8d516bf5Round 4 is on a newer main than rounds 1 to 3, so compare its three sides with each other, not with the earlier rounds
(the render thread's 197.7 fps is that round's; why it is higher than rounds 1 to 3 was not looked into).
Each change alone, on main
6c9edffeplus the changes (the same route and method):The 13 left with the capture alone were the hold timeouts, run by run.
Round 1's log lines, before and after:
Flags and settings
Three switches, all for testing; no menu row, no ini key.
RX_VK_MET_WAIT_CAPTURE=0RX_VK_HOLD_GPU_WAIT=0RX_VK_HOLD_MSwhoever waitsRX_VK_HOLD_GPU_MS=<ms>All three are in
docs/development.md.Testing
Tested:
Windows 11, RTX 4070 SUPER (617.42): the runs above; 11 more runs of the capture alone and 16 of the hold on
6c9edffe.python -I -B tests/run_all.pyon this PR's commit: 323 passed, 80 failed, 192 skipped (no gcc or g++ on this PC). On untouched mainaa95d35f: 321 passed, 80 failed, 192 skipped. The 80 are the same 80 on both (several are link errors of this PC's clang; they were not looked into one by one); the two more that pass here are this PR's new tests.The 80 that fail on both
test_alt_enter,test_appimage_player_build,test_audio_deadline,test_audio_output_errors,test_audio_wave_buffer_release,test_bake_portability,test_bc_levels,test_bind_memo,test_capture_copy_helpers,test_collect_wide,test_cpm_discovery,test_crash_dialog,test_dlss_actor,test_dlss_checks,test_dlss_math,test_draw_binds,test_env_file,test_env_on,test_fps_overlay_order,test_fps_rate,test_fps_stats,test_frame_whole,test_framegen_auto,test_framegen_gate,test_fsr3_math,test_game_font,test_gpu_choice,test_hd_rumble,test_high_fps_fixes,test_import_span,test_jobs_wait_runs_queued,test_lift_cleanup_error,test_linux_preflight,test_make_game_cache,test_make_game_prepare,test_menu_mouse_scroll,test_mirror_inherit,test_missing_nup,test_movie_upscale_policy,test_oot_jitter,test_options_budget_once,test_pass_hazard,test_pool_span,test_precompile_compute_guard,test_present_ahead,test_present_thread,test_prof_clock,test_program_cache_cleanup,test_prompt_auto_face,test_psychov35_default,test_psychov35_dlss,test_push_state,test_quick_pipelines,test_readback_late,test_report_words,test_rumble_mapping,test_rumble_menu,test_rumble_refresh,test_same_bind,test_same_draw,test_same_dyn,test_seed_reader,test_shader_module_guard,test_skip_code,test_status_line,test_submitted_page,test_table_track,test_task_mesh_fallback_devices,test_tested_configurations,test_tex_spans_once_a_present,test_texture_layout_sizes,test_ub_gap,test_upscale_independent,test_upscale_label,test_utf8_paths,test_vertex_bind,test_vk_occlusion_queries,test_vk_pgo,test_walk_key,test_wb_pagesWith this PC's clang wrappers in place of g++, the 137 checks that read the changed files (on main
a00c485c): 125 pass; 12 fail, and the same 12 fail the same way on untouched main:test_audio_volume,test_crash_dialog,test_crash_record,test_oot_fov,test_oot_state_tap,test_present_aspect_vulkan,test_present_thread,test_readback_late,test_readback_wait_bounded,test_text_size,test_vk_pgo,test_walk_key.After the rebase onto
aa95d35f: the two new tests and the eight checks nearest #761's change (test_vk_occlusion_queries,test_recorder_sync,test_draw_stream_visibility,test_fsr_image_retirement,test_flush_nothing_held,test_recorded_wait_flush,test_late_fix_build,test_readback_part) pass; the build links and plays the route.New:
tests/test_met_wait_capture.py(source),tests/test_hold_gpu.pywithtests/hold_gpu_test.cpp(the rule compiled and run). Both fail on main (the code they read is not there).tests/test_tested_configurations.py: 24 of 25 pass here; the one failure is its CLI pipe test's line endings on Windows, which reads none of this PR's files.scripts/check_guide_screenshots.py --review-sourcesalready asks for a review on mainaa95d35f(14 files,gpu/vk/vk_internal.hamong them), and asks for the same 14 with this PR. This PR adds one declaration to that header and changes no menu.Not tested:
RX_VK_ASYNC=0on a 16-core PC.frames by eye on an older base (150 recorded frames, the block empty in exactly the 3 dark ones), not on this one.
Must be tested:
50 mscount at 0 (Test Farm: the gate withRX_VK_ASYNC=0).50 mscount at 0 (by hand: watch Link each time the gate's loading screen ends).Risks
What could break: a queue held longer than before at a long GPU frame: the frame that would have been dark comes up to
RX_VK_HOLD_GPU_MSlater instead (in the runs: 14 holds, none reached the bound). A game thread that waits for the GPU forever would hold stopped queues for 1000 ms each time instead of 50. The met-wait stop adds 400 to 750 captures a run.
Turning it off:
RX_VK_MET_WAIT_CAPTURE=0,RX_VK_HOLD_GPU_WAIT=0; or revert the commit.Compatibility: Nothing changes: no cache, save, option or ABI is touched.
Issues
See #366
Checklist
Everyone
type(scope): description) of the status line's type.main.python -I -B tests/run_all.pypasses (any failure that also fails onmainis named). (80 fail here and the same 80 onmain, named under Testing)third_party/untouched (a new folder with aPROVENANCE.mdinstead).When it applies
Assisted-by:/Co-Authored-By:trailers.docs/tested/for each new measured run (format indocs/tested-configurations.md): twelve files,2026-11-15-met-wait-hold-gumminaomi-{ta,sa,sb}{1,2,3,4}.md.mainand passing here.🤖 Generated with Claude Code
WIP: fix(vk): with the render thread off, a frame is no longer drawn before the data the game writes after its submit (Link dark for a frame)to fix(vk): with the render thread off, a frame is no longer drawn before the data the game writes after its submit (Link dark for a frame)First review, on code only (no tests run here). The fix looks correct and I found nothing that blocks it. I'm posting a comment rather than an approval for one reason: the hardware runs the PR lists under Must be tested (Linux; AMD; Intel or a PC under 12 logical processors) haven't happened yet, and I found no test request for them.
What I checked
schedule()that every stopping caller runs next (submit_job,drain,sync_watch) resumes it straight away throughresume_queue. That takesmemory_capture_now, andmet_resumed_atlets the wait through on the resumed run, so each wait stops at most once. A later wait in the same resumed run can only stop again if a new signal came after that capture.ev_cpu_mu. So a capture that began before the signal is never treated as covering it, which errs on the safe side. Captures on the submitting thread are taken undersync_order_muand their memory work is applied in submit order, so "begun after the signal" does mean the data is in the mirrors before the stopped work replays.GpuWaitercounts a thread only in theminebranch, where none of the queue's work up tofis stopped. The Vulkan work that wait needs therefore cannot depend on the held queues, andwait_rec_seqflushes it first, so there is no cycle. Three things bound the hold:RX_VK_HOLD_GPU_MS(1000 ms, never underhold_ms) counted from when the queues stopped; presents and releases, whose drains are unchanged; and a wait that needs stopped work, whichwait()still forces afterRX_VK_WAIT_HOLD_US. A poll (timeout of 1 ms or less) is not counted. The remaining cost is the one Risks names: a thread that only polls for stopped work, while another thread waits on the GPU, now waits up to 1000 ms instead of 50.met_wait_capture_on()is false whenasync_on().ev_cpu_capturesis written only in the submitting thread's branch ofevent_signal_queued.GpuWaitersits inside the!async_on()block, andsync_watchonly runs in sync mode. Theresume_capturechange is a straight move of the same static intoresume_capture_on(). Settingmet_resumed_aton the render thread is harmless.ev_cpu_mulookup. The measured fps (median 124.2 before, 130.0 after) and the frames over 50 ms show no cost. That is within noise, as the PR says.Two non-blocking nits are inline: the met-wait stop is still on with
RX_VK_CAPTURE=0, and the "made to go at 1000 ms" count also includes holds that ended normally.Rebase: main has moved since
aa95d35f(#526, #552, #489 and others touchvk_memory.cpp,vk_replay.cppandvk_internal.h). The PR still rebases onto mainced37d40without conflicts and Forgejo reports it mergeable, so I didn't push anything. Note that #526 is now on main and your runs predate it. The PR already lists "this change together with #526" as not tested, so the runs below should be on a build of this PR on current main.Before merge (a game run): Castle Town's south gate with Threaded rendering Off (
RX_VK_ASYNC=0), going in and out through the gate's loads for a few minutes, expecting no single dark frame and the log's50 mscount at 0. Needed on Linux (any GPU) and on AMD, plus one PC with 4 to 8 cores on Auto, as the PR's Testing section says. Please post a test request for these (scripts/test_requests.py request --pr 769 ...) or ask for thetesting wantedlabel. With those runs in the comments, this can be approved as it is.@ -1000,0 +1016,4 @@static const bool v = !getenv("RX_VK_RESUME_CAPTURE") || atoi(getenv("RX_VK_RESUME_CAPTURE")) != 0;return v;}bool met_wait_capture_on() {Nit, not blocking: this is on with
RX_VK_CAPTURE=0too. Thencapture_makereturns beforecaptures_begunmoves, socpu_signal_uncapturedstays true for every event the CPU has signalled. Every met wait for a CPU event stops, andresume_queuesplits the recording (finish_recording) for amemory_capture_nowthat makes nothing.met_resumed_atstops it from looping, so it only costs time, and only under a debug switch. Fix: exportcapture_on()fromvk_memory.cpp's anonymous namespace (saybool memory_capture_on();invk_internal.h) and add&& memory_capture_on()here, as you already do forresume_capture_on().@ -2804,0 +2870,4 @@}break;case hold_gpu::Choice::Force:if (holding) st_hold_gpu_forced++;Nit, not blocking: this counts every drain that ends a hold. That includes the normal end, where the GPU wait is over,
hold_mshas passed after it, and no signal came, at well under the bound. The log line reports the count as "made to go at 1000 ms", which is only true when the bound was hit. The Risks section reads it that way ("none reached the bound"). For example, a 100 ms GPU wait with no signal in the 50 ms after it is counted here at about 150 ms. Fix:if (holding && ms_since(blocked_since) >= most_ms) st_hold_gpu_forced++;. Or keep two counts (ended after the wait, hit the bound) so the log tells them apart.