From 8df4311723d98330539b4635d8d6f358157be9f7 Mon Sep 17 00:00:00 2001 From: chrg6 Date: Fri, 13 Nov 2026 12:27:05 -0500 Subject: [PATCH] End the run as a lost device when a timeline reads above every value its signals carry, and log the submissions' state with the first occlusion query left unwritten. The RX 6000 reports of 0.9.1 and 0.9.2 ran the completion callbacks of submissions the GPU never finished before any call returned VK_ERROR_DEVICE_LOST, although the completion thread polled the device first. Every value a queue hand-over or a host signal gives the submissions' timeline or the executed timeline is now noted before the signal (vk_sync_hw.h); the completion thread and the wait after a submit end the run when a timeline reads above that note. The first occlusion query found unwritten after its fence logs its submission, the submissions' values, both timelines' readings and the GPU breadcrumbs, and the lost device's report starts with the same line, so the next report shows whether the driver gave a value above the note. Co-Authored-By: Claude Opus 5.5 --- runtime/vk.h | 8 ++++ runtime/vk_device.c | 2 + runtime/vk_exec_xfer.c | 24 ++++++++++-- runtime/vk_sync.c | 88 ++++++++++++++++++++++++++++++++++++++++-- runtime/vk_sync_hw.h | 23 +++++++++++ tests/sync_hw_check.c | 78 +++++++++++++++++++++++++++++++++++++ tests/sync_hw_check.py | 42 ++++++++++++++++++++ 7 files changed, 258 insertions(+), 7 deletions(-) create mode 100644 runtime/vk_sync_hw.h create mode 100644 tests/sync_hw_check.c create mode 100644 tests/sync_hw_check.py diff --git a/runtime/vk.h b/runtime/vk.h index d13fe759..3efa1048 100644 --- a/runtime/vk.h +++ b/runtime/vk.h @@ -129,6 +129,14 @@ static inline int vk_device_is_lost(void) { return __atomic_load_n(&vk_lost, __A // signals), and ends the run through vk_device_lost_check when it is. The completion thread calls it before it runs // callbacks: a lost device may report the submissions' timeline as reached (vk_sync.c completion_main). void vk_device_lost_poll(void); +// vk_sync.c "a lost device in the timelines' values": a host signal of VkCtx.timeline notes its value first; a read of +// the timeline above every value its signals carry ends the run as a lost device (vk_sync_check_timeline, any thread, +// `where` for the fatal line). vk_sync_state_text: the submissions' values and the two timelines' readings, one line +// without a lock; vk_sync_lost_report logs it (vk_device.c device_fault_report). +void vk_sync_signal_note(uint64_t value); +void vk_sync_check_timeline(const char *where); +void vk_sync_state_text(char *o, size_t n); +void vk_sync_lost_report(void); // ---- GPU breadcrumbs (vk_crumbs.c): with VK_AMD_buffer_marker, each crumb has the GPU write its code into host memory // twice, when the command processor reaches it and when all work before it has finished. After a lost device the two diff --git a/runtime/vk_device.c b/runtime/vk_device.c index 0a1c55db..e614ea9b 100644 --- a/runtime/vk_device.c +++ b/runtime/vk_device.c @@ -797,6 +797,7 @@ static const char *fault_address_type(VkDeviceFaultAddressTypeEXT t) { // The report of a lost device: the breadcrumbs, the pass marks, the video memory and the driver's fault information. // Once per process, on the thread that saw the loss first (vk_device_lost_check). static void device_fault_report(void) { + vk_sync_lost_report(); vk_crumbs_report(); vk_pass_marks_report(); vk_mem_lost_report(); @@ -894,6 +895,7 @@ int vk_selftest(void) { vmaDestroyBuffer(c->vma, buf, alloc); VkSemaphoreSignalInfo sig = {.sType = VK_STRUCTURE_TYPE_SEMAPHORE_SIGNAL_INFO, .semaphore = c->timeline, .value = 1}; + vk_sync_signal_note(1); // a host signal of the timeline is noted first (vk_sync.c timeline_beyond) if ((r = vkSignalSemaphore(c->device, &sig)) != VK_SUCCESS) { rt_log("vk selftest: vkSignalSemaphore failed (%d)", (int)r); return 3; } uint64_t value = 1; VkSemaphoreWaitInfo wi = {.sType = VK_STRUCTURE_TYPE_SEMAPHORE_WAIT_INFO, .semaphoreCount = 1, .pSemaphores = &c->timeline, diff --git a/runtime/vk_exec_xfer.c b/runtime/vk_exec_xfer.c index 1dc37041..8fe418cd 100644 --- a/runtime/vk_exec_xfer.c +++ b/runtime/vk_exec_xfer.c @@ -390,7 +390,7 @@ static uint32_t oq_nseg, oq_capseg; static int oq_lost; // replay: the segment missed a draw (ring full) static uint64_t oq_count; // completion thread: samples since the last reset -typedef struct { uint64_t addr, seq; int reset; volatile int32_t lost; uint32_t n, cap; uint32_t *q; } OqSegment; +typedef struct { uint64_t addr, seq, fence; int reset; volatile int32_t lost; uint32_t n, cap; uint32_t *q; } OqSegment; // The replay workers (vk_exec.c "parallel groups") record the draws of one group at once. The front pass replays a // group's samples-passed resets and reports in the order of the stream before the workers record (vk_exec_xfer_front): @@ -682,8 +682,24 @@ static void oq_cb(void *arg) { if (avail) sum += v; else { sum += 1; - vk_device_lost_poll(); // a query its submission never wrote: on a lost device the run ends here - LOG_ONCE("vk: occlusion query slot %u not available after its fence, counted as visible", s->q[i]); + // A query its submission never wrote. Every RX 6000 report of a lost device (0.8.0 to 0.9.2) had this line + // first, its callback run for work the GPU had not finished. A timeline read above every value its signals + // carry, then the device itself, end the run here when it is lost (vk_sync.c "a lost device in the + // timelines' values", vk_device.c vk_device_lost_poll). Otherwise the slot counts as visible and the game + // goes on, as a ring that came round too early would leave it. The first such slot is logged with the + // submissions' state and the GPU's breadcrumbs: whether the GPU had finished this submission, and whether + // the timeline read above what was signalled. + vk_sync_check_timeline("an occlusion query its finished submission never wrote (a timeline value no " + "submission signals)"); + vk_device_lost_poll(); + static volatile char logged; + if (!__atomic_exchange_n(&logged, 1, __ATOMIC_RELAXED)) { + char st[512]; + vk_sync_state_text(st, sizeof st); + rt_log("vk: occlusion query slot %u of submission %llu not available after its fence, counted as visible; " + "%s", s->q[i], (unsigned long long)s->fence, st); + vk_crumbs_report(); + } } } if (s->n && ++OQB.segs >= 12000) { @@ -711,7 +727,7 @@ static void oq_segment(VkExec *ex, uint64_t addr, int reset) { OqSegment *s = calloc(1, sizeof *s); if (!s || (oq_nseg && !(s->q = malloc(sizeof *s->q * oq_nseg)))) rt_fatal("vk: out of memory"); s->cap = oq_nseg; - s->addr = addr, s->seq = report_seq, s->reset = reset, s->lost = oq_lost, s->n = oq_nseg; + s->addr = addr, s->seq = report_seq, s->fence = ex->fence, s->reset = reset, s->lost = oq_lost, s->n = oq_nseg; if (addr) vk_exec_note_results(VK_RES_OQ); if (oq_nseg) memcpy(s->q, oq_seg, sizeof *s->q * oq_nseg); if (gs_on >= 0) { // the front pass: the workers add the queries of the group's ops before it diff --git a/runtime/vk_sync.c b/runtime/vk_sync.c index d864e659..586eff9c 100644 --- a/runtime/vk_sync.c +++ b/runtime/vk_sync.c @@ -19,6 +19,7 @@ #include "prof.h" #include "vk.h" #include "vk_lowlat.h" +#include "vk_sync_hw.h" #include "platform/platform.h" #define WEAK __attribute__((weak)) @@ -190,6 +191,14 @@ static int hold_max = -1; // NX2NAVI_WB_SPLIT=2 keeps the split with shadow storage too, to measure that fault. static VkSemaphore exec_tl; static uint64_t exec_sig; // sub_lock: the newest value a submitted part signals on exec_tl + +// ---- a lost device in the timelines' values (vk_sync_hw.h) +// The newest value any signal of the timeline (tl_hw) and of exec_tl (ex_hw) carries, noted before the signal can +// happen: by hold_flush_locked before vkQueueSubmit2, by the host's own signals before vkSignalSemaphore. A value read +// above the note ends the run as a lost device (timeline_beyond). Reaching those values is no proof the device lives: +// a driver that reports every pending signal as done after a reset reads at or below the note, and the line an +// occlusion query left unwritten logs (vk_exec_xfer.c oq_cb, vk_sync_state_text) shows which of the two a report had. +static volatile uint64_t tl_hw, ex_hw; static int wb_split = -1; static int wb_results; // the wait on exec_tl also runs the results the game reads (not with 3) @@ -275,6 +284,14 @@ static void hold_flush_locked(VkCtx *c) { __atomic_store_n(&held_n, 0, __ATOMIC_RELEASE); return; } + // every value this hand-over signals is noted before the queue can reach it ("a lost device in the timelines' + // values") + for (int i = 0; i < H.n; i++) + for (uint32_t k = 0; k < H.si[i].signalSemaphoreInfoCount; k++) { + const VkSemaphoreSubmitInfo *s = &H.si[i].pSignalSemaphoreInfos[k]; + if (s->semaphore == c->timeline) sync_hw_raise(&tl_hw, s->value); + else if (s->semaphore == exec_tl) sync_hw_raise(&ex_hw, s->value); + } VkResult r = lost_at_due() ? VK_ERROR_DEVICE_LOST : vkQueueSubmit2(c->gfx_queue, (uint32_t)H.n, H.si, VK_NULL_HANDLE); if (r != VK_SUCCESS) { vk_mem_oom_report("replay submit", r); @@ -850,6 +867,56 @@ WEAK int vk_exec_record(VkCommandBuffer cb, const uint64_t *handles, int n, uint return 0; } +// Without vk_exec.c (the probes): no submission is held back for an event. +WEAK int vk_exec_held(void) { return 0; } + +// raw, read from the timeline whose signals hw notes: above every one of them the device is lost, and the run ends +// here (vk_device_lost_check) after a line with the two values. +static void timeline_beyond(const char *name, uint64_t raw, volatile uint64_t *hw, const char *where) { + uint64_t h = __atomic_load_n(hw, __ATOMIC_ACQUIRE); + if (!sync_hw_beyond(raw, h)) return; + rt_log("vk: the %s reads %llu, above every value its signals carry (%llu): the device is lost", name, + (unsigned long long)raw, (unsigned long long)h); + vk_device_lost_check(VK_ERROR_DEVICE_LOST, where); +} + +void vk_sync_signal_note(uint64_t value) { sync_hw_raise(&tl_hw, value); } + +void vk_sync_check_timeline(const char *where) { + VkCtx *c = vk_ctx(); + if (!c || !c->timeline || vk_device_is_lost()) return; + uint64_t raw = 0; + VkResult r = vkGetSemaphoreCounterValue(c->device, c->timeline, &raw); + vk_device_lost_check(r, where); + if (r == VK_SUCCESS) timeline_beyond("submissions' timeline", raw, &tl_hw, where); +} + +// No lock: the thread that reports a lost device may hold any (vk_device.c device_fault_report). +void vk_sync_state_text(char *o, size_t n) { + VkCtx *c = vk_ctx(); + uint64_t tl = 0, ex = 0; + char a[32] = "nothing (unreadable)", b[32] = "nothing (unreadable)"; + if (c && c->timeline && vkGetSemaphoreCounterValue(c->device, c->timeline, &tl) == VK_SUCCESS) + snprintf(a, sizeof a, "%llu", (unsigned long long)tl); + if (c && exec_tl && vkGetSemaphoreCounterValue(c->device, exec_tl, &ex) == VK_SUCCESS) + snprintf(b, sizeof b, "%llu", (unsigned long long)ex); + snprintf(o, n, + "submissions issued up to %llu, their side effects run up to %llu, handed to the queue up to %llu with %d " + "held back; the submissions' timeline reads %s of %llu signalled at most, the executed timeline %s of %llu; " + "%d submission(s) held for an event", + (unsigned long long)__atomic_load_n(&issued, __ATOMIC_ACQUIRE), + (unsigned long long)__atomic_load_n(&done, __ATOMIC_ACQUIRE), + (unsigned long long)__atomic_load_n(&queued_v, __ATOMIC_ACQUIRE), (int)__atomic_load_n(&held_n, __ATOMIC_ACQUIRE), + a, (unsigned long long)__atomic_load_n(&tl_hw, __ATOMIC_ACQUIRE), b, + (unsigned long long)__atomic_load_n(&ex_hw, __ATOMIC_ACQUIRE), vk_exec_held()); +} + +void vk_sync_lost_report(void) { + char t[512]; + vk_sync_state_text(t, sizeof t); + rt_log("vk: when the device was lost: %s", t); +} + static void completion_main(void *arg) { VkCtx *c = arg; __atomic_store_n(&cb_tid, plat_thread_id(), __ATOMIC_RELEASE); @@ -882,9 +949,13 @@ static void completion_main(void *arg) { vk_device_lost_check(r, "the completion thread's read of the submissions' timeline"); rt_fatal("vk: the submissions' timeline could not be read (%d; device lost?)", (int)r); } - // Both calls may succeed on a lost device and give a value its submissions never reached. So before a - // new value counts, the device is asked once more with a call of its own (vk_device.c - // vk_device_lost_poll, which ends the run when it is lost). + // Both calls may succeed on a lost device and give a value its submissions never reached. A value above + // every one the timeline's signals carry ends the run ("a lost device in the timelines' values"); then, + // before a new value counts, the device is asked once more with a call of its own (vk_device.c + // vk_device_lost_poll, which ends the run when it is lost). That poll alone did not see the losses of the + // RX 6000 reports of 0.9.1 and 0.9.2: their callbacks ran for work the GPU never finished. + timeline_beyond("submissions' timeline", reached, &tl_hw, "the completion thread's read of the submissions' " + "timeline (a value no submission signals)"); if (reached > __atomic_load_n(&done, __ATOMIC_ACQUIRE)) vk_device_lost_poll(); plat_mutex_lock(&st_lock); if (reached > issued) reached = issued; @@ -963,6 +1034,8 @@ void vk_sync_start(void) { perf_gpu_stats = gpu_stats; uint64_t now = 0; vkGetSemaphoreCounterValue(c->device, c->timeline, &now); + sync_hw_raise(&tl_hw, now > issued ? now : issued); // before the restart's signal below + sync_hw_raise(&ex_hw, now > issued ? now : issued); // the executed timeline below starts there if (issued > now) { // a new device after vk_shutdown: values keep increasing for the front end VkSemaphoreSignalInfo si = {.sType = VK_STRUCTURE_TYPE_SEMAPHORE_SIGNAL_INFO, .semaphore = c->timeline, .value = issued}; @@ -1623,6 +1696,14 @@ int vk_sync_exec_wait(uint64_t value, uint64_t timeout_ns) { vk_device_lost_check(r, "the wait for a submission's commands"); rt_fatal("vk: the wait for a submission's commands failed (%d; device lost?)", (int)r); } + if (r == VK_SUCCESS) { // a lost device may end the wait too: the results below would be read from work never run + uint64_t raw = 0; + VkResult q = vkGetSemaphoreCounterValue(c->device, exec_tl, &raw); + vk_device_lost_check(q, "the read of the executed timeline"); + if (q == VK_SUCCESS) + timeline_beyond("executed timeline", raw, &ex_hw, "the wait for a submission's commands (a value no part " + "signals)"); + } // The results the game reads, of this submission and of those before it, which the GPU ran first: here, not when // the completion thread gets to them behind the other side effects of the last frame's submissions. if (r == VK_SUCCESS && wb_results) results_run(value); @@ -1734,6 +1815,7 @@ static uint64_t probe_lost_advance(VkCtx *c, volatile int32_t *ran) { uint64_t v = issued + 1; plat_mutex_unlock(&st_lock); vk_completion_add(v, probe_lost_cb, (void *)ran); + sync_hw_raise(&tl_hw, v); // a host signal: noted before it ("a lost device in the timelines' values") VkSemaphoreSignalInfo si = {.sType = VK_STRUCTURE_TYPE_SEMAPHORE_SIGNAL_INFO, .semaphore = c->timeline, .value = v}; if (vkSignalSemaphore(c->device, &si) != VK_SUCCESS) return 0; plat_mutex_lock(&st_lock); diff --git a/runtime/vk_sync_hw.h b/runtime/vk_sync_hw.h new file mode 100644 index 00000000..9d9dc56b --- /dev/null +++ b/runtime/vk_sync_hw.h @@ -0,0 +1,23 @@ +// The newest value each of the replay's timelines may reach, and the test a value read from one of them must pass +// (vk_sync.c "a lost device in the timelines' values"). Header only, so that tests/sync_hw_check.c checks it without a +// device. +// +// A timeline semaphore changes only through signal operations, and each of them carries a value the program chose: +// for the replay's two timelines, the queue hand-overs of its submissions (vk_sync.c hold_flush_locked) and the host's +// own signals (vk_sync.c vk_sync_start's restart, the lost-device probe, vk_device.c vk_selftest). A live device never +// reports a value above the newest of them. Each such value is noted here before its signal can happen, so a value read +// above the note comes from a device that answers for work it never ran: after a timeout reset, Windows releases every +// waiter of a timeline, and the reports of AMD's RX 6000 cards (0.9.1, 0.9.2) ran the completion callbacks of +// submissions the GPU had not finished ("occlusion query slot ... not available after its fence") before any call +// returned VK_ERROR_DEVICE_LOST. +#pragma once +#include + +// Raises the note *hw to v; never lowers it. Any thread. +static inline void sync_hw_raise(volatile uint64_t *hw, uint64_t v) { + uint64_t o = __atomic_load_n(hw, __ATOMIC_RELAXED); + while (v > o && !__atomic_compare_exchange_n(hw, &o, v, 1, __ATOMIC_RELEASE, __ATOMIC_RELAXED)) {} +} + +// 1 when raw, read from a timeline whose signals were all noted in hw (read after raw), is above every one of them. +static inline int sync_hw_beyond(uint64_t raw, uint64_t hw) { return raw > hw; } diff --git a/tests/sync_hw_check.c b/tests/sync_hw_check.c new file mode 100644 index 00000000..2fd3a41e --- /dev/null +++ b/tests/sync_hw_check.c @@ -0,0 +1,78 @@ +// runtime/vk_sync_hw.h: the newest value each of the replay's timelines may reach, and the test that takes a value read +// above it as a lost device (vk_sync.c "a lost device in the timelines' values"). Built and run by +// tests/sync_hw_check.py; prints each failed check and exits 1 on any. +#include +#include + +#include "vk_sync_hw.h" + +#ifdef _WIN32 +#include +#else +#include +#endif + +static int fails; +#define CHECK(c, ...) do { if (!(c)) { fails++; printf("FAIL line %d: ", __LINE__); printf(__VA_ARGS__); printf("\n"); } } while (0) + +// Four threads raise one note with interleaved values, as the submitting thread, the present and the probes may. +enum { THREADS = 4, PER = 200000 }; +static volatile uint64_t shared_hw; + +#ifdef _WIN32 +static DWORD WINAPI raiser(LPVOID arg) { +#else +static void *raiser(void *arg) { +#endif + uint64_t k = (uint64_t)(uintptr_t)arg; + for (uint64_t i = 0; i < PER; i++) sync_hw_raise(&shared_hw, i * THREADS + k); + return 0; +} + +int main(void) { + // ---- a note only rises + volatile uint64_t hw = 0; + sync_hw_raise(&hw, 10); + CHECK(hw == 10, "a first value of 10 left %llu", (unsigned long long)hw); + sync_hw_raise(&hw, 7); + CHECK(hw == 10, "an older value (7) lowered the note to %llu", (unsigned long long)hw); + sync_hw_raise(&hw, 11); + CHECK(hw == 11, "a newer value (11) left %llu", (unsigned long long)hw); + + // ---- what a live device can read, and what it cannot + // submissions 1..11 noted: the timeline at any of them, or not yet at the first, is a live reading + for (uint64_t raw = 0; raw <= 11; raw++) CHECK(!sync_hw_beyond(raw, hw), "a reading of %llu with 11 noted counted as lost", (unsigned long long)raw); + CHECK(sync_hw_beyond(12, hw), "a reading one past the newest noted value did not count as lost"); + // after a timeout reset Windows releases the waiters of a timeline with the largest value + CHECK(sync_hw_beyond(UINT64_MAX, hw), "the reading a reset leaves (UINT64_MAX) did not count as lost"); + // a note at the largest value (nothing above it can be read) never counts a reading as lost + volatile uint64_t top = 0; + sync_hw_raise(&top, UINT64_MAX); + CHECK(!sync_hw_beyond(UINT64_MAX, top), "a reading equal to a note of UINT64_MAX counted as lost"); + + // ---- the restart of vk_sync_start: the note is raised to the value signalled before the signal, so the + // completion thread's first reading after it is a live one + volatile uint64_t restart = 0; + uint64_t issued = 500, now = 3; // a new device: its timeline at 3, the front end's values at 500 + sync_hw_raise(&restart, now > issued ? now : issued); + CHECK(!sync_hw_beyond(issued, restart), "the restart's own value (500) counted as lost"); + CHECK(sync_hw_beyond(issued + 1, restart), "a reading past the restart's value did not count as lost"); + + // ---- concurrent raises end at the largest value any thread gave +#ifdef _WIN32 + HANDLE t[THREADS]; + for (int k = 0; k < THREADS; k++) t[k] = CreateThread(NULL, 0, raiser, (LPVOID)(uintptr_t)k, 0, NULL); + WaitForMultipleObjects(THREADS, t, TRUE, INFINITE); + for (int k = 0; k < THREADS; k++) CloseHandle(t[k]); +#else + pthread_t t[THREADS]; + for (int k = 0; k < THREADS; k++) pthread_create(&t[k], NULL, raiser, (void *)(uintptr_t)k); + for (int k = 0; k < THREADS; k++) pthread_join(t[k], NULL); +#endif + uint64_t want = (uint64_t)(PER - 1) * THREADS + (THREADS - 1); + CHECK(shared_hw == want, "four threads' raises ended at %llu, not the largest value %llu", + (unsigned long long)shared_hw, (unsigned long long)want); + + printf("sync_hw_check: %s\n", fails ? "FAILED" : "passed"); + return fails ? 1 : 0; +} diff --git a/tests/sync_hw_check.py b/tests/sync_hw_check.py new file mode 100644 index 00000000..c3dc1b97 --- /dev/null +++ b/tests/sync_hw_check.py @@ -0,0 +1,42 @@ +"""Build and run tests/sync_hw_check.c: runtime/vk_sync_hw.h, the newest value each of the replay's timelines may +reach and the test that takes a value read above it as a lost device (vk_sync.c "a lost device in the timelines' +values"). + +No GPU, no game files, any Python. + +Usage: sync_hw_check.py +""" +import os +import shutil +import subprocess +import sys +from pathlib import Path + +ROOT = Path(__file__).resolve().parents[1] +MSYS_BIN = Path(r'C:\msys64\ucrt64\bin') + + +def compiler(): + """$CC, else MSYS2 UCRT64's clang, else clang on PATH (as tests/diff/common.py picks it, without its Unicorn).""" + if os.environ.get('CC'): + return os.environ['CC'] + if os.name == 'nt' and (MSYS_BIN / 'clang.exe').exists(): + return str(MSYS_BIN / 'clang.exe') + return shutil.which('clang') or 'clang' + + +def main(): + work = ROOT / 'build' / 'test' / 'sync_hw' + work.mkdir(parents=True, exist_ok=True) + exe = work / ('sync_hw_check.exe' if os.name == 'nt' else 'sync_hw_check') + env = dict(os.environ) + if os.name == 'nt' and MSYS_BIN.exists(): + env['PATH'] = str(MSYS_BIN) + os.pathsep + env.get('PATH', '') + extra = [] if os.name == 'nt' else ['-pthread'] + subprocess.check_call([compiler(), '-std=gnu11', '-O1', '-Wall', '-Werror', '-I', str(ROOT / 'runtime'), + str(ROOT / 'tests' / 'sync_hw_check.c'), '-o', str(exe), *extra], env=env) + return subprocess.run([str(exe)], env=env).returncode + + +if __name__ == '__main__': + sys.exit(main())