oracle: CD-command trace hook + live-diff localizes Kula World bug 3

Adds a CD-command trace to psx-beetle (beetle_cdcmd_trace_hook.patch:
callback in cdc.cpp's command dispatch, wired through beetle_libretro.cpp
into cdrom_cmd_dump / cdrom_cmd_reset on the oracle debug server). This is
the two-process oracle-diff the setup is built for, now working on Linux.

Live-diff result (docs/kula-world-findings.md, bug 3): the oracle's game
reads level data with a clean Setloc->SeekL->Setmode->ReadN->Pause per
sector (SeekL x18, ReadN x22, GetlocL x89). Our runtime's game, in the
wedge, issues NEITHER SeekL NOR ReadN — only GetStat/Init/Setloc/Pause,
an error/retry branch the oracle never enters.

Crucial: our runtime DID deliver 307 sectors during early boot (ReadN +
data delivery work). Reads only stop at frame ~890 — the BIOS mid-game
region revalidation (ReadTOC+GetID). The region fix made that PASS, but
the post-ReadTOC CD state still stops the game resuming reads. Prime
suspect: our ReadTOC (case 0x1E) is a bare stat+COMPLETE stub that does
not model drive repositioning / the track table the game reads to
recompute its seek. Documented for the next session.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01BdjxoRB1f9VQsNzZayCgGS

docs/beetle-linux.md

@@ -18,8 +18,13 @@ cd beetle-psx
 git checkout 5759277b          # "audit pass" — last C++-tree base we target
 patch -p1 < ../docs/beetle_wtrace_hook.patch
 patch -p1 < ../docs/beetle_sio_trace_hook.patch
+patch -p1 < ../docs/beetle_cdcmd_trace_hook.patch
 ```
 
+`beetle_cdcmd_trace_hook.patch` adds a CD-command trace callback (fires per
+command dispatch in cdc.cpp) exposed as the `cdrom_cmd_dump` / `cdrom_cmd_reset`
+debug commands — used to oracle-diff the Kula World CD read sequence.
+
 `beetle_sio_trace_hook.patch` adds `FrontIO::SetSIOTraceCallback` (fires per
 completed SIO byte exchange) — an integration hook beetle_libretro.cpp needs
 that predated the committed wtrace patch.

docs/beetle_cdcmd_trace_hook.patch

@@ -0,0 +1,82 @@
+diff --git a/libretro.cpp b/libretro.cpp
+index d2e82bca..e9c867c8 100644
+--- a/libretro.cpp
++++ b/libretro.cpp
+@@ -508,6 +508,11 @@ PS_SPU *PSX_SPU = NULL;
+ PS_CDC *PSX_CDC = NULL;
+ FrontIO *PSX_FIO = NULL;
+ 
++/* PSXRecomp oracle hooks: NULL when no listener attached. */
++psxrecomp_wtrace_cb_t  g_psxrecomp_wtrace_cb  = NULL;
++psxrecomp_fntrace_cb_t g_psxrecomp_fntrace_cb = NULL;
++psxrecomp_cdcmd_cb_t   g_psxrecomp_cdcmd_cb   = NULL;
++
+ MultiAccessSizeMem<512 * 1024, uint32, false> *BIOSROM = NULL;
+ MultiAccessSizeMem<65536, uint32, false> *PIOMem = NULL;
+ MultiAccessSizeMem<2048 * 1024, uint32, false> *MainRAM = NULL;
+diff --git a/mednafen/psx/cdc.cpp b/mednafen/psx/cdc.cpp
+index 1daaa5b7..d62c7ee9 100644
+--- a/mednafen/psx/cdc.cpp
++++ b/mednafen/psx/cdc.cpp
+@@ -1318,6 +1318,12 @@ int32_t PS_CDC::Update(const int32_t timestamp)
+                      else
+                      {
+                         const CDC_CTEntry *command = &Commands[PendingCommand];
++                        /* PSXRecomp oracle hook: CD command about to execute. */
++                        if(MDFN_UNLIKELY(g_psxrecomp_cdcmd_cb))
++                           g_psxrecomp_cdcmd_cb(PendingCommand, ArgsReceiveIn,
++                                                ArgsReceiveIn > 0 ? ArgsReceiveBuf[0] : 0,
++                                                ArgsReceiveIn > 1 ? ArgsReceiveBuf[1] : 0,
++                                                ArgsReceiveIn > 2 ? ArgsReceiveBuf[2] : 0);
+                         next_time = (this->*(command->func))(ArgsReceiveIn, ArgsReceiveBuf);
+                         PendingCommandPhase = 2;
+                      }
+diff --git a/mednafen/psx/psx.h b/mednafen/psx/psx.h
+index 704c0a19..d9538c13 100644
+--- a/mednafen/psx/psx.h
++++ b/mednafen/psx/psx.h
+@@ -137,4 +137,44 @@ extern unsigned psx_gpu_overclock_shift;
+ extern uint8_t analog_combo[2];
+ extern uint8_t analog_combo_hold;
+ 
++/* PSXRecomp oracle: SIO byte trace callback.
++ * Fired by FrontIO when a complete byte exchange finishes. */
++class FrontIO;
++extern FrontIO *PSX_FIO;
++typedef void (*psxrecomp_sio_trace_cb_t)(uint8_t tx, uint8_t rx, uint16_t ctrl);
++
++/* PSXRecomp oracle: RAM write trace callback.
++ * Fired by PS_CPU::SB/SH/SW after the write completes.
++ *   addr  = virtual address (caller masks for physical filter)
++ *   value = stored value (sized by `size`)
++ *   pc    = PC of the executing store instruction
++ *   ra    = $ra (GPR[31]) at time of store, for one frame of caller context
++ *   size  = 1, 2, or 4 (byte / halfword / word) */
++typedef void (*psxrecomp_wtrace_cb_t)(uint32_t addr, uint32_t value,
++                                       uint32_t pc, uint32_t ra, uint8_t size);
++extern psxrecomp_wtrace_cb_t g_psxrecomp_wtrace_cb;
++
++/* PSXRecomp oracle: function-call (JAL/JALR/J/JR) trace callback.
++ * Fired by PS_CPU on every J/JAL/JR/JALR retire, BEFORE the link write.
++ * Caller filters by target_pc to keep volume bounded.
++ *   caller_pc = PC of the J/JAL/JR/JALR instruction
++ *   target_pc = computed branch target
++ *   parent_ra = GPR[31] at time of call (parent's return address)
++ *   a0, a1    = argument registers at time of call
++ *   kind      = 1=J, 2=JAL, 3=JR, 4=JALR */
++typedef void (*psxrecomp_fntrace_cb_t)(uint32_t caller_pc, uint32_t target_pc,
++                                        uint32_t parent_ra, uint32_t a0,
++                                        uint32_t a1, uint8_t kind);
++extern psxrecomp_fntrace_cb_t g_psxrecomp_fntrace_cb;
++
++/* PSXRecomp oracle: CD command trace callback.
++ * Fired by PS_CDC just before a command handler executes.
++ *   cmd   = command byte (0x01 GetStat, 0x02 Setloc, 0x06 ReadN, 0x09 Pause,
++ *           0x0A Init, 0x0E Setmode, 0x15 SeekL, 0x1A GetID, 0x1B ReadS, ...)
++ *   nargs = number of argument bytes
++ *   arg0..arg2 = first three argument bytes (0 if absent) */
++typedef void (*psxrecomp_cdcmd_cb_t)(uint8_t cmd, uint8_t nargs,
++                                      uint8_t arg0, uint8_t arg1, uint8_t arg2);
++extern psxrecomp_cdcmd_cb_t g_psxrecomp_cdcmd_cb;
++
+ #endif

docs/kula-world-findings.md

@@ -69,19 +69,37 @@ The 2.5 s cadence is the tell: that is a retry-with-timeout, i.e. the game
 issues a command, waits ~2.5 s for a completion signal, times out, retries.
 The signal it waits for is what our controller/IRQ path delivers wrong.
 
-Next investigation options:
-  1. Live oracle-diff: rebuild psx-beetle WITH a CD-command trace hook
-     (mirror the SIO hook in beetle_sio_trace_hook.patch — add a callback
-     in cdc.cpp's command dispatch), boot it, and compare the boot->demo
-     CD command/IRQ sequence. Does the oracle's game issue the same
-     GetStat/Init loop and then proceed? What completion event breaks it
-     out that ours doesn't?
-  2. Game-side: find the CD-init state machine (caller of the command-issue
-     func_800639C8) and its "init complete" branch condition — which RAM
-     flag it polls, and which ISR path (game CD IRQ handler) is supposed to
-     set it. Then check our INT2-COMPLETE delivery for that command against
-     it (timing of present_cdrom_irq vs the game reading the response).
-  Suspicion: the second INT (INT2 COMPLETE) for Init/Pause is delivered but
-  the game's ISR misses latching its done-flag — a delivery-timing race in
-  present_cdrom_irq's generation latch, the same machinery bug 2's SeekL
-  fix (c146b95) touched.
+### Oracle-diff result (DONE — divergence localized)
+
+Built a CD-command trace hook into psx-beetle (beetle_cdcmd_trace_hook.patch:
+a callback in cdc.cpp's command dispatch + `cdrom_cmd_dump` / `cdrom_cmd_reset`
+debug commands on the oracle) and captured its boot->demo CD command stream.
+
+The oracle's game reads level data with a clean per-sector pattern:
+    Setloc(LBA) -> SeekL -> Setmode(0x80) -> ReadN -> Pause   (x22 ReadN)
+plus GetlocL (0x10) position polling (x89). It issues SeekL 18x and ReadN 22x.
+
+Our runtime's game, in the wedge window, issues **NEITHER SeekL NOR ReadN** —
+only GetStat/Init/Setloc/Pause. So our game took an error/retry branch the
+oracle never enters.
+
+CRUCIAL timeline fact: our runtime DID deliver 307 sectors successfully during
+early boot (so ReadN + sector-data delivery WORK). Reading only stops at
+frame ~890 — the moment the BIOS does its mid-game region revalidation
+(ReadTOC + GetID). After that revalidation the game can never resume reading;
+it drops into the GetStat/Init/Setloc/Pause retry loop and stays there.
+
+So the root cause is narrowed to: the BIOS ReadTOC+GetID revalidation (or the
+CD-controller state it leaves behind — drive repositioned to lead-in / TOC,
+stat/mode reset) prevents the game's CD driver from resuming reads. The region
+fix got the revalidation to PASS, but the post-revalidation CD state still
+breaks the resume. The oracle does not perform this mid-game revalidation in
+the same way, so it reads continuously.
+
+Next: diff the CD-controller state (stat, mode, position, motor/seek bits)
+immediately AFTER ReadTOC completes, ours vs the oracle. Check whether our
+ReadTOC leaves stat/position where the game's resume-read expects it, and
+whether the game's post-revalidation Setloc/SeekL is being answered such that
+it can re-enter the read state. Prime suspect: our ReadTOC (case 0x1E) is a
+bare stat+COMPLETE stub — it does not model the drive repositioning / the
+GetTN/GetTD track table the game may read next to recompute where to seek.

runtime/src/beetle_debug_server.c

@@ -53,6 +53,14 @@ extern uint32_t beetle_get_sio_trace(uint32_t *out_seq, uint8_t *out_tx,
 extern uint32_t beetle_get_sio_trace_total(void);
 extern void     beetle_reset_sio_trace(void);
 
+/* CD command trace */
+extern uint32_t beetle_get_cdcmd_trace(uint32_t *out_seq, uint8_t *out_cmd,
+                                       uint8_t *out_nargs, uint8_t *out_a0,
+                                       uint8_t *out_a1, uint8_t *out_a2,
+                                       int max_count);
+extern uint32_t beetle_get_cdcmd_trace_total(void);
+extern void     beetle_reset_cdcmd_trace(void);
+
 /* wtrace */
 extern int      beetle_wtrace_arm(uint32_t lo, uint32_t hi);
 extern int      beetle_wtrace_disarm(int slot);
@@ -379,6 +387,39 @@ static void h_sio_trace(int id, const char *json) {
     free(seqs); free(txs); free(rxs); free(ctrl);
 }
 
+static void h_cdrom_cmd_dump(int id, const char *json) {
+    int count = json_get_int(json, "count", 256);
+    if (count < 1) count = 1;
+    if (count > 8192) count = 8192;
+
+    uint32_t *seqs = (uint32_t*)malloc(count * sizeof(uint32_t));
+    uint8_t *cmds = (uint8_t*)malloc(count), *nargs = (uint8_t*)malloc(count);
+    uint8_t *a0 = (uint8_t*)malloc(count), *a1 = (uint8_t*)malloc(count), *a2 = (uint8_t*)malloc(count);
+    if (!seqs || !cmds || !nargs || !a0 || !a1 || !a2) {
+        free(seqs); free(cmds); free(nargs); free(a0); free(a1); free(a2);
+        send_err(id, "alloc"); return;
+    }
+    uint32_t got = beetle_get_cdcmd_trace(seqs, cmds, nargs, a0, a1, a2, count);
+    uint32_t total = beetle_get_cdcmd_trace_total();
+
+    send_fmt("{\"id\":%d,\"ok\":true,\"total\":%u,\"count\":%u,\"entries\":[",
+             id, total, got);
+    for (uint32_t i = 0; i < got; i++) {
+        if (i > 0) send_fmt(",");
+        send_fmt("{\"seq\":%u,\"cmd\":\"0x%02X\",\"nargs\":%u,"
+                 "\"a0\":\"0x%02X\",\"a1\":\"0x%02X\",\"a2\":\"0x%02X\"}",
+                 seqs[i], cmds[i], nargs[i], a0[i], a1[i], a2[i]);
+    }
+    send_fmt("]}\n");
+    free(seqs); free(cmds); free(nargs); free(a0); free(a1); free(a2);
+}
+
+static void h_cdrom_cmd_reset(int id, const char *json) {
+    (void)json;
+    beetle_reset_cdcmd_trace();
+    send_ok(id);
+}
+
 static void h_sio_write_window(int id, const char *json) {
     int which = json_get_int(json, "which", 0);
     int before = json_get_int(json, "before", 4);
@@ -1089,6 +1130,8 @@ static const CmdEntry CMDS[] = {
     { "screenshot_file",       h_screenshot_file },  /* alias */
     { "sio_trace_reset",       h_sio_trace_reset },
     { "sio_trace",             h_sio_trace },
+    { "cdrom_cmd_dump",        h_cdrom_cmd_dump },
+    { "cdrom_cmd_reset",       h_cdrom_cmd_reset },
     { "sio_write_window",      h_sio_write_window },
     /* wtrace — normalized verb set (parity contract with psx-runtime). */
     { "wtrace_arm",            h_wtrace_arm },

runtime/src/beetle_libretro.cpp

@@ -56,6 +56,22 @@ static void sio_trace_callback(uint8_t tx, uint8_t rx, uint16_t ctrl) {
     s_sio_trace_idx = (s_sio_trace_idx + 1) % BEETLE_SIO_TRACE_CAP;
 }
 
+/* ---- CD command trace (oracle-diff for the Kula World CD-init wedge) ---- */
+#define BEETLE_CDCMD_TRACE_CAP 8192
+struct BeetleCdcmdEntry {
+    uint32_t seq; uint8_t cmd, nargs, a0, a1, a2;
+};
+static BeetleCdcmdEntry s_cdcmd_trace[BEETLE_CDCMD_TRACE_CAP];
+static int      s_cdcmd_idx = 0;
+static uint32_t s_cdcmd_seq = 0;
+static void cdcmd_trace_callback(uint8_t cmd, uint8_t nargs,
+                                 uint8_t a0, uint8_t a1, uint8_t a2) {
+    BeetleCdcmdEntry *e = &s_cdcmd_trace[s_cdcmd_idx];
+    e->seq = s_cdcmd_seq++; e->cmd = cmd; e->nargs = nargs;
+    e->a0 = a0; e->a1 = a1; e->a2 = a2;
+    s_cdcmd_idx = (s_cdcmd_idx + 1) % BEETLE_CDCMD_TRACE_CAP;
+}
+
 /* ---- wtrace_all ring (ALWAYS-ON; no filter; captures every write) ----
  * Per global rule "ring buffers always-on": every write hits this ring
  * unconditionally so probes connected late can still query the last ~1s
@@ -434,7 +450,8 @@ extern "C" int beetle_init_with_disc(const char *bios_path, const char *disc_pat
 
     g_psxrecomp_wtrace_cb = wtrace_callback;
     g_psxrecomp_fntrace_cb = fntrace_callback;
-    std::fprintf(stderr, "[psx-beetle] wtrace + fntrace callbacks registered\n");
+    g_psxrecomp_cdcmd_cb = cdcmd_trace_callback;
+    std::fprintf(stderr, "[psx-beetle] wtrace + fntrace + cdcmd callbacks registered\n");
     std::fflush(stderr);
 
     return 0;
@@ -553,6 +570,34 @@ extern "C" void beetle_reset_sio_trace(void) {
     memset(s_sio_trace, 0, sizeof(s_sio_trace));
 }
 
+/* ---- CD command trace accessors ---- */
+extern "C" uint32_t beetle_get_cdcmd_trace(uint32_t *out_seq, uint8_t *out_cmd,
+                                           uint8_t *out_nargs, uint8_t *out_a0,
+                                           uint8_t *out_a1, uint8_t *out_a2,
+                                           int max_count)
+{
+    int avail = (int)(s_cdcmd_seq < (uint32_t)BEETLE_CDCMD_TRACE_CAP
+                      ? s_cdcmd_seq : BEETLE_CDCMD_TRACE_CAP);
+    int count = max_count < avail ? max_count : avail;
+    int start = (s_cdcmd_idx - count + BEETLE_CDCMD_TRACE_CAP) % BEETLE_CDCMD_TRACE_CAP;
+    for (int i = 0; i < count; i++) {
+        const BeetleCdcmdEntry *e = &s_cdcmd_trace[(start + i) % BEETLE_CDCMD_TRACE_CAP];
+        out_seq[i]   = e->seq;
+        out_cmd[i]   = e->cmd;
+        out_nargs[i] = e->nargs;
+        out_a0[i]    = e->a0;
+        out_a1[i]    = e->a1;
+        out_a2[i]    = e->a2;
+    }
+    return (uint32_t)count;
+}
+extern "C" uint32_t beetle_get_cdcmd_trace_total(void) { return s_cdcmd_seq; }
+extern "C" void beetle_reset_cdcmd_trace(void) {
+    s_cdcmd_idx = 0;
+    s_cdcmd_seq = 0;
+    memset(s_cdcmd_trace, 0, sizeof(s_cdcmd_trace));
+}
+
 /* ---- wtrace accessors ---- */
 extern "C" int beetle_wtrace_arm(uint32_t lo, uint32_t hi) {
     if (s_wtrace_range_count >= BEETLE_WTRACE_MAX_RANGES) return -1;