fix(vk): end the game with the GPU report when submitted work stops finishing #2407

github-sync · 2026-11-11T17:40:10Z

Joey-Magnus commented

2026-11-11 17:40:10 +00:00

(Migrated from github.com)

A GPU hang that the driver never reports as VK_ERROR_DEVICE_LOST freezes the game for good and leaves no clue in the log about which GPU work died. device_lost() (#1275) only runs when a Vulkan call returns that error, and on NVIDIA's Xid 109 none does.

What happened

RTX 4070 Ti, NVIDIA 595.99.02, Linux, sneaking into Hyrule Castle: the kernel logged NVRM: Xid 109 ... name=hookshot ... CTX SWITCH TIMEOUT, and the game froze. The log's last lines are three of

vk: a capture's wait for write-back 467375 timed out (done 467371)

from the main and presentation threads, and nothing after: the timeline stopped 4 short of what had been sent, the 250 ms write-back waits kept coming back VK_TIMEOUT, and the other waits (recording_wait, wait_value) have no limit. No call returned VK_ERROR_DEVICE_LOST, so the checkpoint report never ran.

The change

A watchdog thread, started at the first present next to the existing hang_watch_start(), reads the timeline once a second (vkGetSemaphoreCounterValue only: it needs no external synchronization, unlike the recordings' fences).
A lost device it reads goes to device_lost().
Work already sent to the queue (note_timeline_sent, at the two submissions that signal the timeline) that finishes nothing for RX_VK_GPU_HANG_SEC seconds (default 30) is logged as a hang and goes to device_lost(): the checkpoint report, the log flushed, exit code 3.
RX_VK_GPU_HANG_SEC=0 only logs the stall (at 10 s, then every 30 s) and lets the game wait.
Only submissions actually sent count. A value held back on the CPU side (the case #2222 bounds) is not taken as a GPU hang.

Trade-off

The present's submission waits for its swapchain image, and a window the system stops presenting could in principle hold the queue as long. That is why the limit is 30 s, not the few seconds a real GPU timeout takes, and why =0 exists. I have not seen it happen.

Tests

tests/test_gpu_hang_watch.py cuts gpu_hang_watch_start() into a fixture with the timeline and device_lost() stubbed. A stuck timeline ends the process after the limit, a lost device ends it at once, and a moving timeline or =0 never does. It also checks that both timeline-signalling submissions are counted and that the watch starts at the first present.
tests/draw_stream_visibility_test.cpp and tests/fsr_image_retirement_test.cpp get a note_timeline_sent stub, since they compile the submit functions.
python -I -B tests/run_all.py on Linux: 381 passed, 15 skipped, 1 failed (test_make_game_cache.py, which fails the same way on main without this change).
vk_replay.cpp built with nx2/build.py's Vulkan flags.
Not yet run in the game. The hang is rare, so the path will be confirmed when it recurs.

Complements #2117, which makes the report itself richer when there are no checkpoints. Refs #1000.

A GPU hang that the driver never reports as `VK_ERROR_DEVICE_LOST` freezes the game for good and leaves no clue in the log about which GPU work died. `device_lost()` (#1275) only runs when a Vulkan call returns that error, and on NVIDIA's Xid 109 none does. **What happened** RTX 4070 Ti, NVIDIA 595.99.02, Linux, sneaking into Hyrule Castle: the kernel logged `NVRM: Xid 109 ... name=hookshot ... CTX SWITCH TIMEOUT`, and the game froze. The log's last lines are three of ``` vk: a capture's wait for write-back 467375 timed out (done 467371) ``` from the main and presentation threads, and nothing after: the timeline stopped 4 short of what had been sent, the 250 ms write-back waits kept coming back `VK_TIMEOUT`, and the other waits (`recording_wait`, `wait_value`) have no limit. No call returned `VK_ERROR_DEVICE_LOST`, so the checkpoint report never ran. **The change** - A watchdog thread, started at the first present next to the existing `hang_watch_start()`, reads the timeline once a second (`vkGetSemaphoreCounterValue` only: it needs no external synchronization, unlike the recordings' fences). - A lost device it reads goes to `device_lost()`. - Work already sent to the queue (`note_timeline_sent`, at the two submissions that signal the timeline) that finishes nothing for `RX_VK_GPU_HANG_SEC` seconds (default 30) is logged as a hang and goes to `device_lost()`: the checkpoint report, the log flushed, exit code 3. - `RX_VK_GPU_HANG_SEC=0` only logs the stall (at 10 s, then every 30 s) and lets the game wait. - Only submissions actually sent count. A value held back on the CPU side (the case #2222 bounds) is not taken as a GPU hang. **Trade-off** The present's submission waits for its swapchain image, and a window the system stops presenting could in principle hold the queue as long. That is why the limit is 30 s, not the few seconds a real GPU timeout takes, and why `=0` exists. I have not seen it happen. **Tests** - `tests/test_gpu_hang_watch.py` cuts `gpu_hang_watch_start()` into a fixture with the timeline and `device_lost()` stubbed. A stuck timeline ends the process after the limit, a lost device ends it at once, and a moving timeline or `=0` never does. It also checks that both timeline-signalling submissions are counted and that the watch starts at the first present. - `tests/draw_stream_visibility_test.cpp` and `tests/fsr_image_retirement_test.cpp` get a `note_timeline_sent` stub, since they compile the submit functions. - `python -I -B tests/run_all.py` on Linux: 381 passed, 15 skipped, 1 failed (`test_make_game_cache.py`, which fails the same way on `main` without this change). - `vk_replay.cpp` built with `nx2/build.py`'s Vulkan flags. - Not yet run in the game. The hang is rare, so the path will be confirmed when it recurs. Complements #2117, which makes the report itself richer when there are no checkpoints. Refs #1000.

hckrman101 (Migrated from github.com) approved these changes

2026-11-11 18:26:57 +00:00

hckrman101 (Migrated from github.com) left a comment

Looks good to me. A hang the driver never reports as lost is exactly the case device_lost() can't see, and reading the timeline from a side thread is the cheapest thing that can.

I went through the false-positive cases:

Slow GPU / long frames: the counter resets on any progress, so it needs a single submission stuck for 30 s, and on Windows TDR would report the device lost long before that.
Shader compile stalls (#2195), a paused game, batched submits on RADV: all of these hold work back on the CPU. timeline_sent only moves after vkQueueSubmit2 succeeds (and only on a flush when batching), so done >= sent and the counter never runs. The same goes for a value held back as in #2222.
Minimised or hidden window: the only GPU-side wait is the present's f.acquired. On Linux the acquire is already bounded at 100 ms on the CPU (the "window is not shown" path), so nothing gets queued behind an image that never comes back. On Windows the acquire returns before the semaphore matters. The 30 s margin plus =0 covers whatever is left.
Suspend/resume, debugger: the watch counts its own 1 s ticks, not wall time, so a stopped process or a suspended machine doesn't add up.

The report path on a hung device: device_lost() → call_once(checkpoints_report) → replay_fatal → _Exit(3). It does no fence or semaphore waits, takes only watch_mu briefly, and if the main thread hits a real DEVICE_LOST at the same moment, call_once covers it. Nothing tears down the device at exit either, so the detached thread can't race a destroy. Parity is fine: plain std::thread/getenv, and the llvm-mingw back end builds.

Notes (none blocking):

With the device hung but not lost, vkGetQueueCheckpointDataNV is technically outside the spec (it requires the device to be in the lost state, and validation will flag it). On NVIDIA it should still return the last checkpoints, which is the point, but it hasn't been run in the game yet, so it's worth confirming the report actually has markers in it when this recurs. Related: when #2117 lands, its automatic vkGetDeviceFaultInfoEXT will run on this path on a device that isn't lost. Whichever PR goes in second should check that the call returns there. The existing comment in checkpoints_report already says it may not return on NVIDIA, and the queued log is only flushed in replay_fatal, after it.
The test takes ~15 s (three 5 s fixture runs). It's fine, but a shorter sleep in the fixture's main would make it cheaper.

CI: the only failure is test_native_astc_texture_count.py on Windows (a scanf deprecation in its fixture). It fails the same way on main and isn't touched here. test_gpu_hang_watch.py passes on both Linux and Windows.

Looks good to me. A hang the driver never reports as lost is exactly the case `device_lost()` can't see, and reading the timeline from a side thread is the cheapest thing that can. I went through the false-positive cases: - **Slow GPU / long frames:** the counter resets on any progress, so it needs a single submission stuck for 30 s, and on Windows TDR would report the device lost long before that. - **Shader compile stalls (#2195), a paused game, batched submits on RADV:** all of these hold work back on the CPU. `timeline_sent` only moves after `vkQueueSubmit2` succeeds (and only on a flush when batching), so `done >= sent` and the counter never runs. The same goes for a value held back as in #2222. - **Minimised or hidden window:** the only GPU-side wait is the present's `f.acquired`. On Linux the acquire is already bounded at 100 ms on the CPU (the "window is not shown" path), so nothing gets queued behind an image that never comes back. On Windows the acquire returns before the semaphore matters. The 30 s margin plus `=0` covers whatever is left. - **Suspend/resume, debugger:** the watch counts its own 1 s ticks, not wall time, so a stopped process or a suspended machine doesn't add up. The report path on a hung device: `device_lost()` → `call_once(checkpoints_report)` → `replay_fatal` → `_Exit(3)`. It does no fence or semaphore waits, takes only `watch_mu` briefly, and if the main thread hits a real DEVICE_LOST at the same moment, `call_once` covers it. Nothing tears down the device at exit either, so the detached thread can't race a destroy. Parity is fine: plain `std::thread`/`getenv`, and the llvm-mingw back end builds. Notes (none blocking): - With the device hung but not lost, `vkGetQueueCheckpointDataNV` is technically outside the spec (it requires the device to be in the lost state, and validation will flag it). On NVIDIA it should still return the last checkpoints, which is the point, but it hasn't been run in the game yet, so it's worth confirming the report actually has markers in it when this recurs. Related: when #2117 lands, its automatic `vkGetDeviceFaultInfoEXT` will run on this path on a device that isn't lost. Whichever PR goes in second should check that the call returns there. The existing comment in `checkpoints_report` already says it may not return on NVIDIA, and the queued log is only flushed in `replay_fatal`, after it. - The test takes ~15 s (three 5 s fixture runs). It's fine, but a shorter sleep in the fixture's `main` would make it cheaper. CI: the only failure is `test_native_astc_texture_count.py` on Windows (a `scanf` deprecation in its fixture). It fails the same way on main and isn't touched here. `test_gpu_hang_watch.py` passes on both Linux and Windows.

gpu/vk/vk_replay.cpp

					
				@ -2630,3 +2638,2 @@

				    std::call_once(once, checkpoints_report);

				    replay_fatal("the GPU device was lost (VK_ERROR_DEVICE_LOST): the driver stopped or reset the GPU, and nothing sent "

				                 "to it runs any more (on Linux, dmesg or journalctl -k around this time names the reset)");

				    replay_fatal(why ? why

Nit: this ends in replay_fatal("the GPU device was lost (VK_ERROR_DEVICE_LOST)..."), so the stderr/FATAL line claims the driver returned DEVICE_LOST when here it didn't. The log line above it says so, but stderr (and anything that shows only the FATAL line) won't. A device_lost(const char* why = ...) overload or a flag would keep the two apart.

Nit: this ends in `replay_fatal("the GPU device was lost (VK_ERROR_DEVICE_LOST)...")`, so the stderr/FATAL line claims the driver returned DEVICE_LOST when here it didn't. The log line above it says so, but stderr (and anything that shows only the FATAL line) won't. A `device_lost(const char* why = ...)` overload or a flag would keep the two apart.

gpu/vk/vk_replay.cpp

Nit: atoi turns a typo (RX_VK_GPU_HANG_SEC=30s works, =abc doesn't) into 0, which silently switches the exit off. Logging the value it settled on once at start would make that visible.

Nit: `atoi` turns a typo (`RX_VK_GPU_HANG_SEC=30s` works, `=abc` doesn't) into 0, which silently switches the exit off. Logging the value it settled on once at start would make that visible.

gpu/vk/vk_replay.cpp

Nit: hang_watch_start() names its thread (SetThreadDescription(..., L"mkw_vk hang watch")). Doing the same here would make this one easy to tell apart in a hang dump.

Nit: `hang_watch_start()` names its thread (`SetThreadDescription(..., L"mkw_vk hang watch")`). Doing the same here would make this one easy to tell apart in a hang dump.

Joey-Magnus (Migrated from github.com) reviewed

2026-11-11 18:38:10 +00:00

gpu/vk/vk_replay.cpp

Done in 0361f50a: the limit it settled on is logged at start, and with 0 it says the stall is only logged and shows the raw value it read, so =abc is visible.

Done in 0361f50a: the limit it settled on is logged at start, and with 0 it says the stall is only logged and shows the raw value it read, so `=abc` is visible.

Joey-Magnus (Migrated from github.com) reviewed

2026-11-11 18:38:11 +00:00

gpu/vk/vk_replay.cpp

Done in 0361f50a: named mkw_vk gpu hang watch.

Done in 0361f50a: named `mkw_vk gpu hang watch`.

Joey-Magnus (Migrated from github.com) reviewed

2026-11-11 18:38:13 +00:00

gpu/vk/vk_replay.cpp

					
				@ -2630,3 +2638,2 @@

				    std::call_once(once, checkpoints_report);

				    replay_fatal("the GPU device was lost (VK_ERROR_DEVICE_LOST): the driver stopped or reset the GPU, and nothing sent "

				                 "to it runs any more (on Linux, dmesg or journalctl -k around this time names the reset)");

				    replay_fatal(why ? why

Done in 0361f50a: device_lost(const char* why = nullptr). The watch passes "the GPU hung: no submission finished in N s, and the driver never reported the device lost ...", and every other site keeps the VK_ERROR_DEVICE_LOST line. Both still share the one call_once report. test_device_lost_exit.py cuts the new signature, and test_gpu_hang_watch.py checks which line each path gives.

Done in 0361f50a: `device_lost(const char* why = nullptr)`. The watch passes "the GPU hung: no submission finished in N s, and the driver never reported the device lost ...", and every other site keeps the VK_ERROR_DEVICE_LOST line. Both still share the one `call_once` report. `test_device_lost_exit.py` cuts the new signature, and `test_gpu_hang_watch.py` checks which line each path gives.

Joey-Magnus commented

2026-11-11 18:38:20 +00:00

(Migrated from github.com)

Thanks for going through the false-positive cases. Besides the three nits, the fixture now sleeps 3.5 s (the test takes about 11 s, was 15).

On the notes: I'll confirm the report has markers in it when the hang recurs. If #2117 lands first, I'll check here that vkGetDeviceFaultInfoEXT returns on a hung but not lost device before its automatic call can run on this path.

tests/run_all.py on Linux: 382 passed, 0 failed.

Thanks for going through the false-positive cases. Besides the three nits, the fixture now sleeps 3.5 s (the test takes about 11 s, was 15). On the notes: I'll confirm the report has markers in it when the hang recurs. If #2117 lands first, I'll check here that `vkGetDeviceFaultInfoEXT` returns on a hung but not lost device before its automatic call can run on this path. `tests/run_all.py` on Linux: 382 passed, 0 failed.

hckrman101 (Migrated from github.com) approved these changes

2026-11-11 18:47:42 +00:00

hckrman101 (Migrated from github.com) left a comment

Re-checked at 0361f50. All three nits are done:

The FATAL line now says what happened: device_lost(why) gets "the GPU hung ... the driver never reported the device lost" from the watch, every other caller keeps the VK_ERROR_DEVICE_LOST text, and both still go through the one call_once report. The test checks which line each path prints.
The limit is logged at start, and with 0 the raw value is shown, so =abc no longer switches the exit off unnoticed.
The thread is named mkw_vk gpu hang watch.

The test is down to about 11 s, which is fine.

The two notes stay notes. You plan to confirm the checkpoint markers when the hang happens again, and to check vkGetDeviceFaultInfoEXT on this path if #2117 lands first. That covers it.

CI: everything passes except Windows part 2/2, where the only failure is test_native_astc_texture_count.py (scanf deprecated under -Werror). That fails on main too and is fixed by #2397, so it isn't from this PR. No conflicts with main.

Good to merge from my side.

Re-checked at 0361f50. All three nits are done: - The FATAL line now says what happened: `device_lost(why)` gets "the GPU hung ... the driver never reported the device lost" from the watch, every other caller keeps the VK_ERROR_DEVICE_LOST text, and both still go through the one `call_once` report. The test checks which line each path prints. - The limit is logged at start, and with 0 the raw value is shown, so `=abc` no longer switches the exit off unnoticed. - The thread is named `mkw_vk gpu hang watch`. The test is down to about 11 s, which is fine. The two notes stay notes. You plan to confirm the checkpoint markers when the hang happens again, and to check `vkGetDeviceFaultInfoEXT` on this path if #2117 lands first. That covers it. CI: everything passes except Windows part 2/2, where the only failure is `test_native_astc_texture_count.py` (`scanf` deprecated under -Werror). That fails on main too and is fixed by #2397, so it isn't from this PR. No conflicts with main. Good to merge from my side.

~~github-sync referenced this pull request 2026-11-12 06:22:54 +00:00~~

chore(main): release 2.2.0-rc.1 #2071

github-sync referenced this pull request

2026-11-12 13:39:30 +00:00

Crash after using Boss Warp after defeating Volvagia in the Fire Temple #2589

Commenting is not possible because the repository is archived.

No reviewers

hckrman101