mirror of
https://github.com/tangerineturtle1/NX2navi.git
synced 2026-11-15 19:19:58 -04:00
Add a hang watch that logs a report when no frame is shown with the window in front, or the GPU does not finish, for 20 s.
A present, a submission or a completion that never came back (a deadlock, a driver wait that does not return, a
GPU hang without a reset) left a log that just stopped: kernel.c wait_watch covers guest lock and thread-end waits
only and is off by default, and nothing watched the present, submit or completion threads.
hang_watch.c runs a thread of its own in a game run (main.c starts it before the boot; never in the tool modes).
Once a second it reads, without a lock, gfx_counters.frames and the submissions issued and done (the new
vk_sync.c vk_sync_progress, no device call). It reports a stall of the frames while the guest runs, the window is
in front and not minimized (gfx_window_in_front) and no orderly end has begun (rt_exit_started): the game stops
presenting without the focus, so a focus change starts the count again, and the boot screen is not judged. It
reports submissions issued and not done, "done" unchanged for N s, whatever the focus. One report per stall, a
new stall needs progress, at most 3 a run. A report names the stall with the counts, the focus and the world
clock; who holds the present, queue and window-start locks (gfx_present.c gfx_lock_holders, read from
PlatRMutex.owner and depth); the guest threads' lock and thread-end waits (kernel.c kern_wait_report, wait_watch's
walk factored out as wait_pass, run with limit 0 under ten 10 ms trylocks of the kernel lock); and then writes the
log out with logq_flush, never rt_log_sync, which would put every later line on the thread that logs it in a run
that may recover. It never ends the process and adds no wait to a drawing thread. The per-thread wait sites and
lock owner wrappers are left for a later change.
NX2NAVI_HANG_WATCH_S sets the seconds (default 20, 0..600, read at start, 0 off): a metas row, a known[] name, a
diagnostics sections[] entry and an nx2navi.ini.example entry.
Not reproduced before the change (a diagnostic). The new tests/hang_watch_check.py drives hang_watch.c's decisions
on made-up readings: no report while things move, unfocused, minimized or ending; one per stall of the frames with
the window in front and one again after progress; one for submissions not done whatever the focus; none for an
idle GPU; at most 3; logq_flush called and logq_sync never. tests/cfg_rows_check.py (0 problems), the scratchpad
rows check ("missing []") and the compile checks of every runtime file pass.
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
@@ -994,6 +994,10 @@
|
||||
# it waits for and what that one is doing (at most 24 lines a run): a game that stops then leaves the chain in its log.
|
||||
# Off by default: its thread takes the game's thread lock every 2 seconds. 10 is a good value for a hang report.
|
||||
# wait_watch_s = 0
|
||||
# A report in the log when nothing moves for this many seconds: no frame shown while the window is in front, or a GPU
|
||||
# submission not finished. It names who holds the present and queue locks and what the game's threads wait for, at
|
||||
# most three times a run; the game goes on. 0 turns it off. Read at start.
|
||||
# hang_watch_s = 20
|
||||
# Diagnosis: one log line per frame while Link stands near a moving floor (the floating platforms): the frame's step,
|
||||
# how far he moved and how far the floor moved. 1 writes 4000 lines, a larger number that many; 0 is off.
|
||||
# floor_probe = 0
|
||||
|
||||
@@ -91,6 +91,8 @@ static const char *const known[] = {
|
||||
// developer switches read with cfg_get, rt_knob or vk_caps.c env_u32, without a menu row (tests/cfg_rows_check.py)
|
||||
"AUDIO_DUMP", "DEFER_STAMP", "DEPTH_TWIN", "DLAA_ZFIT", "DUMP_SKIP_RUNS", "DUMP_TEX", "DUMP_UBO", "EVENT_ORDER",
|
||||
"GATHER_BIAS", "PIN_SWEEP", "REC_CHECK", "REC_DELAY_US", "REG_ORDER", "SHADOW", "ZERO_LOCALS",
|
||||
// hang_watch.c: the hang watch's seconds
|
||||
"HANG_WATCH_S",
|
||||
// retired: the settings of the co-op of versions up to 0.9.2; read by nothing, listed so that a file which still
|
||||
// sets them logs no unknown key
|
||||
"COOP", "COOP_BETA", "COOP_NAME", "COOP_SERVER", "COOP_PORT", "COOP_ROOM", "COOP_AUTO", "COOP_DROP",
|
||||
@@ -173,6 +175,7 @@ static const struct { const char *key, *section; } sections[] = {
|
||||
{"WB_MERGE_MAX", "diagnostics"}, {"MV_SURVEY", "diagnostics"}, {"TEXUP_LOG_MS", "diagnostics"},
|
||||
{"WAIT_WATCH_S", "diagnostics"},
|
||||
{"HANDLE_CENSUS", "diagnostics"},
|
||||
{"HANG_WATCH_S", "diagnostics"},
|
||||
{"VMA_BLOCK_MB", "diagnostics"}, {"DEVICE_LOST_AT", "diagnostics"}, {"STAGING_FAIL_AT", "diagnostics"}, {"VRAM_BALLAST_MB", "diagnostics"},
|
||||
{"COPY_RETIRE", "diagnostics"},
|
||||
{"MEM_BUDGET_TEST_VRAM_MB", "diagnostics"}, {"MEM_BUDGET_TEST_RAM_MB", "diagnostics"},
|
||||
@@ -431,6 +434,8 @@ static const CfgMeta metas[] = {
|
||||
{"WAIT_WATCH_S", "0", "0..3600", RESTART}, // kernel.c wait_watch: a lock or thread-end wait this long is logged; 0 off
|
||||
// perf.c hc_main: with NX2NAVI_TRACE=perf, the process's handles by kind when their count grew
|
||||
{"HANDLE_CENSUS", "0", "0|1", RESTART},
|
||||
// hang_watch.c: a report when no frame is shown with the window in front, or the GPU does not finish, this long; 0 off
|
||||
{"HANG_WATCH_S", "20", "0..600", RESTART},
|
||||
{"VMA_BLOCK_MB", "64", "16..256", RESTART}, // vk_headroom.c vk_vma_block_size
|
||||
// vk_texture.c compact_on: idle textures move out of sparsely used blocks of video memory; the free space inside
|
||||
// the blocks from which a pass starts, and the bytes moved per frame (also the largest texture that moves)
|
||||
|
||||
@@ -27,6 +27,10 @@ uint64_t gfx_vsync_ticks(void); // ticks since start
|
||||
uint64_t gfx_vsync_time_ns(uint64_t tick); // kern_now_ns() time of a tick (pacing)
|
||||
double gfx_window_refresh_hz(void); // refresh rate of the window's monitor; 0 unknown
|
||||
int gfx_window_focused(void);
|
||||
// gfx_present.c: who holds the present, queue and window-start locks, read without taking them (the hang watch)
|
||||
typedef struct { uint32_t present, present_depth, queue, queue_depth, start; } GfxLockHolders;
|
||||
void gfx_lock_holders(GfxLockHolders *h);
|
||||
int gfx_window_in_front(void); // the window has the focus and is not minimized: the game is expected to present
|
||||
int vk_hdr_native(void); // NX2NAVI_HDR = native: the game's own HDR picture (vk_hdr.c)
|
||||
int gfx_picture_rect(float out[4]); // where the last present put the picture, fractions of the swapchain (x, y, w, h); 0 before one
|
||||
|
||||
|
||||
@@ -126,6 +126,8 @@ int rt_exit_begin(void) {
|
||||
for (;;) plat_sleep_ms(1000);
|
||||
}
|
||||
|
||||
int rt_exit_started(void) { return __atomic_load_n(&exit_tid, __ATOMIC_ACQUIRE) != 0; }
|
||||
|
||||
// What every orderly end saves and puts back, in this order. What a kill of the process must not lose and what is quick
|
||||
// comes first: Windows ends a closed console about 5 s after the close, a session's end and an "End task" sooner, and
|
||||
// the pipeline save alone can take that long (vk_pipeline_save_exit waits up to 5 s for the builds that run). So a
|
||||
@@ -2013,3 +2015,15 @@ void gfx_window_start(void) {
|
||||
plat_rmutex_unlock(&g_start_lock);
|
||||
vsync_ensure();
|
||||
}
|
||||
|
||||
int gfx_window_in_front(void) { return gfx_window_focused() && !wsys_minimized(); }
|
||||
|
||||
// For the hang watch's report (hang_watch.c): who holds the present, queue and window-start locks now, read without
|
||||
// taking them (0: free). The fields may be caught mid-change; the report only names them.
|
||||
void gfx_lock_holders(GfxLockHolders *h) {
|
||||
h->present = __atomic_load_n(&g_pl.owner, __ATOMIC_RELAXED);
|
||||
h->present_depth = __atomic_load_n(&g_pl.depth, __ATOMIC_RELAXED);
|
||||
h->queue = __atomic_load_n(&g_ql.owner, __ATOMIC_RELAXED);
|
||||
h->queue_depth = __atomic_load_n(&g_ql.depth, __ATOMIC_RELAXED);
|
||||
h->start = __atomic_load_n(&g_start_lock.owner, __ATOMIC_RELAXED);
|
||||
}
|
||||
|
||||
105
runtime/hang_watch.c
Normal file
105
runtime/hang_watch.c
Normal file
@@ -0,0 +1,105 @@
|
||||
// The hang watch: a report in the log when nothing moves for NX2NAVI_HANG_WATCH_S seconds (default 20; 0 off). A
|
||||
// present, a GPU submission or the completion of one that never comes back (a deadlock, a driver wait that does not
|
||||
// return, a GPU hang without a reset) left a log that just stopped, and nothing in it said where the threads were.
|
||||
//
|
||||
// Its own thread reads, once a second and without a lock, what moves while the game runs: the frames shown
|
||||
// (gfx_counters.frames) and the GPU submissions issued and done (vk_sync.c vk_sync_progress). Two stalls are reported:
|
||||
// - no frame shown for N s while the guest runs, the window is in front and not minimized and the process is not
|
||||
// ending: the game stops presenting when it loses the focus, so a focus change starts the count again, and the boot
|
||||
// screen (before the guest starts) is not judged;
|
||||
// - submissions issued and not done, with "done" unchanged for N s, whatever the focus.
|
||||
// One report per stall, and a new stall needs progress first; at most HW_REPORTS a run. The report names the stall,
|
||||
// who holds the present, queue and window-start locks (gfx_present.c gfx_lock_holders), the guest threads' lock and
|
||||
// thread-end waits (kernel.c kern_wait_report), and then writes the log out with logq_flush, which leaves the log
|
||||
// thread on: rt_log_sync would make every later line a write on the thread that logs it, drawing threads included,
|
||||
// in a run that may yet recover. The watch never ends the process, never calls the device, and takes no lock a
|
||||
// drawing thread waits for, but for the kernel lock it tries during a report (kernel.c kern_wait_report).
|
||||
#include "cfg.h"
|
||||
#include "gfx.h"
|
||||
#include "host.h"
|
||||
#include "logq.h"
|
||||
#include "nvn_api.h"
|
||||
#include "platform/platform.h"
|
||||
|
||||
#define HW_REPORTS 3
|
||||
|
||||
typedef struct { // what the watch reads each second
|
||||
uint64_t now_ns, frames, issued, done;
|
||||
int judge_present; // the guest runs, the window is in front and not minimized, the process is not ending
|
||||
} HwBeat;
|
||||
|
||||
typedef struct {
|
||||
uint64_t limit_ns;
|
||||
uint64_t frames, frames_at; // the frame count last seen, and since when nothing moved while judged
|
||||
uint64_t done, done_at; // the same for the submissions done, while some are outstanding
|
||||
int present_told, gpu_told; // this stall is reported
|
||||
int reports;
|
||||
} HangWatch;
|
||||
|
||||
enum { HW_NONE, HW_PRESENT, HW_GPU };
|
||||
|
||||
// One second's reading: which stall to report now, if any.
|
||||
static int hw_step(HangWatch *w, const HwBeat *b) {
|
||||
if (b->frames != w->frames || !b->judge_present) { // progress, or not judged: the count starts again
|
||||
w->frames = b->frames;
|
||||
w->frames_at = b->now_ns;
|
||||
w->present_told = 0;
|
||||
}
|
||||
if (b->done != w->done || b->issued <= b->done) {
|
||||
w->done = b->done;
|
||||
w->done_at = b->now_ns;
|
||||
w->gpu_told = 0;
|
||||
}
|
||||
if (w->reports >= HW_REPORTS) return HW_NONE;
|
||||
int gpu = !w->gpu_told && b->issued > b->done && b->now_ns - w->done_at >= w->limit_ns;
|
||||
int present = !w->present_told && b->judge_present && b->now_ns - w->frames_at >= w->limit_ns;
|
||||
if (!gpu && !present) return HW_NONE;
|
||||
w->reports++;
|
||||
w->present_told = 1; // a GPU stall stops the frames too: one report for both
|
||||
if (gpu) w->gpu_told = 1;
|
||||
return gpu ? HW_GPU : HW_PRESENT;
|
||||
}
|
||||
|
||||
static void hw_read(HwBeat *b) {
|
||||
b->now_ns = plat_now_ns();
|
||||
b->frames = __atomic_load_n(&gfx_counters.frames, __ATOMIC_RELAXED);
|
||||
vk_sync_progress(&b->issued, &b->done);
|
||||
b->judge_present = __atomic_load_n(&rt_guest_start_ns, __ATOMIC_RELAXED) && gfx_window_in_front() &&
|
||||
!rt_exit_started();
|
||||
}
|
||||
|
||||
static void hw_report(int kind, const HwBeat *b, const HangWatch *w) {
|
||||
int64_t world = frame_step_world_us();
|
||||
uint64_t since = b->now_ns - (kind == HW_GPU ? w->done_at : w->frames_at);
|
||||
rt_log("hang watch: %s for %.0f s (frames shown %llu; GPU submissions issued up to %llu, done up to %llu; window "
|
||||
"%s; world clock %.1f s); report %d of at most %d, the game goes on",
|
||||
kind == HW_GPU ? "GPU submissions not done" : "no frame shown with the window in front", since / 1e9,
|
||||
(unsigned long long)b->frames, (unsigned long long)b->issued, (unsigned long long)b->done,
|
||||
gfx_window_in_front() ? "in front" : "not in front", world >= 0 ? world / 1e6 : -1.0, w->reports, HW_REPORTS);
|
||||
GfxLockHolders h;
|
||||
gfx_lock_holders(&h);
|
||||
rt_log("hang watch: the present lock is held by thread %u (depth %u), the queue lock by thread %u (depth %u), the "
|
||||
"window start lock by thread %u (0: free)", h.present, h.present_depth, h.queue, h.queue_depth, h.start);
|
||||
kern_wait_report();
|
||||
logq_flush();
|
||||
}
|
||||
|
||||
static void hang_watch_main(void *arg) {
|
||||
HangWatch w = {.limit_ns = (uint64_t)(uintptr_t)arg * 1000000000ull};
|
||||
HwBeat b;
|
||||
hw_read(&b);
|
||||
w.frames = b.frames, w.frames_at = b.now_ns, w.done = b.done, w.done_at = b.now_ns;
|
||||
while (w.reports < HW_REPORTS) {
|
||||
plat_sleep_ms(1000);
|
||||
hw_read(&b);
|
||||
int kind = hw_step(&w, &b);
|
||||
if (kind) hw_report(kind, &b, &w);
|
||||
}
|
||||
}
|
||||
|
||||
void hang_watch_start(void) {
|
||||
int s = cfg_int("NX2NAVI_HANG_WATCH_S");
|
||||
if (s <= 0) return;
|
||||
if (!plat_thread_spawn(hang_watch_main, (void *)(uintptr_t)s, "hang watch", 0))
|
||||
rt_log("hang watch: its thread did not start");
|
||||
}
|
||||
@@ -25,6 +25,9 @@ void rt_log_raw(const char *p, size_t n);
|
||||
const char *rt_log_path(void); // the log file, NULL when this run writes none
|
||||
void rt_log_sync(void); // writes the queued log lines now; later lines are written as they are made
|
||||
void rt_log_ending(void); // the process is ending: its lines reach the log file past its 64 MiB cap
|
||||
void hang_watch_start(void); // hang_watch.c: NX2NAVI_HANG_WATCH_S's thread, in a game run
|
||||
void kern_wait_report(void); // kernel.c: the guest threads' lock and thread-end waits, for a hang report
|
||||
void vk_sync_progress(uint64_t *issued, uint64_t *done); // vk_sync.c: submissions issued and done, no lock or device call
|
||||
enum { RT_TRACE_SVC = 1, RT_TRACE_HOSTCALL = 2, RT_TRACE_IPC = 4, RT_TRACE_FS = 8, RT_TRACE_GFX = 16, RT_TRACE_PERF = 32,
|
||||
RT_TRACE_SCHED = 64, RT_TRACE_AUDIO = 128, RT_TRACE_PRESENT = 256 };
|
||||
extern unsigned rt_trace; // from NX2NAVI_TRACE=svc,host,ipc,fs,gfx,perf,sched,audio,present (or all)
|
||||
@@ -116,6 +119,7 @@ void gfx_window_closed(void); // gfx_present.c (gfx_wsys.h): t
|
||||
// --seconds). rt_exit_begin: 1 for the first caller; another thread waits there for good; 0 for that caller's own
|
||||
// thread again. rt_exit_steps: the saves and the put-backs, the slow pipeline save late and the final save flush last.
|
||||
int rt_exit_begin(void);
|
||||
int rt_exit_started(void); // an orderly end has begun (the hang watch stops judging presents)
|
||||
enum { RT_EXIT_SETTINGS = 1 }; // rt_exit_steps also writes the menu's changes to nx2navi.ini
|
||||
void rt_exit_steps(unsigned what);
|
||||
void perf_gpu_wait(uint64_t t0); // a wait for a GPU fence ended (any thread; the render thread's also counts as PERF_FENCE)
|
||||
|
||||
@@ -968,6 +968,35 @@ static void wait_watch_holder(char *out, size_t cap, const RtThread *h) {
|
||||
(kern_now_ns() - h->blk_since) / 1e9, kinds[k], (unsigned long long)h->wobj);
|
||||
}
|
||||
|
||||
// One walk over the guest threads, G held: each one that has waited `limit` ns or longer for a lock or for another
|
||||
// thread's end gets a line, at most max of them. mark: a wait gets its line once (wait_watch); the hang watch's report
|
||||
// (kern_wait_report) lists every such wait as it stands. Returns the lines written.
|
||||
static int wait_pass(uint64_t limit, int max, int mark) {
|
||||
int lines = 0;
|
||||
uint64_t now = kern_now_ns();
|
||||
for (RtThread *t = g_all; t && lines < max; t = t->all) {
|
||||
if (!t->blk_since || (mark && t->blk_told) || now - t->blk_since < limit) continue;
|
||||
char who[160];
|
||||
if (t->wkind == W_LOCK) { // the lock word's owner field is the holder's handle
|
||||
wait_watch_holder(who, sizeof who, h_peek((uint32_t)t->wobj, O_THREAD));
|
||||
rt_log("kernel: thread %#x (priority %d) has waited %.0f s for the lock at %#llx held by %s",
|
||||
t->handle, t->prio, (now - t->blk_since) / 1e9, (unsigned long long)t->waddr, who);
|
||||
} else if (t->wkind == W_SYNC && t->whs) {
|
||||
const RtThread *end = NULL;
|
||||
for (int i = 0; i < t->wn && !end; i++) end = h_peek(t->whs[i], O_THREAD);
|
||||
if (!end) continue;
|
||||
wait_watch_holder(who, sizeof who, end);
|
||||
rt_log("kernel: thread %#x (priority %d) has waited %.0f s for the end of %s", t->handle, t->prio,
|
||||
(now - t->blk_since) / 1e9, who);
|
||||
} else {
|
||||
continue;
|
||||
}
|
||||
if (mark) t->blk_told = 1;
|
||||
lines++;
|
||||
}
|
||||
return lines;
|
||||
}
|
||||
|
||||
static void wait_watch(void *arg) {
|
||||
(void)arg;
|
||||
uint64_t limit = (uint64_t)atoi(cfg_value("NX2NAVI_WAIT_WATCH_S")) * 1000000000ull;
|
||||
@@ -976,31 +1005,26 @@ static void wait_watch(void *arg) {
|
||||
while (lines < WAIT_WATCH_LINES) {
|
||||
plat_wait_ns(2000000000ull);
|
||||
lock();
|
||||
uint64_t now = kern_now_ns();
|
||||
for (RtThread *t = g_all; t && lines < WAIT_WATCH_LINES; t = t->all) {
|
||||
if (!t->blk_since || t->blk_told || now - t->blk_since < limit) continue;
|
||||
char who[160];
|
||||
if (t->wkind == W_LOCK) { // the lock word's owner field is the holder's handle
|
||||
wait_watch_holder(who, sizeof who, h_peek((uint32_t)t->wobj, O_THREAD));
|
||||
rt_log("kernel: thread %#x (priority %d) has waited %.0f s for the lock at %#llx held by %s",
|
||||
t->handle, t->prio, (now - t->blk_since) / 1e9, (unsigned long long)t->waddr, who);
|
||||
} else if (t->wkind == W_SYNC && t->whs) {
|
||||
const RtThread *end = NULL;
|
||||
for (int i = 0; i < t->wn && !end; i++) end = h_peek(t->whs[i], O_THREAD);
|
||||
if (!end) continue;
|
||||
wait_watch_holder(who, sizeof who, end);
|
||||
rt_log("kernel: thread %#x (priority %d) has waited %.0f s for the end of %s", t->handle, t->prio,
|
||||
(now - t->blk_since) / 1e9, who);
|
||||
} else {
|
||||
continue;
|
||||
}
|
||||
t->blk_told = 1, lines++;
|
||||
}
|
||||
lines += wait_pass(limit, WAIT_WATCH_LINES - lines, 1);
|
||||
unlock();
|
||||
}
|
||||
rt_log("kernel: %d long waits logged: no more", lines);
|
||||
}
|
||||
|
||||
// The hang watch's report (hang_watch.c): the guest threads' lock and thread-end waits as they stand. G is only tried,
|
||||
// ten times 10 ms apart: its holder may be the thread that hangs, and the watch adds no wait of its own.
|
||||
void kern_wait_report(void) {
|
||||
int got = 0;
|
||||
for (int i = 0; i < 10 && !(got = plat_mutex_trylock(&G)); i++) plat_sleep_ms(10);
|
||||
if (!got) {
|
||||
rt_log("kernel: the thread lock stayed taken for 100 ms; the guest threads' waits are not listed");
|
||||
return;
|
||||
}
|
||||
int lines = wait_pass(0, 16, 0);
|
||||
unlock();
|
||||
if (!lines) rt_log("kernel: no guest thread waits for a lock or for another thread's end");
|
||||
}
|
||||
|
||||
int kern_core_away(void) {
|
||||
RtThread *t = tcur;
|
||||
if (!t || t->cur_core < 0) return 0;
|
||||
|
||||
@@ -754,6 +754,7 @@ static int main_run(int argc, char **argv) {
|
||||
if (plat_console_setup(console_closed))
|
||||
rt_log("console: QuickEdit off; closing the console ends the game as its window does");
|
||||
mem_start_note(0); // memory.c: a warning when the machine has less memory free than the game takes
|
||||
hang_watch_start(); // a report in the log when the frames or the GPU stop (hang_watch.c); never in tool modes
|
||||
cfg.boot = cfg.seconds > 0; // --seconds starts the game like --boot, with its checkpoints
|
||||
vk_driver_cache_env(); // before the threads below and rt_boot's, any of which may load the Vulkan driver
|
||||
discord_init(); // the Rich Presence thread (discord_rpc.c); it reads nx2navi.ini itself and idles while off
|
||||
|
||||
@@ -988,6 +988,13 @@ void vk_sync_lost_report(void) {
|
||||
rt_log("vk: when the device was lost: %s", t);
|
||||
}
|
||||
|
||||
// The hang watch's reading (hang_watch.c): the newest value submitted and the newest done, without a lock or a device
|
||||
// call.
|
||||
void vk_sync_progress(uint64_t *issued_out, uint64_t *done_out) {
|
||||
*issued_out = __atomic_load_n(&issued, __ATOMIC_ACQUIRE);
|
||||
*done_out = __atomic_load_n(&done, __ATOMIC_ACQUIRE);
|
||||
}
|
||||
|
||||
static void completion_main(void *arg) {
|
||||
VkCtx *c = arg;
|
||||
__atomic_store_n(&cb_tid, plat_thread_id(), __ATOMIC_RELEASE);
|
||||
|
||||
91
tests/hang_watch_check.c
Normal file
91
tests/hang_watch_check.c
Normal file
@@ -0,0 +1,91 @@
|
||||
// runtime/hang_watch.c's decisions on made-up readings, a second apart, with stand-ins for what it reads and calls.
|
||||
// Built and run by tests/hang_watch_check.py; prints each failed check and exits 1 on any.
|
||||
#include "hang_watch.c"
|
||||
|
||||
#include <stdarg.h>
|
||||
#include <stdio.h>
|
||||
|
||||
static int fails;
|
||||
#define CHECK(c, ...) do { if (!(c)) { fails++; printf("FAIL line %d: ", __LINE__); printf(__VA_ARGS__); printf("\n"); } } while (0)
|
||||
|
||||
// ---- the runtime hang_watch.c reaches
|
||||
GfxStats gfx_counters;
|
||||
uint64_t rt_guest_start_ns = 1;
|
||||
static int focused = 1, minimized, ending, flushes, syncs, wait_reports;
|
||||
static uint64_t issued_v, done_v;
|
||||
void vk_sync_progress(uint64_t *issued, uint64_t *done) { *issued = issued_v, *done = done_v; }
|
||||
int gfx_window_in_front(void) { return focused && !minimized; }
|
||||
int rt_exit_started(void) { return ending; }
|
||||
int64_t frame_step_world_us(void) { return 1000000; }
|
||||
void gfx_lock_holders(GfxLockHolders *h) { *h = (GfxLockHolders){7, 1, 0, 0, 0}; }
|
||||
void kern_wait_report(void) { wait_reports++; }
|
||||
void logq_flush(void) { flushes++; }
|
||||
void logq_sync(void) { syncs++; }
|
||||
void rt_log(const char *fmt, ...) {
|
||||
va_list ap;
|
||||
va_start(ap, fmt);
|
||||
printf(" log: ");
|
||||
vprintf(fmt, ap);
|
||||
printf("\n");
|
||||
va_end(ap);
|
||||
}
|
||||
int cfg_int(const char *name) { (void)name; return 20; }
|
||||
|
||||
// ---- the readings: t seconds, the frames shown so far, focus, and the GPU's issued and done values
|
||||
static HangWatch w;
|
||||
static uint64_t t_s;
|
||||
static int run(int seconds, int frames_move, int gpu_move) {
|
||||
int reports = 0;
|
||||
for (int i = 0; i < seconds; i++) {
|
||||
t_s++;
|
||||
if (frames_move) gfx_counters.frames++;
|
||||
if (gpu_move) issued_v++, done_v++;
|
||||
HwBeat b;
|
||||
hw_read(&b);
|
||||
b.now_ns = t_s * 1000000000ull;
|
||||
int kind = hw_step(&w, &b);
|
||||
if (kind) {
|
||||
hw_report(kind, &b, &w);
|
||||
reports++;
|
||||
}
|
||||
}
|
||||
return reports;
|
||||
}
|
||||
|
||||
int main(void) {
|
||||
setvbuf(stdout, NULL, _IONBF, 0);
|
||||
w = (HangWatch){.limit_ns = 20000000000ull};
|
||||
CHECK(!run(100, 1, 1), "a report while frames and the GPU move");
|
||||
focused = 0;
|
||||
CHECK(!run(100, 0, 0), "a report while the window is not in front");
|
||||
focused = 1, minimized = 1;
|
||||
CHECK(!run(100, 0, 0), "a report while the window is minimized");
|
||||
minimized = 0, ending = 1;
|
||||
CHECK(!run(100, 0, 0), "a report while the process ends");
|
||||
ending = 0;
|
||||
int r = run(19, 0, 0);
|
||||
CHECK(!r, "a report before 20 s without a frame in front");
|
||||
r = run(60, 0, 0);
|
||||
CHECK(r == 1, "%d reports for one stall of the frames, want 1", r);
|
||||
CHECK(flushes == 1 && wait_reports == 1 && !syncs, "the report wrote %d flushes, %d wait lists and %d syncs", flushes,
|
||||
wait_reports, syncs);
|
||||
r = run(5, 1, 1) + run(30, 0, 0);
|
||||
CHECK(r == 1, "%d reports for a second stall after progress, want 1", r);
|
||||
focused = 0; // the GPU stops: reported whatever the focus
|
||||
issued_v += 3;
|
||||
r = run(30, 0, 0);
|
||||
CHECK(r == 1, "%d reports for submissions not done, want 1", r);
|
||||
issued_v = done_v;
|
||||
r = run(5, 1, 1);
|
||||
focused = 1;
|
||||
r += run(60, 0, 0);
|
||||
CHECK(r == 0, "%d reports after the third: at most 3 a run", r);
|
||||
CHECK(w.reports == 3, "%d reports in all, want 3", w.reports);
|
||||
// a fresh watch: the GPU idle (nothing outstanding) is no stall
|
||||
w = (HangWatch){.limit_ns = 20000000000ull};
|
||||
focused = 0;
|
||||
issued_v = done_v;
|
||||
CHECK(!run(100, 0, 0), "a report for an idle GPU");
|
||||
printf("hang_watch_check: %s\n", fails ? "FAILED" : "ok");
|
||||
return fails ? 1 : 0;
|
||||
}
|
||||
53
tests/hang_watch_check.py
Normal file
53
tests/hang_watch_check.py
Normal file
@@ -0,0 +1,53 @@
|
||||
"""Build and run tests/hang_watch_check.c: runtime/hang_watch.c's decisions on made-up readings. No report while the
|
||||
frames and the GPU move, while the window is not in front or minimized, or while the process ends; one report for a
|
||||
stall of the frames with the window in front, another after progress and a new stall, one for GPU submissions not
|
||||
done whatever the focus, none for an idle GPU, at most three a run. A report writes the log out with logq_flush and
|
||||
never with logq_sync, which would turn the log thread off. No game files, no GPU.
|
||||
|
||||
Usage: hang_watch_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')
|
||||
|
||||
LAYOUT = '''// A stand-in for the generated layout.h (tests/hang_watch_check.py).
|
||||
#pragma once
|
||||
#define MOD_MAIN_BASE 0x7000000000ull
|
||||
#define MOD_MAIN_SIZE 0x4ea0000ull
|
||||
'''
|
||||
|
||||
|
||||
def compiler():
|
||||
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' / 'hang_watch'
|
||||
work.mkdir(parents=True, exist_ok=True)
|
||||
(work / 'layout.h').write_text(LAYOUT)
|
||||
win = os.name == 'nt'
|
||||
exe = work / ('hang_watch_check.exe' if win else 'hang_watch_check')
|
||||
env = dict(os.environ)
|
||||
if win and MSYS_BIN.exists():
|
||||
env['PATH'] = str(MSYS_BIN) + os.pathsep + env.get('PATH', '')
|
||||
rt = ROOT / 'runtime'
|
||||
plat = [rt / 'platform' / ('win32.c' if win else 'linux.c'), rt / 'platform' / 'common.c']
|
||||
libs = ['-lbcrypt', '-lws2_32', '-lpsapi', '-lwinmm', '-ldbghelp', '-lshell32', '-lole32', '-luser32', '-ladvapi32'] if win \
|
||||
else ['-lpthread']
|
||||
subprocess.check_call([compiler(), '-O1', '-g', '-Wall', '-Wno-unused-function', '-fno-strict-aliasing',
|
||||
'-march=x86-64-v3', '-I', str(rt), '-I', str(work), str(ROOT / 'tests' / 'hang_watch_check.c'),
|
||||
*map(str, plat), '-o', str(exe), '-lm', *libs], env=env)
|
||||
return subprocess.run([str(exe)], env=env, timeout=120).returncode
|
||||
|
||||
|
||||
if __name__ == '__main__':
|
||||
sys.exit(main())
|
||||
Reference in New Issue
Block a user