mirror/psxrecomp
1
0
Fork 0
mirror of https://github.com/RetroPortingToolKit/psxrecomp synced 2026-10-26 02:11:36 -04:00
Code Issues Packages Projects Releases Wiki Activity

observability: always-on production rings + halt-and-serve on opted-in listener

Browse Source 
Landed while root-causing the Tomba 2 warm-cache boot death; each of these
was a hole that blocked attribution on the production binary:

- psx_fatal_halt: halt-and-serve is now keyed on the TCP listener being
  live (debug_server_get_status) instead of the build flavor. A production
  run with PSX_DEBUG_SERVER=1 + PSX_EXIT_HALT=1 now stays inspectable at
  the fatal instead of exit(1)ing the evidence away.
- debug_server_get_status: was declared in debug_server.h but never
  implemented; implemented (listener state, port, saved socket error).
- event_ring: EVENT_RING_ENABLED=1 unconditionally. The ring records
  edges only; its production disable predated the production listener and
  contradicted its own ALWAYS-ON design note.
- sp_ring (new): stack-domain (64 KB) transition ring at fntrace_record --
  one entry per dispatch whose guest SP crossed a domain, i.e. the
  provenance record for 'who installed this stack pointer'.
- disp_ring (new): 128-entry unconditional dispatch tail (target/ra/sp/
  cycle) so the final control-flow sequence before a death is always
  reconstructable post-mortem.
- overlay_loader: the native-call ring (overlay_native_ring recent[]) is
  now recorded in production too -- each entry names the requested PC and
  the claiming candidate CRC, which is what finally attributed the
  wrong-variant native run.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
This commit is contained in:
Matthew Stanley
2026-07-20 00:06:51 -07:00
parent eb3474c8ac
commit 6e2a36c4c8
6 changed files with 196 additions and 34 deletions
Download Patch File Download Diff File Expand all files Collapse all files
runtime/include/event_ring.h
+7 -8
View File
@@ -28,17 +28,16 @@
extern "C" {
#endif
/* The event ring is a dev diagnostic: it is only readable over the TCP
* debug server, which production builds strip (PSX_NO_DEBUG_TOOLS). It is
* not part of the freeze dump, so recording in production is pure
* hot-path cost — disable it there. */
/* ALWAYS-ON in every build, production included. The ring records EDGES
* (IRQ decisions, I_STAT raises, DMA/CD/timer schedule+fire), not per-poll
* samples, so the hot-path cost is a handful of stores per device event.
* The TCP debug server is compiled into every build too (production runs
* opt the listener in via PSX_DEBUG_SERVER=1), so the ring is readable on
* the exact production binary that exhibits a bug — the Tomba 2 lost
* CD-completion race was only attributable because of this. */
#ifndef EVENT_RING_ENABLED
#ifdef PSX_NO_DEBUG_TOOLS
#define EVENT_RING_ENABLED 0
#else
#define EVENT_RING_ENABLED 1
#endif
#endif
/* 64K entries * 48 bytes ~= 3 MB. Covers many frames of transition activity. */
#define EVENT_RING_CAP (1u << 16)
runtime/include/fntrace.h
+34
View File
@@ -47,6 +47,40 @@ typedef struct {
extern FntraceEntry g_fntrace_ring[FNTRACE_RING_CAP];
extern uint64_t g_fntrace_seq; /* monotonic; index into ring = seq % CAP */
/* ── Stack-domain transition ring (ALWAYS-ON, every build) ──────────────────
* One entry per dispatch whose guest SP crossed a 64 KB domain since the
* previous dispatch. Quiet in normal execution; fires at genuine stack
* switches (green-thread/coroutine restores, longjmp, kernel ChangeThread,
* crt0 stack init) — the provenance record for "who installed this SP".
* Dumped via the `sp_ring` TCP command. */
#define SPDOM_RING_CAP 512u
typedef struct {
uint64_t seq;
uint64_t cycle; /* guest cycle at the recording dispatch */
uint32_t prev_sp; /* sp domain execution came FROM */
uint32_t new_sp; /* sp observed at this dispatch */
uint32_t target; /* dispatch target (the code running on the new stack) */
uint32_t ra; /* caller's return PC at the dispatch */
uint32_t tcb; /* kernel current-TCB (PCB[0]) at the dispatch */
uint32_t frame; /* s_frame_count */
} SpDomainEntry;
extern SpDomainEntry g_spdom_ring[SPDOM_RING_CAP];
extern uint64_t g_spdom_seq;
/* Always-on dispatch tail ring: last N dispatches (target/ra/sp/cycle),
* recorded unconditionally so the final control-flow sequence before a death
* is always reconstructable. Dumped via `disp_ring`. */
#define DISP_TAIL_CAP 128u
typedef struct {
uint64_t cycle;
uint32_t target;
uint32_t ra;
uint32_t sp;
uint32_t pad;
} DispTailEntry;
extern DispTailEntry g_disp_tail[DISP_TAIL_CAP];
extern uint64_t g_disp_tail_seq;
/* Hot path. Called from psx_dispatch on every entry. Inlinable. */
void fntrace_record(CPUState* cpu, uint32_t target);
/* Register the game's text range for one-shot game-start detection.
runtime/src/crash_trace.c
+22 -18
View File
@@ -583,28 +583,32 @@ void psx_fatal_halt(const char *reason) {
psx_crash_trace_dump(g_psx_fatal_reason, NULL);
freeze_heartbeat_fatal_dump(g_psx_fatal_reason);
}
#ifndef PSX_NO_DEBUG_TOOLS
/* Halt-and-serve: emulation is dead but the rings are not. Keep the
* TCP debug server pumping on this (main) thread so a post-mortem
* client can run wtrace_dump / read_ram / screenshot / etc. against
* the exact crash state. */
extern void debug_server_poll(void);
fprintf(stderr,
"FATAL: %s — emulation halted; TCP debug server stays live "
"for post-mortem ring queries.\n", g_psx_fatal_reason);
fflush(stderr);
for (;;) {
debug_server_poll();
/* Halt-and-serve: emulation is dead but the rings are not. Keyed to the
* LISTENER being live, not the build flavor — the server is compiled into
* every build and production runs opt it in via PSX_DEBUG_SERVER=1, so a
* fatal on such a run must stay inspectable instead of exit(1)ing the
* evidence away. Without a listener (a player's release run) there is
* nobody to serve; exit so the process doesn't hang invisibly. */
{ int listening = 0, port = 0, err = 0;
extern void debug_server_get_status(int *listening, int *port, int *error);
debug_server_get_status(&listening, &port, &err);
if (!listening) exit(1);
extern void debug_server_poll(void);
fprintf(stderr,
"FATAL: %s — emulation halted; TCP debug server stays live "
"on port %d for post-mortem ring queries.\n",
g_psx_fatal_reason, port);
fflush(stderr);
for (;;) {
debug_server_poll();
#ifdef _WIN32
Sleep(1);
Sleep(1);
#else
struct timespec req = {0, 1000000};
nanosleep(&req, NULL);
struct timespec req = {0, 1000000};
nanosleep(&req, NULL);
#endif
}
}
#else
exit(1);
#endif
}
/* ── Crash handlers ──────────────────────────────────────────────────── */
runtime/src/debug_server.c
+75
View File
@@ -95,6 +95,7 @@ extern void psx_write_byte(uint32_t addr, uint8_t val);
static sock_t s_listen = SOCK_INVALID;
static sock_t s_client = SOCK_INVALID;
static int s_port = DEFAULT_DEBUG_PORT;
static int s_listen_err = 0; /* platform socket error captured by init */
#define RECV_BUF_SIZE 8192
static char s_recv_buf[RECV_BUF_SIZE];
@@ -8767,6 +8768,69 @@ static void handle_irqctx_ring(int id, const char *json)
free(buf);
}
/* sp_ring — dump the always-on stack-domain transition ring (fntrace.c).
* One entry per dispatch whose guest SP crossed a 64 KB domain: the
* provenance record for "who installed this stack pointer". */
static void handle_sp_ring(int id, const char *json)
{
extern SpDomainEntry g_spdom_ring[]; extern uint64_t g_spdom_seq;
int count = json_get_int(json, "count", 64);
if (count < 1) count = 1;
if (count > (int)SPDOM_RING_CAP) count = (int)SPDOM_RING_CAP;
uint64_t total = g_spdom_seq;
uint32_t avail = total < SPDOM_RING_CAP ? (uint32_t)total : SPDOM_RING_CAP;
uint32_t n = (uint32_t)count < avail ? (uint32_t)count : avail;
size_t BUF_SZ = 256u + (size_t)n * 200u;
char *buf = (char *)malloc(BUF_SZ); if (!buf) { send_err(id, "oom"); return; }
size_t pos = 0;
pos += snprintf(buf + pos, BUF_SZ - pos,
"{\"id\":%d,\"ok\":true,\"total\":%llu,\"entries\":[",
id, (unsigned long long)total);
for (uint32_t i = 0; i < n && pos < BUF_SZ - 256; i++) {
uint64_t idx = total - n + i;
SpDomainEntry *e = &g_spdom_ring[idx % SPDOM_RING_CAP];
pos += snprintf(buf + pos, BUF_SZ - pos,
"%s{\"seq\":%llu,\"cycle\":%llu,\"frame\":%u,"
"\"prev_sp\":\"0x%08X\",\"new_sp\":\"0x%08X\","
"\"target\":\"0x%08X\",\"ra\":\"0x%08X\",\"tcb\":\"0x%08X\"}",
i ? "," : "", (unsigned long long)e->seq, (unsigned long long)e->cycle,
e->frame, e->prev_sp, e->new_sp, e->target, e->ra, e->tcb);
}
pos += snprintf(buf + pos, BUF_SZ - pos, "]}");
debug_server_send_line(buf);
free(buf);
}
/* disp_ring — dump the always-on dispatch tail ring (fntrace.c). */
static void handle_disp_ring(int id, const char *json)
{
extern DispTailEntry g_disp_tail[]; extern uint64_t g_disp_tail_seq;
int count = json_get_int(json, "count", 64);
if (count < 1) count = 1;
if (count > (int)DISP_TAIL_CAP) count = (int)DISP_TAIL_CAP;
uint64_t total = g_disp_tail_seq;
uint32_t avail = total < DISP_TAIL_CAP ? (uint32_t)total : DISP_TAIL_CAP;
uint32_t n = (uint32_t)count < avail ? (uint32_t)count : avail;
size_t BUF_SZ = 256u + (size_t)n * 130u;
char *buf = (char *)malloc(BUF_SZ); if (!buf) { send_err(id, "oom"); return; }
size_t pos = 0;
pos += snprintf(buf + pos, BUF_SZ - pos,
"{\"id\":%d,\"ok\":true,\"total\":%llu,\"entries\":[",
id, (unsigned long long)total);
for (uint32_t i = 0; i < n && pos < BUF_SZ - 200; i++) {
uint64_t idx = total - n + i;
DispTailEntry *e = &g_disp_tail[idx % DISP_TAIL_CAP];
pos += snprintf(buf + pos, BUF_SZ - pos,
"%s{\"seq\":%llu,\"cycle\":%llu,\"target\":\"0x%08X\","
"\"ra\":\"0x%08X\",\"sp\":\"0x%08X\"}",
i ? "," : "", (unsigned long long)idx, (unsigned long long)e->cycle,
e->target, e->ra, e->sp);
}
pos += snprintf(buf + pos, BUF_SZ - pos, "]}");
debug_server_send_line(buf);
free(buf);
}
static void handle_freeze_check(int id, const char *json)
{
int window = json_get_int(json, "window", 256);
@@ -12191,6 +12255,8 @@ static const CmdEntry s_commands[] = {
{ "freeze_check", handle_freeze_check },
{ "d44_ring", handle_d44_ring },
{ "irqctx_ring", handle_irqctx_ring },
{ "sp_ring", handle_sp_ring },
{ "disp_ring", handle_disp_ring },
{ "cyc_watch", handle_cyc_watch },
{ "cyc_watch_dump", handle_cyc_watch_dump },
{ "cyc_watch_clear", handle_cyc_watch_clear },
@@ -12394,6 +12460,7 @@ void debug_server_init(int port)
s_listen = socket(AF_INET, SOCK_STREAM, 0);
if (s_listen == SOCK_INVALID) {
s_listen_err = sock_error();
fprintf(stdout, "psxrecomp: debug server socket() FAILED\n");
return;
}
@@ -12408,6 +12475,7 @@ void debug_server_init(int port)
addr.sin_port = htons((uint16_t)s_port);
if (bind(s_listen, (struct sockaddr *)&addr, sizeof(addr)) != 0) {
s_listen_err = sock_error();
fprintf(stdout, "psxrecomp: debug server bind(%d) FAILED\n", s_port);
sock_close(s_listen);
s_listen = SOCK_INVALID;
@@ -12831,6 +12899,13 @@ static int io_thread_main(void *arg)
return 0;
}
void debug_server_get_status(int *listening, int *port, int *error)
{
if (listening) *listening = (s_listen != SOCK_INVALID);
if (port) *port = s_port;
if (error) *error = s_listen_err;
}
void debug_server_poll(void)
{
/* Phase 1.0e-e2 starvation watchdog heartbeat. Refreshes the
runtime/src/fntrace.c
+53
View File
@@ -63,7 +63,60 @@ static inline int armed_match(uint32_t target) {
return 0;
}
/* ── Stack-domain transition ring (ALWAYS-ON, every build) ─────────────────
* Records every dispatch where the guest SP crossed a 64 KB domain since the
* previous dispatch. Ordinary call nesting never moves SP that far, so the
* ring stays quiet except at genuine stack switches: game green-thread /
* coroutine context restores, longjmps, kernel thread changes, and crt0
* stack (re)initialization. Those transitions are exactly the provenance
* question in stack-corruption deaths (Tomba 2 splash→title reload: the
* guest resumed on a stack pointing INTO freshly loaded module code, and
* nothing recorded who installed that SP). Cost: two loads + xor + branch
* per dispatch; entries only on domain edges. Dumped via `sp_ring`. */
SpDomainEntry g_spdom_ring[SPDOM_RING_CAP];
uint64_t g_spdom_seq = 0;
static uint32_t s_spdom_prev_sp = 0;
/* Always-on dispatch tail ring: the last DISP_TAIL_CAP dispatches with
* target/ra/sp/cycle. Unlike the armed fntrace ring this is unconditional —
* sized tiny so the post-mortem question "what was the exact dispatch
* sequence in the final iterations" is always answerable (the Tomba 2
* splash reload loop was invisible without it). Dumped via `disp_ring`. */
DispTailEntry g_disp_tail[DISP_TAIL_CAP];
uint64_t g_disp_tail_seq = 0;
void fntrace_record(CPUState* cpu, uint32_t target) {
{
extern uint64_t psx_get_cycle_count(void);
DispTailEntry *t = &g_disp_tail[g_disp_tail_seq % DISP_TAIL_CAP];
t->target = target;
t->ra = cpu->gpr[31];
t->sp = cpu->gpr[29];
t->cycle = psx_get_cycle_count();
g_disp_tail_seq++;
}
{
uint32_t sp_now = cpu->gpr[29];
if (((sp_now ^ s_spdom_prev_sp) & 0xFFFF0000u) != 0u) {
if (s_spdom_prev_sp != 0u) {
extern uint64_t psx_get_cycle_count(void);
extern uint32_t psx_read_word(uint32_t addr);
SpDomainEntry *e = &g_spdom_ring[g_spdom_seq % SPDOM_RING_CAP];
uint32_t pcb = psx_read_word(0x108u);
e->seq = g_spdom_seq;
e->cycle = psx_get_cycle_count();
e->prev_sp = s_spdom_prev_sp;
e->new_sp = sp_now;
e->target = target;
e->ra = cpu->gpr[31];
e->tcb = pcb ? psx_read_word(pcb & 0x1FFFFFFFu) : 0u;
e->frame = (uint32_t)s_frame_count;
g_spdom_seq++;
}
s_spdom_prev_sp = sp_now;
}
}
/* On-the-fly string translation (framework feature — text_xlate.cpp). The
* generated psx_dispatch_impl calls us at the top of each dispatch iteration
* with cpu->gpr[4..7] holding THIS call's args, BEFORE the target function
runtime/src/overlay_loader.c
+5 -8
View File
@@ -2957,7 +2957,10 @@ retry_candidates:
#endif
}
if (_probe) s_cps_probe_outcome = 2;
#ifndef PSX_NO_DEBUG_TOOLS
/* Native-call ring: ALWAYS-ON (production too). Each entry names
* the requested PC and the candidate CRC that claimed it — the
* only record that can attribute a wrong-variant native run on
* a production binary (Tomba 2 splash reload loop). */
uint32_t slot = s_nring_pos++ & (NRING_CAP - 1u);
s_nring[slot].addr = addr;
s_nring[slot].crc = c->crc_code;
@@ -2966,7 +2969,6 @@ retry_candidates:
s_nring[slot].returned = 0;
uint32_t prev_inprogress = s_native_inprogress;
s_native_inprogress = c->addr;
#endif
s_native_calls_total++;
native_hot_note(c->addr);
if (s_active_depth < (int)(sizeof(s_active_stack) / sizeof(s_active_stack[0])))
@@ -2983,10 +2985,8 @@ retry_candidates:
}
overlay_post_dispatch_irq_pump(cpu);
if (s_active_depth > 0) s_active_depth--;
#ifndef PSX_NO_DEBUG_TOOLS
s_nring[slot].returned = 1;
s_native_inprogress = prev_inprogress;
#endif
if (g_native_bad_entry) { /* foreign interior entry: fail closed to interp */
g_native_bad_entry = 0;
s_disp_native--; s_disp_interp++;
@@ -3098,7 +3098,7 @@ retry_candidates:
/* Record into the always-on ring BEFORE the call; mark in-progress
* so a freeze inside this fn is visible at dump time. */
#ifndef PSX_NO_DEBUG_TOOLS
/* Native-call ring: ALWAYS-ON (see the range-chain site). */
uint32_t slot = s_nring_pos++ & (NRING_CAP - 1u);
s_nring[slot].addr = c->addr;
s_nring[slot].crc = c->crc_code;
@@ -3107,7 +3107,6 @@ retry_candidates:
s_nring[slot].returned = 0;
uint32_t prev_inprogress = s_native_inprogress;
s_native_inprogress = c->addr;
#endif
s_native_calls_total++;
native_hot_note(c->addr);
@@ -3135,10 +3134,8 @@ retry_candidates:
#endif
if (s_active_depth > 0) s_active_depth--;
#ifndef PSX_NO_DEBUG_TOOLS
s_nring[slot].returned = 1;
s_native_inprogress = prev_inprogress; /* restore (nested calls) */
#endif
if (g_native_bad_entry) { /* foreign interior entry: fail closed to interp */
g_native_bad_entry = 0;
s_disp_native--; s_disp_interp++;