Files
psxrecomp/runtime/tests/test_frame_pacing.c
T
Matthew Stanley ffc15219fd fix: Bug B hard freeze — TOCTOU underflow in frame pacing slept ~24.7 days
Root cause (freeze dump 1781046069, addr2line-verified): the wall-clock
pacing loop in sdl_vblank_present read the performance counter twice per
iteration — once in the while-condition, once to compute remaining time.
If the frame deadline was crossed between the two reads (a preemption
window), the unsigned subtraction underflowed, *1000 overflowed, and
SDL_Delay received ~2^64/10^4 ms mod 2^32 ≈ 24.7 days at the standard
10 MHz QPC. The app parks in one SDL_Delay with every counter frozen,
wedged between 'i_stat |= VBLANK' (interrupts.c:286) and exception
delivery — which is why dumps showed i_stat=1 pinned. VBLANK was being
ACK'd every frame right up to the wedge in every dump examined; the
'VBLANK-ACK reentry storm' framing was a symptom misread.

- frame_pacing.c/h: shared race-free pacer (single counter read per
  decision, compare-before-subtract, sleep clamped to one period).
  Both call sites switched: main.cpp sdl_vblank_present and
  beetle_main.cpp. Unit test pins the underflow case.
- Vsync self-heal: the 'recovered storm' dump (1781045865) was 8/8
  main-thread samples inside wglSwapBuffers — NV driver blocking ~1.5s
  per present. After 3 presents >250ms, drop driver vsync (we pace to
  59.94 Hz ourselves). Counters surfaced in the freeze dump.
- Watchdog classifier: 'reentry_storm' threshold (5K/sec) was below the
  healthy baseline (~2K reentry blocks/frame × 30-60 fps), mislabeling
  normal play and host stalls — that label misdirected two prior
  investigations. Now normalized per frame (>20K/frame), plus a new
  slow_frames kind (<5 fps) with multi-sample stack capture.

Verified: test_frame_pacing ALL PASS; live Tomba paced at 59.962 fps
over 20s (single-process measurement).

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
2026-06-09 20:09:25 -07:00

78 lines
3.5 KiB
C

/*
* test_frame_pacing.c — validate the race-free pacing decision function.
*
* Bug B regression test. The old open-coded pacing loop in
* sdl_vblank_present read the performance counter twice: once in the
* while-condition, once to compute remaining time. If the deadline was
* crossed between the two reads, the unsigned subtraction underflowed
* and SDL_Delay received (2^64 - delta_ticks)*1000/freq truncated to
* Uint32 — ~24.7 days at the standard 10 MHz QPC. The replacement,
* frame_pacing_sleep_ms(), takes a SINGLE counter sample and compares
* before subtracting, so the underflow is impossible by construction.
* This test pins that property, including the exact post-deadline
* sample that froze the app.
*
* Build: gcc -I../include -o test_frame_pacing test_frame_pacing.c
* (includes ../src/frame_pacing.c directly with FRAME_PACING_PURE_ONLY,
* which compiles only the SDL-free decision function.)
*/
#include <stdio.h>
#include <stdint.h>
/* Pull in just the pure function — frame_pacing.c guards its SDL parts. */
#define FRAME_PACING_PURE_ONLY 1
#include "../src/frame_pacing.c"
static int failures = 0;
#define CHECK(cond, msg) do { \
if (!(cond)) { printf("FAIL: %s\n", msg); failures++; } \
else { printf("ok: %s\n", msg); } \
} while (0)
int main(void) {
const uint64_t FREQ = 10000000ull; /* standard Win10 QPC: 10 MHz */
const uint64_t PERIOD = (uint64_t)((double)FREQ * (1000.0 / 59.94) / 1000.0);
/* 1. The Bug B scenario: counter sampled just AFTER the deadline
* (old code underflowed here -> ~24.7-day sleep). Must be 0. */
uint64_t deadline = 1000000000ull;
CHECK(frame_pacing_sleep_ms(deadline + 1, deadline, FREQ, PERIOD) == 0,
"now just past deadline sleeps 0 (Bug B underflow case)");
CHECK(frame_pacing_sleep_ms(deadline + 123456789ull, deadline, FREQ, PERIOD) == 0,
"now far past deadline sleeps 0");
CHECK(frame_pacing_sleep_ms(deadline, deadline, FREQ, PERIOD) == 0,
"now exactly at deadline sleeps 0");
/* 2. Normal case: ~10ms remaining -> sleep 9ms (1ms undershoot for spin). */
CHECK(frame_pacing_sleep_ms(deadline - FREQ / 100, deadline, FREQ, PERIOD) == 9,
"10ms remaining sleeps 9ms");
/* 3. Sub-2ms remaining -> 0 (caller spins). */
CHECK(frame_pacing_sleep_ms(deadline - FREQ / 1000, deadline, FREQ, PERIOD) == 0,
"1ms remaining spins (0)");
/* 4. Deadline absurdly far ahead (corrupt/poisoned state) -> clamped to
* one period, never a multi-day sleep. */
uint32_t ms = frame_pacing_sleep_ms(0, UINT64_MAX, FREQ, PERIOD);
CHECK(ms <= (PERIOD * 1000 / FREQ),
"runaway deadline clamped to <= one period");
/* 5. freq == 0 (degenerate platform answer) -> 0, no divide-by-zero. */
CHECK(frame_pacing_sleep_ms(deadline - FREQ / 100, deadline, 0, PERIOD) == 0,
"freq 0 returns 0");
/* 6. Sweep the deadline-crossing window tick by tick: result must be
* monotonically sane and never exceed one period's ms. This is the
* exact window the old TOCTOU race made lethal. */
int sweep_ok = 1;
for (int64_t d = -20; d <= 20; d++) {
uint64_t now = deadline + (uint64_t)d; /* wraps safely for d<0 */
uint32_t v = frame_pacing_sleep_ms(now, deadline, FREQ, PERIOD);
if (v > (PERIOD * 1000 / FREQ) + 1) { sweep_ok = 0; break; }
}
CHECK(sweep_ok, "tick-by-tick sweep across deadline never exceeds one period");
printf(failures ? "FAILED (%d)\n" : "ALL PASS\n", failures);
return failures ? 1 : 0;
}