cdrom: model read-start latency + far-seek completion delay (MMX5 FMV fix)

Give ReadN/ReadS an initial read delay before the steady-state sector cadence, classify SetLoc as near vs far and drive SeekL/SeekP completion timing off it (the far-seek case PCSX calls out for Rockman X5), and fix GetlocP to report the drive sub-Q position during an active read rather than the last data-ready sector. Previously the CD data-ready cadence was too eager, so the MMX5 intro FMV / CD script never accumulated a valid decode window and the movie player bailed with zero decodes. With faithful read/seek latency the intro cutscene now decodes and plays. debug_server: add a cdrom_command_history TCP command exposing the CD command/seq ring (kind, cmd, params, read MSF, pending/queued state, pc) to back this investigation. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-10-26 02:11:36 -04:00 · 2026-07-04 23:45:49 -07:00
parent 4e6208a6e6
commit db4016b685
2 changed files with 216 additions and 7 deletions
@@ -139,6 +139,7 @@ static uint64_t command_history_seq;
 /* Seek target */
 static uint8_t seek_min, seek_sec, seek_sect;
 static int     s_setloc_lba = -1;  /* LBA captured at SetLoc time */
+static int     setloc_seek_far;

 /* Read state */
 static int reading;
@@ -240,6 +241,7 @@ uint32_t g_cd_overwrite_last_frame = 0;
 * MAX_PER_FRAME knob. */
 #define VBLANK_CYCLES_NTSC          564480   /* 33.8688 MHz / 60 Hz; matches interrupts.c */
 #define CDROM_INSTANT_MAX_PER_FRAME_DEFAULT 32
+#define CDROM_SINGLE_SPEED_SECTOR_CYCLES 451584

 /* Runtime-tunable 'instant' budget (step 3). One knob drives three writers:
 * game.toml [runtime] instant_max_per_frame, the cdrom_instant_rate TCP
@@ -324,7 +326,27 @@ uint32_t cdrom_get_burst_total(void) { return s_burst_count; }
 static int sector_delay_cycles(void) {
    /* PS1 CPU is 33.8688 MHz. CD-ROM sectors arrive at 75 Hz in 1x
     * mode, or twice that rate when SetMode bit 7 enables double speed. */
-    int base = (mode_reg & 0x80) ? 225792 : 451584;
+    int base = (mode_reg & 0x80)
+        ? (CDROM_SINGLE_SPEED_SECTOR_CYCLES / 2)
+        : CDROM_SINGLE_SPEED_SECTOR_CYCLES;
+    return apply_speed(base);
+}
+
+static int initial_read_delay_cycles(void) {
+    /* Beetle/PCSX model an additional read-start latency after ReadN/ReadS.
+     * In double-speed mode the first sector still waits one 1x sector period;
+     * subsequent sectors use the steady-state 2x cadence above. */
+    int base = (mode_reg & 0x80)
+        ? CDROM_SINGLE_SPEED_SECTOR_CYCLES
+        : (CDROM_SINGLE_SPEED_SECTOR_CYCLES * 2);
+    return apply_speed(base);
+}
+
+static int seek_complete_delay_cycles(void) {
+    /* PCSX carries a far-SetLoc seek state and explicitly calls out Rockman X5:
+     * far SeekL/SeekP completes after roughly four 1x sector periods, while a
+     * near/already-settled seek returns quickly. */
+    int base = setloc_seek_far ? (CDROM_SINGLE_SPEED_SECTOR_CYCLES * 4) : 0x800;
    return apply_speed(base);
 }

@@ -871,7 +893,7 @@ static void start_read_stream(uint8_t cmd) {
    read_sec = seek_sec;
    read_sect = seek_sect;
    read_cmd = cmd;
-    read_delay = sector_delay_cycles();
+    read_delay = initial_read_delay_cycles();
    reading = 1;
    stat_reg |= CDSTAT_READ;
    /* ENQUEUE: sector-read stream scheduled (due in read_delay cycles). A
@@ -975,10 +997,14 @@ static void exec_command(uint8_t cmd) {

    case 0x02: /* SetLoc */
        if (param_count >= 3) {
+            int current_lba = (last_sector_lba >= 0)
+                ? last_sector_lba
+                : msf_to_lba(seek_min, seek_sec, seek_sect);
            seek_min = bcd_to_bin(param_fifo[0]);
            seek_sec = bcd_to_bin(param_fifo[1]);
            seek_sect = bcd_to_bin(param_fifo[2]);
            s_setloc_lba = msf_to_lba(seek_min, seek_sec, seek_sect);
+            setloc_seek_far = (abs(current_lba - s_setloc_lba) > 16) ? 1 : 0;
        }
        response_push(stat_reg);
        set_irq(CDIRQ_ACK);
@@ -1083,9 +1109,16 @@ static void exec_command(uint8_t cmd) {
    }

    case 0x11: { /* GetlocP */
-        int lba = (last_sector_lba >= 0)
-            ? last_sector_lba
-            : msf_to_lba(read_min, read_sec, read_sect);
+        int lba;
+        if (reading) {
+            /* GetlocP reports the drive/sub-Q position. During a read the
+             * sector stream has already advanced past the data-ready sector. */
+            lba = msf_to_lba(read_min, read_sec, read_sect);
+        } else if (last_sector_lba >= 0) {
+            lba = last_sector_lba;
+        } else {
+            lba = msf_to_lba(seek_min, seek_sec, seek_sect);
+        }
        int rm, rs, rf;
        int am, as, af;
        lba_to_msf(lba, 0, &rm, &rs, &rf);
@@ -1178,7 +1211,7 @@ static void exec_command(uint8_t cmd) {
        set_irq(CDIRQ_ACK);
        pending.cmd = cmd;   /* 0x15 or 0x16 — completed in process_pending */
        pending.pending = 1;
-        pending.delay = apply_speed(20000);
+        pending.delay = seek_complete_delay_cycles();
        pending.phase = 1;
        break;

@@ -1286,6 +1319,7 @@ static void process_pending(uint32_t cycles) {
    case 0x15: /* SeekL complete */
    case 0x16: /* SeekP complete */
        stat_reg &= ~CDSTAT_SEEK;
+        setloc_seek_far = 0;
        response_push(stat_reg);
        set_irq(CDIRQ_COMPLETE);
        fire_cdrom_irq();
@@ -1411,6 +1445,7 @@ void cdrom_init(const char* cue_path) {
    pending.pending = 0;
    memset(&queued_cmd, 0, sizeof(queued_cmd));
    seek_min = seek_sec = seek_sect = 0;
+    setloc_seek_far = 0;
    cdrom_debug_clear_sector_history();

    if (cue_path) {
@@ -1751,7 +1786,7 @@ int cdrom_load_in_progress(void) {
    X(last_sector_raw_mode) X(last_sector_xa_file) X(last_sector_xa_channel) \
    X(last_sector_xa_submode) X(last_sector_xa_coding) \
    /* seek target */ \
-    X(seek_min) X(seek_sec) X(seek_sect) X(s_setloc_lba) \
+    X(seek_min) X(seek_sec) X(seek_sect) X(s_setloc_lba) X(setloc_seek_far) \
    /* read stream state */ \
    X(reading) X(read_min) X(read_sec) X(read_sect) X(mode_reg) \
    X(read_cmd) X(read_delay) X(filter_file) X(filter_channel) X(cd_muted) \
@@ -4872,6 +4872,91 @@ static void handle_cdrom_sector_history_clear(int id, const char *json)
    send_ok(id);
 }

+static const char *cdrom_command_kind_name(uint8_t kind)
+{
+    switch (kind) {
+    case 'C': return "exec";
+    case 'Q': return "queued";
+    default: return "unknown";
+    }
+}
+
+static void handle_cdrom_command_history(int id, const char *json)
+{
+    int count = json_get_int(json, "count", 128);
+    if (count < 1) count = 1;
+    if (count > CDROM_COMMAND_HISTORY_CAP) count = CDROM_COMMAND_HISTORY_CAP;
+
+    int frame_lo = json_get_int(json, "frame_lo", -1);
+    int frame_hi = json_get_int(json, "frame_hi", -1);
+
+    const CDROMCommandHistoryEntry *entries = NULL;
+    uint64_t total = cdrom_debug_get_command_history(&entries);
+    uint64_t oldest = (total > CDROM_COMMAND_HISTORY_CAP)
+        ? total - CDROM_COMMAND_HISTORY_CAP : 0;
+
+    size_t bufsz = 256u + (size_t)count * 640u;
+    char *buf = (char *)malloc(bufsz);
+    if (!buf) { send_err(id, "oom"); return; }
+
+    size_t pos = 0;
+    int emitted = 0;
+    pos += snprintf(buf + pos, bufsz - pos,
+                    "{\"id\":%d,\"ok\":true,\"total\":%llu,"
+                    "\"oldest\":%llu,\"entries\":[",
+                    id, (unsigned long long)total,
+                    (unsigned long long)oldest);
+
+    uint64_t seq = total;
+    while (seq > oldest && emitted < count && pos < bufsz - 640) {
+        seq--;
+        const CDROMCommandHistoryEntry *e =
+            &entries[seq % CDROM_COMMAND_HISTORY_CAP];
+        if (e->seq != seq) continue;
+        if (frame_lo >= 0 && (int)e->frame < frame_lo) continue;
+        if (frame_hi >= 0 && (int)e->frame > frame_hi) continue;
+
+        pos += snprintf(buf + pos, bufsz - pos,
+                        "%s{\"seq\":%llu,\"frame\":%u,\"kind\":\"%s\","
+                        "\"cmd\":\"0x%02X\",\"param_count\":%u,\"params\":[",
+                        emitted ? "," : "",
+                        (unsigned long long)e->seq, e->frame,
+                        cdrom_command_kind_name(e->kind),
+                        e->cmd, e->param_count);
+        for (uint8_t i = 0; i < e->param_count && i < 16 && pos < bufsz - 96; i++) {
+            pos += snprintf(buf + pos, bufsz - pos,
+                            "%s\"0x%02X\"", i ? "," : "", e->params[i]);
+        }
+        pos += snprintf(buf + pos, bufsz - pos,
+                        "],\"stat\":\"0x%02X\",\"request\":\"0x%02X\","
+                        "\"irq_enable\":\"0x%02X\",\"irq_flag\":\"0x%02X\","
+                        "\"mode\":\"0x%02X\",\"seek_msf\":[%u,%u,%u],"
+                        "\"read_msf\":[%u,%u,%u],\"read_cmd\":\"0x%02X\","
+                        "\"reading\":%u,\"pending_cmd\":\"0x%02X\","
+                        "\"pending\":%u,\"queued_cmd\":\"0x%02X\","
+                        "\"queued\":%u,\"func\":\"0x%08X\",\"pc\":\"0x%08X\","
+                        "\"i_stat\":\"0x%08X\"}",
+                        e->stat, e->request, e->irq_enable, e->irq_flag,
+                        e->mode, e->seek_min, e->seek_sec, e->seek_sect,
+                        e->read_min, e->read_sec, e->read_sect, e->read_cmd,
+                        e->reading, e->pending_cmd, e->pending_pending,
+                        e->queued_cmd, e->queued_pending, e->func, e->pc,
+                        e->i_stat);
+        emitted++;
+    }
+
+    pos += snprintf(buf + pos, bufsz - pos, "],\"emitted\":%d}", emitted);
+    debug_server_send_line(buf);
+    free(buf);
+}
+
+static void handle_cdrom_command_history_clear(int id, const char *json)
+{
+    (void)json;
+    cdrom_debug_clear_command_history();
+    send_ok(id);
+}
+
 static void handle_cdrom_trace_clear(int id, const char *json)
 {
    (void)json;
@@ -4885,6 +4970,9 @@ static void handle_cdrom_trace_dump(int id, const char *json)
    if (count < 1) count = 1;
    if (count > CDROM_TRACE_CAP) count = CDROM_TRACE_CAP;

+    int frame_lo = json_get_int(json, "frame_lo", -1);
+    int frame_hi = json_get_int(json, "frame_hi", -1);
+
    const CDROMTraceEntry *entries = NULL;
    uint64_t total = cdrom_debug_get_trace(&entries);
    uint64_t oldest = (total > CDROM_TRACE_CAP) ? total - CDROM_TRACE_CAP : 0;
@@ -4903,6 +4991,8 @@ static void handle_cdrom_trace_dump(int id, const char *json)
    for (uint64_t seq = start; seq < total && pos < bufsz - 400; seq++) {
        const CDROMTraceEntry *e = &entries[seq % CDROM_TRACE_CAP];
        if (e->seq != seq) continue;
+        if (frame_lo >= 0 && (int)e->frame < frame_lo) continue;
+        if (frame_hi >= 0 && (int)e->frame > frame_hi) continue;
        pos += snprintf(buf + pos, bufsz - pos,
                        "%s{\"seq\":%llu,\"kind\":\"%s\",\"addr\":\"0x%08X\","
                        "\"val\":\"0x%08X\",\"w\":%u,\"func\":\"0x%08X\","
@@ -4939,6 +5029,7 @@ static const char *dma_trace_kind_name(uint32_t kind)
    switch (kind) {
    case 'S': return "start";
    case 'C': return "complete";
+    case 'W': return "write";
    default: return "unknown";
    }
 }
@@ -5023,6 +5114,86 @@ static void handle_dma_trace_dump(int id, const char *json)
    free(buf);
 }

+static void append_word_array(char *buf, size_t bufsz, size_t *pos,
+                              const uint32_t *words, int count)
+{
+    *pos += snprintf(buf + *pos, bufsz - *pos, "[");
+    for (int i = 0; i < count && *pos < bufsz - 16; i++) {
+        *pos += snprintf(buf + *pos, bufsz - *pos,
+                         "%s\"0x%08X\"", i ? "," : "", words[i]);
+    }
+    *pos += snprintf(buf + *pos, bufsz - *pos, "]");
+}
+
+static void handle_dma_cdrom_history(int id, const char *json)
+{
+    int count = json_get_int(json, "count", 256);
+    if (count < 1) count = 1;
+    if (count > DMA_CDROM_HISTORY_CAP) count = DMA_CDROM_HISTORY_CAP;
+
+    int frame_lo = json_get_int(json, "frame_lo", -1);
+    int frame_hi = json_get_int(json, "frame_hi", -1);
+    int newest = json_get_int(json, "newest", 0) != 0;
+
+    const DMACDROMHistoryEntry *entries = NULL;
+    uint64_t total = dma_debug_get_cdrom_history(&entries);
+    uint64_t oldest = (total > DMA_CDROM_HISTORY_CAP) ? total - DMA_CDROM_HISTORY_CAP : 0;
+
+    size_t bufsz = 256u + (size_t)count * 1152u;
+    char *buf = (char *)malloc(bufsz);
+    if (!buf) { send_err(id, "oom"); return; }
+
+    size_t pos = 0;
+    int emitted = 0;
+    pos += snprintf(buf + pos, bufsz - pos,
+                    "{\"id\":%d,\"ok\":true,\"total\":%llu,\"oldest\":%llu,\"entries\":[",
+                    id, (unsigned long long)total, (unsigned long long)oldest);
+
+    uint64_t start = newest && total > (uint64_t)count ? total - (uint64_t)count : oldest;
+    if (start < oldest) start = oldest;
+    for (uint64_t seq = start; seq < total && emitted < count && pos < bufsz - 1152; seq++) {
+        const DMACDROMHistoryEntry *e = &entries[seq % DMA_CDROM_HISTORY_CAP];
+        if (e->seq != seq) continue;
+        if (frame_lo >= 0 && (int)e->frame_start < frame_lo) continue;
+        if (frame_hi >= 0 && (int)e->frame_start > frame_hi) continue;
+
+        pos += snprintf(buf + pos, bufsz - pos,
+                        "%s{\"seq\":%llu,\"frame_start\":%u,\"frame_end\":%u,"
+                        "\"start_addr\":\"0x%08X\",\"final_addr\":\"0x%08X\","
+                        "\"requested_words\":%u,\"moved_words\":%u,"
+                        "\"bcr\":\"0x%08X\",\"chcr\":\"0x%08X\",\"dpcr\":\"0x%08X\","
+                        "\"dicr_start\":\"0x%08X\",\"dicr_end\":\"0x%08X\","
+                        "\"i_stat_start\":\"0x%08X\",\"i_stat_end\":\"0x%08X\","
+                        "\"func\":\"0x%08X\",\"pc\":\"0x%08X\","
+                        "\"lba\":%d,\"sector_size\":%d,"
+                        "\"sector_read_pos_start\":%d,\"sector_read_pos_end\":%d,"
+                        "\"mode\":\"0x%02X\",\"sector_available_start\":%u,"
+                        "\"sector_available_end\":%u,\"completed\":%u,"
+                        "\"first_words\":",
+                        emitted ? "," : "",
+                        (unsigned long long)e->seq, e->frame_start, e->frame_end,
+                        e->start_addr, e->final_addr,
+                        e->requested_words, e->moved_words,
+                        e->bcr, e->chcr, e->dpcr,
+                        e->dicr_start, e->dicr_end,
+                        e->i_stat_start, e->i_stat_end,
+                        e->func, e->pc,
+                        e->lba, e->sector_size,
+                        e->sector_read_pos_start, e->sector_read_pos_end,
+                        e->mode, e->sector_available_start,
+                        e->sector_available_end, e->completed);
+        append_word_array(buf, bufsz, &pos, e->first_words, e->first_count);
+        pos += snprintf(buf + pos, bufsz - pos, ",\"last_words\":");
+        append_word_array(buf, bufsz, &pos, e->last_words, e->last_count);
+        pos += snprintf(buf + pos, bufsz - pos, "}");
+        emitted++;
+    }
+
+    pos += snprintf(buf + pos, bufsz - pos, "],\"emitted\":%d}", emitted);
+    debug_server_send_line(buf);
+    free(buf);
+}
+
 extern uint32_t gpu_get_opcode_count(uint8_t op);

 extern int gpu_get_a0_count(void);
@@ -10861,11 +11032,14 @@ static const CmdEntry s_commands[] = {
    { "cdrom_sector_dump", handle_cdrom_sector_dump },
    { "cdrom_sector_history", handle_cdrom_sector_history },
    { "cdrom_sector_history_clear", handle_cdrom_sector_history_clear },
+    { "cdrom_command_history", handle_cdrom_command_history },
+    { "cdrom_command_history_clear", handle_cdrom_command_history_clear },
    { "cdrom_trace_dump",  handle_cdrom_trace_dump },
    { "cdrom_trace_clear", handle_cdrom_trace_clear },
    { "dma_state",         handle_dma_state },
    { "dma_trace_dump",    handle_dma_trace_dump },
    { "dma_trace_clear",   handle_dma_trace_clear },
+    { "dma_cdrom_history", handle_dma_cdrom_history },
    { "sio_state",         handle_sio_state },
    { "mc_status",         handle_mc_status },
    { "spu_status",        handle_spu_status },