Exclude host waits from render-thread GPU timing brackets

This commit is contained in:
Shokunin
2026-10-21 09:09:26 -07:00
parent 1ef10b7f79
commit 22f12a54f7
6 changed files with 80 additions and 16 deletions
+2
View File
@@ -213,6 +213,8 @@ on a fixed region -> next.
## 5. Status / Log (update every session)
- **2026-10-21 (BRIEF-4 GPU timing):** Split TIME_ELAPSED brackets around command starvation and presentation waits. Real-context 30ms producer-idle control reports 35.141ms with the old bracket / 5.620ms active GPU work; Windows and Mac GL fixtures and render-thread unit checks pass. Completion stalls remain; dynamic-resolution reallocations are the next target. No guest or completion-clock changes.
- **2026-10-21 (BRIEF-4 depth state):** Removed per-batch GL state round trips, including the mask-check exception absent in the old experiment. Real-context state restoration and image/readback controls pass on Windows and Mac. Fullscreen quiet route remains unaccepted (8 completion gaps, 53.2% p99 busy). Investigating GPU query spans that include host pacing and provoke expensive dynamic-resolution reallocations.
- **2026-10-21 (BRIEF-4 Stage 1):** Reused #722 display-height cap and added opt-in `supersample_disable_at_lines`; unchanged defaults for other titles. Resolution, replay, config-parser and R4 default checks pass on Windows and macOS. R4 fullscreen 8K route cap restores 60 Hz but completion gaps remain (6 quiet / 7 loaded); no stage acceptance claimed. See R4 `analysis/STATUS.md`.
+3
View File
@@ -66,6 +66,9 @@ typedef struct RtConfig {
RtCtxFn ctx;
void *user;
RtTickFn tick; /* optional (NULL) */
/* Optional: before a command wait, on the render thread with its context
* current and no queue mutex held (e.g. end a GPU timing bracket). */
void (*idle)(void *user);
} RtConfig;
/* Start: the context must be current on the calling thread; on success it is
+49 -16
View File
@@ -433,6 +433,7 @@ static void fg_flush(void);
static void fg_invalidate(void);
static uint64_t fg_tick(void *user, uint64_t now);
static void fg_note_guest_frame(void);
static void rthf_gpu_pause(void);
extern int psx_ws_prim_is_tagged(void); /* gpu.c: is the current GP0 prim sprite-tagged? */
extern int psx_ws_prim_in_backdrop(void); /* gpu.c: is its source addr in the flower-field struct? */
extern int gpu_ws_nw_flat_backdrop_enabled(void); /* gpu.c: per-title flat backdrop opt-in */
@@ -9851,6 +9852,8 @@ static void pt_end(void) {
/* The swap: direct, or queued to the present thread. */
static void gl_present_swap(void) {
/* Swap/slot waits are host pacing, not execution time on the GPU. */
rthf_gpu_pause();
if (!s_pt_on) { gl_window_swap(); return; }
(void)pt_target_fbo(); /* a frame that never bound 0 still has its slot */
void *ready = p_glFenceSync(PT_SYNC_GPU_COMMANDS_COMPLETE, 0);
@@ -11373,12 +11376,13 @@ static void rth_present_payload(uint16_t op, const uint8_t *p) {
#define RTHF_Q 8
/* Frame generation pauses a frame's measurement while it draws (the frame
* then has up to RTHF_SEG queries, summed). */
#define RTHF_SEG 4
#define RTHF_SEG 64
static _Atomic int s_rthf_want = 0; /* host: measure (dynres active) */
static int s_rthf_qok = -1; /* render thread: queries usable */
static GLuint s_rthf_q[RTHF_Q][RTHF_SEG];
static int s_rthf_nseg[RTHF_Q];
static uint64_t s_rthf_slot_cpu[RTHF_Q];
static int s_rthf_gpu_active = 0;
static int s_rthf_paused = 0; /* a pause ended this frame's query */
static uint64_t s_rthf_pause_t0 = 0, s_rthf_pause_swap = 0, s_rthf_excl = 0;
static void fg_note_real_cost(uint64_t cpu_ns, uint64_t gpu_ns, int has_gpu); /* frame generation */
@@ -11426,6 +11430,37 @@ static void rthf_poll(void) {
}
}
/* TIME_ELAPSED includes wall time when the command stream is starved.
* Close it before host waits and reopen only for a subsequent record. */
static int rthf_active_segments(void) {
static int enabled = -1;
if (enabled < 0) {
const char *e = getenv("PSX_GL_GPU_ACTIVE_SEGMENTS");
enabled = !(e && e[0] == '0');
}
return enabled;
}
static void rthf_gpu_pause(void) {
if (!s_rthf_open || !s_rthf_has_q || !s_rthf_gpu_active ||
!rthf_active_segments()) return;
p_glEndQuery(GL_TIME_ELAPSED);
s_rthf_gpu_active = 0;
}
static void rthf_gpu_resume(void) {
if (!s_rthf_open || !s_rthf_has_q || s_rthf_gpu_active || s_rthf_paused) return;
const unsigned i = s_rthf_head % RTHF_Q;
if (s_rthf_nseg[i] == RTHF_SEG) { s_rthf_taint = 1; return; }
p_glBeginQuery(GL_TIME_ELAPSED, s_rthf_q[i][s_rthf_nseg[i]++]);
s_rthf_gpu_active = 1;
}
static void gl_rth_idle(void *user) {
(void)user;
int active = s_rthf_gpu_active;
rthf_gpu_pause();
/* Submit the end marker before sleeping; it must reach the GPU now. */
if (active && !s_rthf_gpu_active) glFlush();
}
static void rthf_begin(void) {
if (s_rthf_qok < 0) {
s_rthf_qok = (p_glGenQueries && p_glBeginQuery && p_glEndQuery &&
@@ -11434,6 +11469,7 @@ static void rthf_begin(void) {
if (s_rthf_qok) p_glGenQueries(RTHF_Q * RTHF_SEG, &s_rthf_q[0][0]);
}
s_rthf_open = 1;
s_rthf_gpu_active = 0;
s_rthf_taint = 0;
s_rthf_paused = 0;
s_rthf_excl = 0;
@@ -11444,8 +11480,8 @@ static void rthf_begin(void) {
if (s_rthf_has_q) {
gl_perf_yield(); /* close frame_perf's open bracket, if any */
const unsigned i = s_rthf_head % RTHF_Q;
s_rthf_nseg[i] = 1;
p_glBeginQuery(GL_TIME_ELAPSED, s_rthf_q[i][0]);
s_rthf_nseg[i] = 0;
rthf_gpu_resume();
}
}
@@ -11457,23 +11493,16 @@ static void rthf_pause(void) {
s_rthf_paused = 1;
s_rthf_pause_t0 = host_now_ns_rthf();
s_rthf_pause_swap = s_rthf_swap_ns;
if (s_rthf_has_q) p_glEndQuery(GL_TIME_ELAPSED);
if (s_rthf_has_q && s_rthf_gpu_active) {
p_glEndQuery(GL_TIME_ELAPSED); s_rthf_gpu_active = 0;
}
}
static void rthf_resume(void) {
if (!s_rthf_open || !s_rthf_paused) return;
s_rthf_paused = 0;
s_rthf_excl += host_now_ns_rthf() - s_rthf_pause_t0;
s_rthf_swap_ns = s_rthf_pause_swap; /* the generated frames' swaps */
if (s_rthf_has_q) {
const unsigned i = s_rthf_head % RTHF_Q;
if (s_rthf_nseg[i] < RTHF_SEG) {
p_glBeginQuery(GL_TIME_ELAPSED, s_rthf_q[i][s_rthf_nseg[i]++]);
} else {
/* Out of segments: the rest of the frame goes unmeasured. */
s_rthf_taint = 1;
p_glBeginQuery(GL_TIME_ELAPSED, s_rthf_q[i][RTHF_SEG - 1]);
}
}
rthf_gpu_resume();
}
static void rthf_end(void) {
@@ -11484,7 +11513,8 @@ static void rthf_end(void) {
/* The query pair is still issued so the ring stays in order; the
* frame is not published. */
if (s_rthf_has_q) {
p_glEndQuery(GL_TIME_ELAPSED);
if (s_rthf_gpu_active) p_glEndQuery(GL_TIME_ELAPSED);
s_rthf_gpu_active = 0;
s_rthf_tail = ++s_rthf_head; /* drop it and anything older */
}
atomic_fetch_add(&s_rthf_dropped, 1);
@@ -11498,7 +11528,8 @@ static void rthf_end(void) {
const uint64_t cpu = span > skip ? span - skip : 0;
if (s_rthf_has_q) {
const unsigned i = s_rthf_head % RTHF_Q;
p_glEndQuery(GL_TIME_ELAPSED);
if (s_rthf_gpu_active) p_glEndQuery(GL_TIME_ELAPSED);
s_rthf_gpu_active = 0;
s_rthf_slot_cpu[i] = cpu;
s_rthf_head++;
} else {
@@ -13988,6 +14019,7 @@ static void gl_rth_exec(void *user, const RtCmd *c, const void *payload) {
if (c->op == RTH_FRAME) { rthf_end(); return; }
if (!s_rthf_open && (atomic_load_explicit(&s_rthf_want, memory_order_relaxed) || s_fg_on))
rthf_begin();
rthf_gpu_resume();
if (s_fg_on) fg_capture(c, payload);
switch (c->op) {
case RTH_SEMI: glb_set_semi_transparency(v[0], v[1]); break;
@@ -14134,6 +14166,7 @@ int gl_renderer_render_thread_start(int max_frames) {
cfg.exec = gl_rth_exec;
cfg.ctx = gl_rth_ctx;
cfg.user = NULL;
cfg.idle = gl_rth_idle;
cfg.tick = fg_tick;
fg_invalidate();
(void)pt_begin(); /* [video] present_thread; falls back to direct swaps */
+3
View File
@@ -99,6 +99,7 @@ static struct {
RtCtxFn ctx;
void *user;
RtTickFn tick;
void (*idle)(void *user);
uint64_t tick_at; /* consumer: next tick deadline (0 = none) */
/* shared positions / counters */
@@ -218,6 +219,7 @@ static void *render_main(void *arg)
spun++;
}
if (atomic_load_explicit(&R.wpos, memory_order_acquire) != r) continue;
if (R.idle) R.idle(R.user);
uint64_t t0 = now_ns();
mtx_lock(&R.mtx);
atomic_store(&R.render_sleeping, 1);
@@ -434,6 +436,7 @@ int rt_start(const RtConfig *cfg) {
R.ctx = cfg->ctx;
R.user = cfg->user;
R.tick = cfg->tick;
R.idle = cfg->idle;
R.tick_at = 0;
mtx_init(&R.mtx);
cnd_init(&R.cv_work);
+5
View File
@@ -170,6 +170,11 @@ def main():
print(f"FAIL scale {s} dynres: {k} differs with the render thread on "
f"({runs[0][k]} off, {runs[1][k]} on)")
ok = False
# A paced producer must not turn an inexpensive draw into 30ms GPU work.
r = run([probe, 4, 1, args.frames, "idle"])
print("producer-idle timing:", r.returncode, r.stdout.strip().splitlines()[-8:], r.stderr[-800:])
if r.returncode or parse(r.stdout)["failures"] != 0:
ok = False
print("PASS" if ok else "FAIL")
return 0 if ok else 1
+18
View File
@@ -115,6 +115,7 @@ static uint64_t fnv(const void *pp, size_t n, uint64_t h) {
for (size_t i = 0; i < n; i++) { h ^= p[i]; h *= 0x100000001b3ull; }
return h;
}
static int timing_idle;
static uint64_t rb_digest = 0xcbf29ce484222325ull;
static uint32_t rng = 0x2468ace1u;
static uint32_t rnd(void) { rng ^= rng << 13; rng ^= rng >> 17; rng ^= rng << 5; return rng; }
@@ -235,6 +236,10 @@ static void frame(int f, int buf_x) {
rb_digest = fnv(out, sizeof out, rb_digest);
}
gl_renderer_present_vram(buf_x, 0, FRAME_W, FRAME_H, 0, 0);
if (timing_idle && rt_running()) {
rt_drain();
SDL_Delay(30); /* producer pacing after the rendered image is submitted */
}
gl_renderer_render_thread_frame_boundary();
}
@@ -243,6 +248,7 @@ int main(int argc, char **argv) {
int threaded = argc > 2 && argv[2][0] == '1';
int frames = argc > 3 ? atoi(argv[3]) : 80;
int dynres = argc > 4 && !strcmp(argv[4], "dynres");
timing_idle = argc > 4 && !strcmp(argv[4], "idle");
/* No video device, window or GL context (headless, Windows over SSH):
* exit 77, which the harness reports as a CTest skip. */
if (SDL_Init(SDL_INIT_VIDEO) != 0) {
@@ -310,6 +316,7 @@ int main(int argc, char **argv) {
check(gl_renderer_dynamic_resolution_ceiling() == scale, "dynres ceiling");
if (threaded) gl_renderer_render_thread_measure(1);
}
if (timing_idle && threaded) gl_renderer_render_thread_measure(1);
static const int levels[] = { 2, 1, 3, 1, 4, 2 };
int nsteps = 0, level = scale;
for (int f = 0; f < frames; f++) {
@@ -345,6 +352,17 @@ int main(int argc, char **argv) {
}
}
if (timing_idle && threaded) {
gl_renderer_render_thread_sync("idle timing check");
GlRthCosts co;
gl_renderer_render_thread_costs(&co);
double gpu_ms = co.gpu_frames ? (double)co.gpu_ns / co.gpu_frames * 1e-6 : 0.0;
printf("idle_gpu_ms=%.3f gpu_frames=%llu\n", gpu_ms, (unsigned long long)co.gpu_frames);
check(co.gpu_frames > 0, "idle timing has completed GPU samples");
if (rthf_active_segments())
check(gpu_ms < 15.0, "GPU work excludes the 30ms producer wait");
}
/* Guest-visible VRAM, the frame at internal resolution, the wide surface. */
static uint16_t native[1024 * 512];
gr_vram_transfer_out(0, 0, 1024, 512, native);