diff --git a/runtime/include/debug_server.h b/runtime/include/debug_server.h index 54754fe9..3b06f844 100644 --- a/runtime/include/debug_server.h +++ b/runtime/include/debug_server.h @@ -12,6 +12,7 @@ #define PSXRECOMP_V4_DEBUG_SERVER_H #include +#include #include "cpu_state.h" @@ -178,6 +179,27 @@ extern CPUState *debug_cpu_ptr; void debug_server_send_line(const char *json); void debug_server_send_fmt(const char *fmt, ...); +/* ---- Freeze auto-dump accessors ---- + * + * Called from the freeze_heartbeat thread (NOT from TCP). Each function + * writes a JSON array `[entry1,entry2,...]` of the newest `max_count` + * entries from its ring directly to the given FILE*. Caller wraps with + * the field name (e.g. "wtrace_all":[ ... ]). + * + * Thread-safety: best-effort. The heartbeat thread fires these only + * after detecting a main-thread stall, so concurrent writers are rare, + * but a wedged loop that still touches RAM could tear an entry near the + * ring head. Forensic value is in the bulk of older entries which are + * stable. */ +void debug_server_freeze_dump_wtrace_all_json(FILE *f, uint32_t max_count); +void debug_server_freeze_dump_wtrace_json(FILE *f, uint32_t max_count); +void debug_server_freeze_dump_frame_history_json(FILE *f, uint32_t max_count); +void debug_server_freeze_dump_sio_pc_json(FILE *f, uint32_t max_count); +void debug_server_freeze_dump_thread_trace_json(FILE *f, uint32_t max_count); +void debug_server_freeze_dump_restore_trace_json(FILE *f, uint32_t max_count); +void debug_server_freeze_dump_fn_entry_json(FILE *f, uint32_t max_count); +void debug_server_freeze_dump_dirty_block_json(FILE *f, uint32_t max_count); + #ifdef __cplusplus } #endif diff --git a/runtime/runtime.cmake b/runtime/runtime.cmake index 6f713771..5e0ea0e8 100644 --- a/runtime/runtime.cmake +++ b/runtime/runtime.cmake @@ -165,7 +165,7 @@ function(psxrecomp_v4_add_runtime_target target) endif() if(WIN32 OR MINGW) - target_link_libraries(${target} PRIVATE ws2_32) + target_link_libraries(${target} PRIVATE ws2_32 dbghelp) endif() if(MINGW) diff --git a/runtime/src/debug_server.c b/runtime/src/debug_server.c index 1cb5e812..d8779cb5 100644 --- a/runtime/src/debug_server.c +++ b/runtime/src/debug_server.c @@ -163,6 +163,27 @@ static uint32_t s_wtrace_head = 0; static struct { uint32_t lo, hi; } s_wtrace_ranges[WTRACE_MAX_RANGES]; static int s_wtrace_range_count = 0; +/* ---- wtrace_all ring (ALWAYS-ON; no filter; lean fields) ---- + * Parity with psx-beetle's s_wtrace_all. Every recompiled-code write + * to RAM lands here unconditionally, so a probe that connects AFTER + * an event still has ~1 second of context to query without needing + * to have pre-armed a range. Lean record (no register window) keeps + * 262144 * 32 B = 8 MB per backend. */ +#define WRITE_TRACE_ALL_CAP (1 << 18) +typedef struct { + uint64_t seq; + uint32_t addr; + uint32_t new_val; + uint32_t pc; + uint32_t ra; + uint32_t frame; + uint8_t w; + uint8_t pad[3]; +} WriteTraceAllEntry; +static WriteTraceAllEntry *s_wtrace_all = NULL; +static uint64_t s_wtrace_all_seq = 0; +static uint32_t s_wtrace_all_head = 0; + /* Function attribution global — set by psx_dispatch() before each call. */ uint32_t g_debug_current_func_addr = 0; @@ -4368,8 +4389,25 @@ static void wtrace_record(uint32_t phys, uint32_t old_val, uint32_t new_val, uin s_wtrace_head = (s_wtrace_head + 1) % WRITE_TRACE_CAP; } +/* Always-on catch-all recorder. Lean record (no register window). */ +static void wtrace_all_record(uint32_t phys, uint32_t new_val, uint8_t width) +{ + if (!s_wtrace_all) return; + WriteTraceAllEntry *e = &s_wtrace_all[s_wtrace_all_head]; + e->seq = s_wtrace_all_seq++; + e->addr = phys; + e->new_val = new_val; + e->pc = g_debug_last_store_pc; + e->ra = debug_cpu_ptr ? debug_cpu_ptr->gpr[31] : 0; + e->frame = (uint32_t)s_frame_count; + e->w = width; + s_wtrace_all_head = (s_wtrace_all_head + 1) % WRITE_TRACE_ALL_CAP; +} + /* Multi-range check called from memory.c write paths. - * Iterates up to 8 ranges; records if any match. */ + * Iterates up to 8 ranges; records if any match. + * The always-on catch-all ring is recorded UNCONDITIONALLY first so + * late-connecting probes can still see recent writes without arming. */ void debug_server_trace_write_check(uint32_t phys, uint32_t old_val, uint32_t new_val, uint8_t width) { @@ -4377,6 +4415,7 @@ void debug_server_trace_write_check(uint32_t phys, uint32_t old_val, (void)phys; (void)old_val; (void)new_val; (void)width; return; #endif + wtrace_all_record(phys, new_val, width); if (s_wtrace_range_count == 0) return; for (int i = 0; i < s_wtrace_range_count; i++) { if (phys >= s_wtrace_ranges[i].lo && phys < s_wtrace_ranges[i].hi) { @@ -4459,6 +4498,15 @@ static void handle_wtrace_del(int id, const char *json) send_ok(id); } +/* Normalized verb: disarm every range in one shot. Parity with + * psx-beetle's wtrace_disarm_all. */ +static void handle_wtrace_disarm_all(int id, const char *json) +{ + (void)json; + s_wtrace_range_count = 0; + send_ok(id); +} + static void handle_wtrace_ranges(int id, const char *json) { (void)json; @@ -4689,6 +4737,90 @@ static void handle_wtrace_clear(int id, const char *json) send_ok(id); } +/* ---- Always-on catch-all wtrace handlers (parity with psx-beetle) ---- */ + +static void handle_wtrace_all_stats(int id, const char *json) +{ + (void)json; + uint64_t total = s_wtrace_all_seq; + uint64_t oldest = (total <= WRITE_TRACE_ALL_CAP) ? 0 : total - WRITE_TRACE_ALL_CAP; + uint64_t newest = (total > 0) ? total - 1 : 0; + send_fmt("{\"id\":%d,\"ok\":true,\"total\":%llu,\"capacity\":%d," + "\"oldest_seq\":%llu,\"newest_seq\":%llu}", + id, (unsigned long long)total, WRITE_TRACE_ALL_CAP, + (unsigned long long)oldest, (unsigned long long)newest); +} + +static void handle_wtrace_all_reset(int id, const char *json) +{ + (void)json; + s_wtrace_all_seq = 0; + s_wtrace_all_head = 0; + if (s_wtrace_all) + memset(s_wtrace_all, 0, + (size_t)WRITE_TRACE_ALL_CAP * sizeof(WriteTraceAllEntry)); + send_ok(id); +} + +static void handle_wtrace_all_dump(int id, const char *json) +{ + if (!s_wtrace_all) { send_err(id, "wtrace_all not initialized"); return; } + + /* Optional post-hoc address filter (matches wtrace_dump shape). */ + char lo_str[32], hi_str[32]; + uint32_t flo = 0, fhi = 0xFFFFFFFFu; + if (json_get_str(json, "addr_lo", lo_str, sizeof(lo_str))) + flo = hex_to_u32(lo_str) & 0x1FFFFFFFu; + if (json_get_str(json, "addr_hi", hi_str, sizeof(hi_str))) + fhi = hex_to_u32(hi_str) & 0x1FFFFFFFu; + + uint64_t total = s_wtrace_all_seq; + uint32_t avail = (total < WRITE_TRACE_ALL_CAP) + ? (uint32_t)total : WRITE_TRACE_ALL_CAP; + uint32_t start = (total < WRITE_TRACE_ALL_CAP) ? 0 : s_wtrace_all_head; + + int max_out = json_get_int(json, "count", 65536); + if (max_out < 1) max_out = 1; + if (max_out > WRITE_TRACE_ALL_CAP) max_out = WRITE_TRACE_ALL_CAP; + int newest_first = json_get_int(json, "newest", 0) != 0; + + const uint32_t MAX_OUT = (uint32_t)max_out; + size_t BUF_SZ = 256u + (size_t)MAX_OUT * 200u; + if (BUF_SZ > (size_t)64 * 1024 * 1024) BUF_SZ = (size_t)64 * 1024 * 1024; + char *buf = (char *)malloc(BUF_SZ); + if (!buf) { send_err(id, "oom"); return; } + size_t pos = 0; + uint32_t emitted = 0; + pos += snprintf(buf + pos, BUF_SZ - pos, + "{\"id\":%d,\"ok\":true,\"total\":%llu,\"available\":%u,\"entries\":[", + id, (unsigned long long)total, avail); + for (uint32_t i = 0; i < avail && emitted < MAX_OUT && pos < BUF_SZ - 256; i++) { + uint32_t idx; + if (newest_first) { + uint32_t newest = (s_wtrace_all_head + WRITE_TRACE_ALL_CAP - 1u) + % WRITE_TRACE_ALL_CAP; + idx = (newest + WRITE_TRACE_ALL_CAP - (i % WRITE_TRACE_ALL_CAP)) + % WRITE_TRACE_ALL_CAP; + } else { + idx = (start + i) % WRITE_TRACE_ALL_CAP; + } + WriteTraceAllEntry *e = &s_wtrace_all[idx]; + if (e->addr < flo || e->addr >= fhi) continue; + pos += snprintf(buf + pos, BUF_SZ - pos, + "%s{\"seq\":%llu,\"addr\":\"0x%08X\"," + "\"new\":\"0x%08X\",\"pc\":\"0x%08X\"," + "\"ra\":\"0x%08X\",\"frame\":%u,\"w\":%u}", + (emitted == 0) ? "" : ",", + (unsigned long long)e->seq, + e->addr, e->new_val, e->pc, e->ra, + e->frame, (unsigned)e->w); + emitted++; + } + pos += snprintf(buf + pos, BUF_SZ - pos, "],\"emitted\":%u}", emitted); + debug_server_send_line(buf); + free(buf); +} + static void handle_wtrace_dump(int id, const char *json) { if (!s_wtrace) { send_err(id, "trace not initialized"); return; } @@ -5237,6 +5369,278 @@ static void handle_fn_exit_dump(int id, const char *json) { free(buf); } +/* ==================================================================== + * Freeze auto-dump accessors. Called from the freeze_heartbeat thread + * after it detects a main-thread stall. Each function writes a JSON + * array `[entry1,entry2,...]` of the newest entries directly to FILE*. + * + * Snapshot the ring's seq/head ONCE on entry so a concurrent writer + * (very rare at dump time) cannot make us walk off the end. + * ==================================================================== */ + +void debug_server_freeze_dump_wtrace_all_json(FILE *f, uint32_t max_count) +{ + if (!f) return; + if (!s_wtrace_all) { fputs("[]", f); return; } + + uint64_t total = s_wtrace_all_seq; + uint32_t head = s_wtrace_all_head; + uint32_t avail = (total < WRITE_TRACE_ALL_CAP) + ? (uint32_t)total : WRITE_TRACE_ALL_CAP; + if (max_count > avail) max_count = avail; + if (max_count == 0) { fputs("[]", f); return; } + + /* Walk oldest-first within the newest `max_count` window. */ + uint32_t start = (total < WRITE_TRACE_ALL_CAP) + ? (avail - max_count) + : (head + (WRITE_TRACE_ALL_CAP - max_count)) % WRITE_TRACE_ALL_CAP; + + fputc('[', f); + for (uint32_t i = 0; i < max_count; i++) { + uint32_t idx = (start + i) % WRITE_TRACE_ALL_CAP; + const WriteTraceAllEntry *e = &s_wtrace_all[idx]; + fprintf(f, + "%s{\"seq\":%llu,\"addr\":\"0x%08X\",\"new\":\"0x%08X\"," + "\"pc\":\"0x%08X\",\"ra\":\"0x%08X\",\"frame\":%u,\"w\":%u}", + i ? "," : "", + (unsigned long long)e->seq, e->addr, e->new_val, + e->pc, e->ra, e->frame, (unsigned)e->w); + } + fputc(']', f); +} + +void debug_server_freeze_dump_wtrace_json(FILE *f, uint32_t max_count) +{ + if (!f) return; + if (!s_wtrace) { fputs("[]", f); return; } + + uint64_t total = s_wtrace_seq; + uint32_t head = s_wtrace_head; + uint32_t avail = (total < WRITE_TRACE_CAP) ? (uint32_t)total : WRITE_TRACE_CAP; + if (max_count > avail) max_count = avail; + if (max_count == 0) { fputs("[]", f); return; } + + uint32_t start = (total < WRITE_TRACE_CAP) + ? (avail - max_count) + : (head + (WRITE_TRACE_CAP - max_count)) % WRITE_TRACE_CAP; + + fputc('[', f); + for (uint32_t i = 0; i < max_count; i++) { + uint32_t idx = (start + i) % WRITE_TRACE_CAP; + const WriteTraceEntry *e = &s_wtrace[idx]; + fprintf(f, + "%s{\"seq\":%llu,\"addr\":\"0x%08X\",\"old\":\"0x%08X\"," + "\"new\":\"0x%08X\",\"ra\":\"0x%08X\",\"func\":\"0x%08X\"," + "\"pc\":\"0x%08X\",\"cpu_pc\":\"0x%08X\",\"sp\":\"0x%08X\"," + "\"v0\":\"0x%08X\",\"v1\":\"0x%08X\"," + "\"a0\":\"0x%08X\",\"a1\":\"0x%08X\"," + "\"a2\":\"0x%08X\",\"a3\":\"0x%08X\"," + "\"t0\":\"0x%08X\",\"t1\":\"0x%08X\"," + "\"frame\":%u,\"w\":%u}", + i ? "," : "", + (unsigned long long)e->seq, e->addr, e->old_val, e->new_val, + e->ra, e->func_addr, e->pc, e->cpu_pc, e->sp, + e->v0, e->v1, e->a0, e->a1, e->a2, e->a3, e->t0, e->t1, + e->frame, (unsigned)e->width); + } + fputc(']', f); +} + +void debug_server_freeze_dump_frame_history_json(FILE *f, uint32_t max_count) +{ + if (!f) return; + if (!s_frame_history) { fputs("[]", f); return; } + + uint64_t total = s_history_count; + if (total == 0 || max_count == 0) { fputs("[]", f); return; } + uint64_t oldest = (total > FRAME_HISTORY_CAP) ? total - FRAME_HISTORY_CAP : 0; + uint64_t start = (total > (uint64_t)max_count) + ? total - (uint64_t)max_count : 0; + if (start < oldest) start = oldest; + + fputc('[', f); + int first = 1; + for (uint64_t fr = start; fr < total; fr++) { + uint32_t idx = (uint32_t)(fr % FRAME_HISTORY_CAP); + const PSXFrameRecord *r = &s_frame_history[idx]; + if (r->frame_number != (uint32_t)fr) continue; + fprintf(f, + "%s{\"frame\":%u,\"verify\":%d," + "\"sr\":\"0x%08X\",\"cause\":\"0x%08X\",\"epc\":\"0x%08X\"," + "\"i_stat\":\"0x%08X\",\"i_mask\":\"0x%08X\"," + "\"pad\":\"0x%04X\",\"sio_stat\":\"0x%04X\",\"sio_ctrl\":\"0x%04X\"," + "\"dispatch_count\":%u,\"total_dispatches\":%llu," + "\"disp\":{\"x\":%u,\"y\":%u,\"w\":%u,\"h\":%u,\"off\":%u}," + "\"last_func\":\"%s\"}", + first ? "" : ",", + r->frame_number, r->verify_pass, + r->cop0_sr, r->cop0_cause, r->cop0_epc, + r->i_stat, r->i_mask, + (unsigned)r->pad_buttons, + (unsigned)r->sio_stat, (unsigned)r->sio_ctrl, + r->dispatch_count, + (unsigned long long)r->total_dispatches, + (unsigned)r->display_area_x, (unsigned)r->display_area_y, + (unsigned)r->display_w, (unsigned)r->display_h, + (unsigned)r->display_disabled, + r->last_func); + first = 0; + } + fputc(']', f); +} + +void debug_server_freeze_dump_sio_pc_json(FILE *f, uint32_t max_count) +{ + if (!f) return; + uint64_t total = s_sio_pc_trace_seq; + uint32_t avail = (total < SIO_PC_TRACE_CAP) ? (uint32_t)total : SIO_PC_TRACE_CAP; + if (max_count > avail) max_count = avail; + if (max_count == 0) { fputs("[]", f); return; } + + uint64_t start = total - (uint64_t)max_count; + + fputc('[', f); + for (uint32_t i = 0; i < max_count; i++) { + uint64_t s = start + i; + const SioPcTraceEntry *e = &s_sio_pc_trace[s % SIO_PC_TRACE_CAP]; + fprintf(f, + "%s{\"seq\":%llu,\"pc\":\"0x%08X\",\"func\":\"0x%08X\"," + "\"addr\":\"0x%08X\",\"value\":\"0x%08X\"," + "\"byte_seq\":%u,\"width\":%u}", + i ? "," : "", + (unsigned long long)e->seq, e->pc, e->func, + e->addr, e->value, e->byte_seq, (unsigned)e->width); + } + fputc(']', f); +} + +void debug_server_freeze_dump_thread_trace_json(FILE *f, uint32_t max_count) +{ + if (!f) return; + uint64_t total = s_thread_trace_seq; + uint64_t avail = (total < THREAD_TRACE_CAP) ? total : THREAD_TRACE_CAP; + if ((uint64_t)max_count > avail) max_count = (uint32_t)avail; + if (max_count == 0) { fputs("[]", f); return; } + + uint64_t start = total - (uint64_t)max_count; + + fputc('[', f); + for (uint32_t i = 0; i < max_count; i++) { + uint64_t s = start + i; + const ThreadTraceEntry *e = &s_thread_trace[s % THREAD_TRACE_CAP]; + fprintf(f, + "%s{\"seq\":%llu,\"kind\":%u,\"name\":\"%s\"," + "\"current_tcb\":\"0x%08X\",\"target_tcb\":\"0x%08X\"," + "\"current_state\":\"0x%08X\",\"target_state\":\"0x%08X\"," + "\"target_pc\":\"0x%08X\",\"func\":\"0x%08X\"," + "\"store_pc\":\"0x%08X\",\"ra\":\"0x%08X\",\"sp\":\"0x%08X\"," + "\"a0\":\"0x%08X\",\"a1\":\"0x%08X\"," + "\"sr\":\"0x%08X\",\"epc\":\"0x%08X\"," + "\"istat\":\"0x%08X\",\"imask\":\"0x%08X\"," + "\"frame\":%u,\"in_exc\":%u}", + i ? "," : "", + (unsigned long long)e->seq, e->kind, thread_kind_name(e->kind), + e->current_tcb, e->target_tcb, + e->current_state, e->target_state, + e->target_pc, e->func, + e->last_store_pc, e->ra, e->sp, + e->a0, e->a1, + e->sr, e->epc, e->istat, e->imask, + e->frame, (unsigned)e->in_exception); + } + fputc(']', f); +} + +void debug_server_freeze_dump_restore_trace_json(FILE *f, uint32_t max_count) +{ + if (!f) return; + uint64_t total = s_restore_trace_seq; + uint64_t avail = (total < RESTORE_TRACE_CAP) ? total : RESTORE_TRACE_CAP; + if ((uint64_t)max_count > avail) max_count = (uint32_t)avail; + if (max_count == 0) { fputs("[]", f); return; } + + uint64_t start = total - (uint64_t)max_count; + + fputc('[', f); + for (uint32_t i = 0; i < max_count; i++) { + uint64_t s = start + i; + const RestoreTraceEntry *e = &s_restore_trace[s % RESTORE_TRACE_CAP]; + fprintf(f, + "%s{\"seq\":%llu,\"kind\":%u,\"name\":\"%s\",\"jmp\":%u," + "\"target\":\"0x%08X\",\"cpu_pc\":\"0x%08X\"," + "\"func\":\"0x%08X\",\"store_pc\":\"0x%08X\"," + "\"byte_seq\":%u,\"ra\":\"0x%08X\",\"sp\":\"0x%08X\"," + "\"sr\":\"0x%08X\",\"epc\":\"0x%08X\"," + "\"istat\":\"0x%08X\",\"imask\":\"0x%08X\"," + "\"frame\":%u,\"in_exc\":%u}", + i ? "," : "", + (unsigned long long)e->seq, e->kind, restore_kind_name(e->kind), + e->jmp_val, e->target_pc, e->cpu_pc, + e->func, e->last_store_pc, e->byte_seq, e->ra, e->sp, + e->sr, e->epc, e->istat, e->imask, + e->frame, (unsigned)e->in_exception); + } + fputc(']', f); +} + +void debug_server_freeze_dump_fn_entry_json(FILE *f, uint32_t max_count) +{ + if (!f) return; + if (!s_fn_entry) { fputs("[]", f); return; } + + uint64_t total = s_fn_entry_seq; + uint64_t oldest = (total > FN_TRACE_CAP) ? total - FN_TRACE_CAP : 0; + uint64_t start = (total > (uint64_t)max_count) + ? total - (uint64_t)max_count : 0; + if (start < oldest) start = oldest; + if (start >= total) { fputs("[]", f); return; } + + fputc('[', f); + int first = 1; + for (uint64_t s = start; s < total; s++) { + const FnEntryEntry *e = &s_fn_entry[s % FN_TRACE_CAP]; + if (e->seq != s) continue; + fprintf(f, + "%s{\"seq\":%llu,\"func\":\"0x%08X\",\"ra\":\"0x%08X\"," + "\"a0\":\"0x%08X\",\"a1\":\"0x%08X\",\"a2\":\"0x%08X\"," + "\"a3\":\"0x%08X\",\"t1\":\"0x%08X\",\"frame\":%u}", + first ? "" : ",", + (unsigned long long)e->seq, e->func_addr, e->ra, + e->a0, e->a1, e->a2, e->a3, e->t1, e->frame); + first = 0; + } + fputc(']', f); +} + +void debug_server_freeze_dump_dirty_block_json(FILE *f, uint32_t max_count) +{ + if (!f) { return; } + + uint64_t total = g_dirty_ram_block_log_seq; + uint64_t avail = (total < (uint64_t)DIRTY_RAM_BLOCK_LOG_CAP) + ? total : (uint64_t)DIRTY_RAM_BLOCK_LOG_CAP; + uint64_t want = ((uint64_t)max_count < avail) ? (uint64_t)max_count : avail; + uint64_t start = total - want; + + fputc('[', f); + int first = 1; + for (uint64_t s = start; s < total; s++) { + const DirtyRamBlockLogEntry *e = + &g_dirty_ram_block_log[s & (DIRTY_RAM_BLOCK_LOG_CAP - 1u)]; + if (e->seq != s) { continue; } + fprintf(f, + "%s{\"seq\":%llu,\"target\":\"0x%08X\",\"ra\":\"0x%08X\"," + "\"a0\":\"0x%08X\",\"a1\":\"0x%08X\",\"a2\":\"0x%08X\"," + "\"a3\":\"0x%08X\",\"t0\":\"0x%08X\",\"t1\":\"0x%08X\"," + "\"sp\":\"0x%08X\",\"frame\":%u}", + first ? "" : ",", + (unsigned long long)e->seq, e->target, e->ra, + e->a0, e->a1, e->a2, e->a3, e->t0, e->t1, e->sp, e->frame); + first = 0; + } + fputc(']', f); +} + typedef void (*CmdHandler)(int id, const char *json); typedef struct { const char *name; CmdHandler handler; } CmdEntry; @@ -5305,13 +5709,27 @@ static const CmdEntry s_commands[] = { { "imask_trace", handle_imask_trace }, { "watch", handle_watch }, { "unwatch", handle_unwatch }, - { "wtrace_range", handle_wtrace_range }, - { "wtrace_add", handle_wtrace_add }, - { "wtrace_del", handle_wtrace_del }, - { "wtrace_ranges", handle_wtrace_ranges }, - { "wtrace_dump", handle_wtrace_dump }, - { "wtrace_clear", handle_wtrace_clear }, - { "wtrace_stats", handle_wtrace_stats }, + /* wtrace — normalized verb set (parity contract with psx-beetle). + * One slot per "lo,hi" pair. arm/disarm/disarm_all/reset/ranges/ + * dump/stats. Both backends accept identical JSON shape. */ + { "wtrace_arm", handle_wtrace_add }, + { "wtrace_disarm", handle_wtrace_del }, + { "wtrace_disarm_all", handle_wtrace_disarm_all }, + { "wtrace_reset", handle_wtrace_clear }, + { "wtrace_ranges", handle_wtrace_ranges }, + { "wtrace_dump", handle_wtrace_dump }, + { "wtrace_stats", handle_wtrace_stats }, + /* Always-on catch-all wtrace ring (parity with psx-beetle). */ + { "wtrace_all_dump", handle_wtrace_all_dump }, + { "wtrace_all_stats", handle_wtrace_all_stats }, + { "wtrace_all_reset", handle_wtrace_all_reset }, + /* Legacy verbs retained for existing tools/ scripts that haven't + * been updated; they dispatch to the same handlers as the + * normalized verbs. Will retire once consumers are migrated. */ + { "wtrace_range", handle_wtrace_range }, + { "wtrace_add", handle_wtrace_add }, + { "wtrace_del", handle_wtrace_del }, + { "wtrace_clear", handle_wtrace_clear }, { "freeze_check", handle_freeze_check }, { "mmio_dump", handle_mmio_dump }, { "mmio_clear", handle_mmio_clear }, @@ -5444,6 +5862,16 @@ void debug_server_init(int port) s_wtrace_seq = 0; s_wtrace_head = 0; + /* Always-on catch-all wtrace ring (8 MB). Records EVERY RAM write + * with lean fields (no register window). Sized for ~1 second of + * coverage at typical Tomba write rates. */ + if (!s_wtrace_all) { + s_wtrace_all = (WriteTraceAllEntry *)calloc(WRITE_TRACE_ALL_CAP, + sizeof(WriteTraceAllEntry)); + } + s_wtrace_all_seq = 0; + s_wtrace_all_head = 0; + /* Function entry/exit ring buffers (32 MB each, 64 MB total). */ if (!s_fn_entry) s_fn_entry = (FnEntryEntry *)calloc(FN_TRACE_CAP, sizeof(FnEntryEntry)); if (!s_fn_exit) s_fn_exit = (FnExitEntry *)calloc(FN_EXIT_TRACE_CAP, sizeof(FnExitEntry)); diff --git a/runtime/src/freeze_heartbeat.c b/runtime/src/freeze_heartbeat.c index 37831550..889fb49f 100644 --- a/runtime/src/freeze_heartbeat.c +++ b/runtime/src/freeze_heartbeat.c @@ -1,6 +1,7 @@ /* freeze_heartbeat.c — see header for rationale. */ #include "freeze_heartbeat.h" +#include "debug_server.h" #include #include @@ -9,6 +10,7 @@ #ifdef _WIN32 #include +#include #endif /* State accessors. All defined in other compilation units; declared here @@ -43,11 +45,42 @@ static char s_backend[32] = "psx-runtime"; #ifdef _WIN32 static HANDLE s_thread = NULL; +static HANDLE s_main_thread = NULL; /* DuplicateHandle of main thread */ +static DWORD s_main_thread_id = 0; +static int s_sym_initialized = 0; #endif -#define HB_FILE "psx_freeze_heartbeat.json" +#define HB_FILE "psx_freeze_heartbeat.json" #define HB_INTERVAL_MS 100u +/* Wedge detection. + * + * Two failure modes to catch: + * A. HARD freeze — main thread is fully wedged; frame_count stops + * advancing entirely. Detected by zero frame_delta over the window. + * B. SOFT freeze / reentry storm — frame_count keeps advancing + * (sometimes at near-normal rate) but the main thread is starved + * by exception-handler reentry. Detected by exc_reentry_blocks + * delta exceeding a threshold over the window. OPTIONS-black on + * psx-runtime is this case: ~58 Hz frame rate, ~45K reentries/sec. + * + * Window = 20 ticks = 2.0 sec. Long enough that legitimate startup + * activity (boot, FMV decode, save load) doesn't trip it; short enough + * that real wedges dump within seconds. */ +#define WEDGE_WINDOW_TICKS 20u +#define WEDGE_EXC_REENTRY_DELTA_THRESHOLD 10000u /* >5K/sec sustained = wedge */ + +/* Per-ring caps for auto-dump. Newest-first window. Sized so the total + * dump fits in ~10-15 MB JSON even when every ring is full. */ +#define DUMP_CAP_WTRACE_ALL 16384u +#define DUMP_CAP_WTRACE 8192u +#define DUMP_CAP_FRAME_HISTORY 600u +#define DUMP_CAP_SIO_PC 8192u +#define DUMP_CAP_THREAD_TRACE 4096u +#define DUMP_CAP_RESTORE_TRACE 4096u +#define DUMP_CAP_FN_ENTRY 4096u +#define DUMP_CAP_DIRTY_BLOCK 16384u + /* Pre-freeze history ring. Each entry = a snapshot taken at one heartbeat * tick (~100 ms). When the runtime freezes, all the "now" values stop * advancing but the past N entries still show what state it was in for @@ -71,6 +104,266 @@ static HbRingEntry s_ring[RING_CAP]; static uint32_t s_ring_head = 0; static uint32_t s_ring_count = 0; +/* Wedge detection state. + * s_dump_armed - 1 if a wedge dump is allowed to fire; cleared after + * firing, re-armed when the wedge clears (healthy tick). */ +static int s_dump_armed = 1; +static uint32_t s_last_wedge_kind = 0; /* informational, last detected kind */ + +#ifdef _WIN32 +/* Capture the main thread's call stack at the moment of a hard freeze. + * + * Called from the heartbeat thread when wedge_kind==1 (frame_count not + * advancing). Suspends the main thread, walks its stack via StackWalk64, + * symbolizes via SymFromAddr, then resumes. Each frame becomes a JSON + * object {addr, symbol?, displacement?, module?}. + * + * Best-effort: if DbgHelp init fails, dump an empty array and continue. */ +static void freeze_dump_main_stack_json(FILE *f) { + if (!f) return; + if (!s_main_thread) { fputs("[]", f); return; } + + if (!s_sym_initialized) { + SymSetOptions(SYMOPT_LOAD_LINES | SYMOPT_UNDNAME | SYMOPT_DEFERRED_LOADS); + if (SymInitialize(GetCurrentProcess(), NULL, TRUE)) { + s_sym_initialized = 1; + } else { + fputs("[]", f); + return; + } + } + + DWORD susp_count = SuspendThread(s_main_thread); + if (susp_count == (DWORD)-1) { fputs("[]", f); return; } + + CONTEXT ctx; + memset(&ctx, 0, sizeof(ctx)); + ctx.ContextFlags = CONTEXT_FULL; + if (!GetThreadContext(s_main_thread, &ctx)) { + ResumeThread(s_main_thread); + fputs("[]", f); + return; + } + + STACKFRAME64 frame; + memset(&frame, 0, sizeof(frame)); +#if defined(_M_X64) || defined(__x86_64__) + DWORD machine = IMAGE_FILE_MACHINE_AMD64; + frame.AddrPC.Offset = ctx.Rip; + frame.AddrFrame.Offset = ctx.Rbp; + frame.AddrStack.Offset = ctx.Rsp; +#else + DWORD machine = IMAGE_FILE_MACHINE_I386; + frame.AddrPC.Offset = ctx.Eip; + frame.AddrFrame.Offset = ctx.Ebp; + frame.AddrStack.Offset = ctx.Esp; +#endif + frame.AddrPC.Mode = AddrModeFlat; + frame.AddrFrame.Mode = AddrModeFlat; + frame.AddrStack.Mode = AddrModeFlat; + + fputc('[', f); + int first = 1; + union { + SYMBOL_INFO si; + char buf[sizeof(SYMBOL_INFO) + 512]; + } sym_storage; + SYMBOL_INFO *sym = &sym_storage.si; + + for (int depth = 0; depth < 128; depth++) { + if (!StackWalk64(machine, GetCurrentProcess(), s_main_thread, &frame, + &ctx, NULL, SymFunctionTableAccess64, SymGetModuleBase64, + NULL)) { + break; + } + DWORD64 addr = frame.AddrPC.Offset; + if (!addr) break; + + memset(sym, 0, sizeof(SYMBOL_INFO)); + sym->SizeOfStruct = sizeof(SYMBOL_INFO); + sym->MaxNameLen = 511; + DWORD64 displacement = 0; + BOOL got_sym = SymFromAddr(GetCurrentProcess(), addr, &displacement, sym); + + IMAGEHLP_MODULE64 mod; + memset(&mod, 0, sizeof(mod)); + mod.SizeOfStruct = sizeof(mod); + BOOL got_mod = SymGetModuleInfo64(GetCurrentProcess(), addr, &mod); + + fprintf(f, "%s{\"depth\":%d,\"addr\":\"0x%016llX\"", + first ? "" : ",", depth, (unsigned long long)addr); + if (got_sym) { + /* Escape JSON-special chars in symbol name (best-effort: bracket replace). */ + char safe[512]; + size_t k = 0; + for (size_t i = 0; sym->Name[i] && k < sizeof(safe) - 2; i++) { + char c = sym->Name[i]; + if (c == '"' || c == '\\') safe[k++] = '_'; + else if ((unsigned char)c < 0x20) safe[k++] = '_'; + else safe[k++] = c; + } + safe[k] = 0; + fprintf(f, ",\"symbol\":\"%s\",\"displacement\":%llu", + safe, (unsigned long long)displacement); + } + if (got_mod && mod.ModuleName[0]) { + fprintf(f, ",\"module\":\"%s\"", mod.ModuleName); + } + fputc('}', f); + first = 0; + } + fputc(']', f); + + ResumeThread(s_main_thread); +} +#endif /* _WIN32 */ + +static void freeze_dump_write(long long wall, uint64_t frame, uint64_t cyc, + uint64_t exc_reentry, uint32_t cur_fn, + uint32_t last_store, uint32_t i_stat_v, + uint32_t i_mask_v, int in_exc, + uint64_t total_checks, uint32_t dispatch_count, + uint64_t exc_entries, + uint16_t sio_stat_v, uint16_t sio_ctrl_v, + int sio_card_active, int mc_max, int tx_writes) +{ + char path[128]; + snprintf(path, sizeof(path), + "psx_freeze_dump_%s_%lld.json", s_backend, wall); + + FILE *f = fopen(path, "wb"); + if (!f) return; + + /* Large stdio buffer so multi-MB JSON arrays write efficiently. */ + static char io_buf[1 << 16]; + setvbuf(f, io_buf, _IOFBF, sizeof(io_buf)); + + fprintf(f, + "{\n" + " \"backend\":\"%s\",\n" + " \"wall_clock_epoch\":%lld,\n" + " \"frame_count\":%llu,\n" + " \"psx_cycle_count\":%llu,\n" + " \"current_func\":\"0x%08X\",\n" + " \"last_store_pc\":\"0x%08X\",\n" + " \"total_checks\":%llu,\n" + " \"dispatch_count\":%u,\n" + " \"in_exception\":%d,\n" + " \"exception_entries\":%llu,\n" + " \"exception_reentry_blocks\":%llu,\n" + " \"sio_stat\":\"0x%04X\",\n" + " \"sio_ctrl\":\"0x%04X\",\n" + " \"sio_card_active\":%d,\n" + " \"i_stat\":\"0x%08X\",\n" + " \"i_mask\":\"0x%08X\",\n" + " \"mc_max_state\":%d,\n" + " \"tx_writes\":%d,\n" + " \"dirty_ram_blocks\":%llu,\n" + " \"dirty_ram_insns\":%llu,\n" + " \"wedge_kind\":%u,\n" + " \"wedge_kind_name\":\"%s\",\n" + " \"caps\":{\"wtrace_all\":%u,\"wtrace\":%u,\"frames\":%u," + "\"sio_pc\":%u,\"thread\":%u,\"restore\":%u,\"fn_entry\":%u," + "\"dirty_block\":%u},\n", + s_backend, wall, + (unsigned long long)frame, (unsigned long long)cyc, + cur_fn, last_store, + (unsigned long long)total_checks, dispatch_count, + in_exc, + (unsigned long long)exc_entries, + (unsigned long long)exc_reentry, + (unsigned)sio_stat_v, (unsigned)sio_ctrl_v, + sio_card_active, + i_stat_v, i_mask_v, + mc_max, tx_writes, + (unsigned long long)g_dirty_ram_blocks_run, + (unsigned long long)g_dirty_ram_insns_run, + s_last_wedge_kind, + (s_last_wedge_kind == 1) ? "hard_freeze" : + (s_last_wedge_kind == 2) ? "reentry_storm" : "unknown", + (unsigned)DUMP_CAP_WTRACE_ALL, + (unsigned)DUMP_CAP_WTRACE, + (unsigned)DUMP_CAP_FRAME_HISTORY, + (unsigned)DUMP_CAP_SIO_PC, + (unsigned)DUMP_CAP_THREAD_TRACE, + (unsigned)DUMP_CAP_RESTORE_TRACE, + (unsigned)DUMP_CAP_FN_ENTRY, + (unsigned)DUMP_CAP_DIRTY_BLOCK); + + fputs(" \"heartbeat_ring\":[\n", f); + uint32_t avail = s_ring_count; + uint32_t start = (s_ring_count < RING_CAP) ? 0 : s_ring_head; + for (uint32_t i = 0; i < avail; i++) { + HbRingEntry *e = &s_ring[(start + i) % RING_CAP]; + fprintf(f, + " {\"wall\":%lld,\"frame\":%llu,\"cyc\":%llu," + "\"exc_re\":%llu,\"dirty_insns\":%llu," + "\"cur_fn\":\"0x%08X\",\"store_pc\":\"0x%08X\"," + "\"i_stat\":\"0x%08X\",\"sio_stat\":\"0x%04X\"," + "\"sio_ctrl\":\"0x%04X\",\"in_exc\":%u,\"mc_max\":%u}%s\n", + e->wall_clock, + (unsigned long long)e->frame_count, + (unsigned long long)e->psx_cycle_count, + (unsigned long long)e->exc_reentry, + (unsigned long long)e->dirty_ram_insns, + e->current_func, e->last_store_pc, + e->i_stat, (unsigned)e->sio_stat, (unsigned)e->sio_ctrl, + (unsigned)e->in_exception, (unsigned)e->mc_max_state, + (i + 1 < avail) ? "," : ""); + } + fputs(" ],\n", f); + + fputs(" \"wtrace_all\":", f); + debug_server_freeze_dump_wtrace_all_json(f, DUMP_CAP_WTRACE_ALL); + fputs(",\n", f); + + fputs(" \"wtrace\":", f); + debug_server_freeze_dump_wtrace_json(f, DUMP_CAP_WTRACE); + fputs(",\n", f); + + fputs(" \"frame_history\":", f); + debug_server_freeze_dump_frame_history_json(f, DUMP_CAP_FRAME_HISTORY); + fputs(",\n", f); + + fputs(" \"sio_pc_trace\":", f); + debug_server_freeze_dump_sio_pc_json(f, DUMP_CAP_SIO_PC); + fputs(",\n", f); + + fputs(" \"thread_trace\":", f); + debug_server_freeze_dump_thread_trace_json(f, DUMP_CAP_THREAD_TRACE); + fputs(",\n", f); + + fputs(" \"restore_trace\":", f); + debug_server_freeze_dump_restore_trace_json(f, DUMP_CAP_RESTORE_TRACE); + fputs(",\n", f); + + fputs(" \"fn_entry\":", f); + debug_server_freeze_dump_fn_entry_json(f, DUMP_CAP_FN_ENTRY); + fputs(",\n", f); + + fputs(" \"dirty_block\":", f); + debug_server_freeze_dump_dirty_block_json(f, DUMP_CAP_DIRTY_BLOCK); + fputs(",\n", f); + +#ifdef _WIN32 + /* Main-thread call stack — only for hard freezes (wedge_kind==1). + * For reentry storms the main thread is still running; capturing its + * stack would just show a random recompiled-block frame. */ + fputs(" \"main_stack\":", f); + if (s_last_wedge_kind == 1) { + freeze_dump_main_stack_json(f); + } else { + fputs("[]", f); + } + fputs("\n", f); +#else + fputs(" \"main_stack\":[]\n", f); +#endif + + fputs("}\n", f); + fclose(f); +} + static void heartbeat_write(void) { uint64_t cyc = psx_get_cycle_count(); uint64_t frame = s_frame_count; @@ -120,6 +413,50 @@ static void heartbeat_write(void) { s_ring_head = (s_ring_head + 1) % RING_CAP; if (s_ring_count < RING_CAP) s_ring_count++; + /* ---- Wedge detection: arm-once auto-dump ---- + * Walk back WEDGE_WINDOW_TICKS in the heartbeat ring (just pushed + * above) and compute deltas. Trigger if either: + * A. frame_count delta == 0 (hard freeze) + * B. exc_reentry delta > threshold (reentry storm; soft freeze) + * + * Only fires once the ring has enough history. When the wedge clears + * (a healthy tick: frames advancing AND exc_re quiet), re-arm. */ + uint32_t wedge_kind = 0; /* 0=healthy, 1=hard freeze, 2=reentry storm */ + if (s_ring_count >= WEDGE_WINDOW_TICKS) { + /* The just-pushed tick is at (s_ring_head - 1). The oldest in + * our window is WEDGE_WINDOW_TICKS - 1 ticks before it. */ + uint32_t newest_idx = (s_ring_head + RING_CAP - 1u) % RING_CAP; + uint32_t oldest_idx = (s_ring_head + RING_CAP - WEDGE_WINDOW_TICKS) % RING_CAP; + uint64_t newest_frame = s_ring[newest_idx].frame_count; + uint64_t oldest_frame = s_ring[oldest_idx].frame_count; + uint64_t newest_excre = s_ring[newest_idx].exc_reentry; + uint64_t oldest_excre = s_ring[oldest_idx].exc_reentry; + uint64_t frame_delta = (newest_frame >= oldest_frame) + ? (newest_frame - oldest_frame) : 0; + uint64_t excre_delta = (newest_excre >= oldest_excre) + ? (newest_excre - oldest_excre) : 0; + + if (frame_delta == 0) + wedge_kind = 1; + else if (excre_delta > WEDGE_EXC_REENTRY_DELTA_THRESHOLD) + wedge_kind = 2; + } + + if (wedge_kind != 0) { + if (s_dump_armed) { + s_dump_armed = 0; + s_last_wedge_kind = wedge_kind; + freeze_dump_write(wall, frame, cyc, exc_reentry, cur_fn, last_store, + i_stat, i_mask, in_exc, total_checks, + dispatch_count, exc_entries, + sio_stat, sio_ctrl, card_active, + mc_max, tx_writes); + } + } else { + /* Healthy tick: re-arm for the next wedge. */ + s_dump_armed = 1; + } + /* Buffer sized for current-state JSON + ring (~256B per ring entry). */ static char buf[64 * 1024]; int n = snprintf(buf, sizeof(buf), @@ -254,6 +591,16 @@ void freeze_heartbeat_start(const char *backend_label) { s_backend[n] = 0; } #ifdef _WIN32 + /* Duplicate the main thread's pseudo-handle into a real handle so the + * heartbeat thread can SuspendThread/GetThreadContext for stack capture + * on hard freezes. GetCurrentThread() returns a pseudo-handle that's + * only valid in the calling thread, so the duplication is required. */ + s_main_thread_id = GetCurrentThreadId(); + if (!DuplicateHandle(GetCurrentProcess(), GetCurrentThread(), + GetCurrentProcess(), &s_main_thread, + THREAD_ALL_ACCESS, FALSE, 0)) { + s_main_thread = NULL; + } s_thread = CreateThread(NULL, 0, heartbeat_thread, NULL, 0, NULL); if (s_thread) s_started = 1; #endif diff --git a/runtime/src/gpu.c b/runtime/src/gpu.c index 45942be5..293a5d68 100644 --- a/runtime/src/gpu.c +++ b/runtime/src/gpu.c @@ -103,6 +103,12 @@ static uint32_t dma_direction; /* bits 29-30 in GPUSTAT */ /* LCF (even/odd line in interlace, toggles per vblank) */ static uint32_t lcf; /* bit 31 */ +/* I_STAT — defined in memory.c; declared early so gpu_read_gpustat can + * raise the VBLANK bit when a synthetic vblank fires from a tight + * BIOS-shell GPUSTAT poll loop, without going through the + * vblank-callback path (which would call SDL_Delay/Sleep). */ +extern uint32_t i_stat; + /* Display area start (GP1(05h)) */ static uint32_t display_area_x; static uint32_t display_area_y; @@ -213,11 +219,21 @@ void gpu_init(void) { uint32_t gpu_read_gpustat(void) { /* Advance vblank when polled enough times from within a single function. - * This handles BIOS VSYNC wait loops that poll LCF in tight loops. */ + * This handles BIOS VSYNC wait loops that poll LCF in tight loops. + * + * IMPORTANT: only update emulation state here (LCF + I_STAT). Do NOT + * fire the vblank callback — that calls sdl_vblank_present, which + * runs SDL_RenderPresent and SDL_Delay (Sleep). Entering Sleep from + * an MMIO-read code path means recompiled MIPS code spends real wall + * time inside Sleep — wrong context, hard to reason about, and + * accumulates host stack frames inside the recompiled call tree. + * The callback fires from the proper VBLANK trigger in + * psx_check_interrupts (cycle-paced). */ gpustat_poll_count++; if (gpustat_poll_count >= GPUSTAT_POLL_VBLANK_THRESHOLD) { gpustat_poll_count = 0; - gpu_vblank_tick(); + lcf ^= 1; + i_stat |= (1u << 0); /* IRQ_VBLANK */ } uint32_t stat = 0; @@ -320,8 +336,7 @@ static uint16_t rgb888_to_rgb555(uint32_t color24) { return (uint16_t)((r >> 3) | ((g >> 3) << 5) | ((b >> 3) << 10)); } -/* I_STAT owned by memory.c — needed to set IRQ_VBLANK from poll-triggered vblank */ -extern uint32_t i_stat; +/* i_stat extern declared earlier in this file (above gpu_read_gpustat). */ void gpu_vblank_tick(void) { lcf ^= 1; diff --git a/runtime/src/interrupts.c b/runtime/src/interrupts.c index 1e23a907..c3207b98 100644 --- a/runtime/src/interrupts.c +++ b/runtime/src/interrupts.c @@ -79,8 +79,24 @@ static uint64_t exception_reentry_blocks; * very next psx_check_interrupts re-enters immediately. */ static int post_exception_cooldown; -/* setjmp target for ReturnFromException during handler dispatch. */ -static jmp_buf exception_jmpbuf; +/* setjmp target for ReturnFromException during handler dispatch. + * + * IMPORTANT: longjmp(exception_jmpbuf, ...) MUST execute on the same + * Windows fiber that called setjmp; otherwise RSP is restored to that + * fiber's stack while the OS still tracks a different fiber as current, + * corrupting fiber state and eventually deadlocking SwitchToFiber. + * + * s_exception_owner_fiber records which fiber called setjmp. If a + * longjmp request originates on a different fiber, the caller must: + * (1) set s_pending_exception_longjmp = code + * (2) SwitchToFiber back to s_exception_owner_fiber + * That fiber's wrapped SwitchToFiber call will observe the flag on + * return and execute the longjmp on the correct stack. */ +jmp_buf exception_jmpbuf; /* non-static so traps.c can deferred-longjmp */ +#ifdef _WIN32 +void* g_exception_owner_fiber = NULL; +int g_pending_exception_longjmp = 0; +#endif extern int g_psx_dispatch_depth; int psx_get_in_exception(void) { return in_exception; } @@ -123,15 +139,39 @@ void interrupts_init(void) { * in_exception and return, effectively letting the interrupted * code resume at the saved EPC through normal dispatch. */ +#ifdef _WIN32 +#include +/* Defer a longjmp to the fiber that owns the current exception setjmp. + * If we're on the owning fiber already, longjmp immediately. Otherwise + * record the requested code, SwitchToFiber back to the owner, and the + * post-SwitchToFiber check in traps.c psx_change_thread_fiber (or the + * fiber entry helper) will execute the longjmp on the correct stack. */ +static void deferred_exception_longjmp(int code) { + if (!g_exception_owner_fiber || GetCurrentFiber() == g_exception_owner_fiber) { + longjmp(exception_jmpbuf, code); + } + g_pending_exception_longjmp = code; + SwitchToFiber(g_exception_owner_fiber); + /* If we end up back here, the owner didn't honor the flag (bug). + * Fall through to direct longjmp as a last resort — even though + * the stack is wrong, the alternative is hanging silently. */ + longjmp(exception_jmpbuf, code); +} +#else +static void deferred_exception_longjmp(int code) { + longjmp(exception_jmpbuf, code); +} +#endif + void psx_exception_longjmp(void) { debug_server_log_restore_event(2, debug_cpu_ptr ? debug_cpu_ptr->pc : 0, 1); - longjmp(exception_jmpbuf, 1); + deferred_exception_longjmp(1); } void psx_restore_state_escape(void) { if (in_exception) { debug_server_log_restore_event(1, debug_cpu_ptr ? debug_cpu_ptr->pc : 0, 2); - longjmp(exception_jmpbuf, 2); + deferred_exception_longjmp(2); } /* Not in exception context — return normally, let caller's `return;` handle it. */ } @@ -305,6 +345,15 @@ void psx_check_interrupts(CPUState* cpu) { target_pc = hi_val + (uint32_t)(int32_t)lo_val; } +#ifdef _WIN32 + /* Record which fiber owns this setjmp. Any subsequent longjmp must + * happen on this same fiber; if a non-owner fiber needs to longjmp + * it must SwitchToFiber back here first (see deferred_exception_longjmp). */ + void *prev_owner_fiber = g_exception_owner_fiber; + int prev_pending = g_pending_exception_longjmp; + g_exception_owner_fiber = GetCurrentFiber(); + g_pending_exception_longjmp = 0; +#endif for (;;) { int jmp_val = setjmp(exception_jmpbuf); if (jmp_val == 2) { @@ -327,6 +376,12 @@ void psx_check_interrupts(CPUState* cpu) { /* jmp_val 0 (normal return) or 1 (ReturnFromException): done. */ break; } +#ifdef _WIN32 + /* Restore previous exception-owner state. Supports nested exceptions + * if they ever arise (uncommon but harmless). */ + g_exception_owner_fiber = prev_owner_fiber; + g_pending_exception_longjmp = prev_pending; +#endif /* Restore the interrupted code's registers. * diff --git a/runtime/src/traps.c b/runtime/src/traps.c index 650537cd..6d841ccb 100644 --- a/runtime/src/traps.c +++ b/runtime/src/traps.c @@ -262,6 +262,18 @@ static int psx_change_thread_fiber(CPUState* cpu, uint32_t target_tcb) debug_server_log_thread_event(8, cpu, current_tcb, target_tcb, 0); SwitchToFiber(target->fiber); + /* If a non-owner fiber requested an exception longjmp while we were + * suspended, it deferred it by SwitchToFiber'ing back to us (the + * owner). Honor it now from the correct stack. */ + extern void* g_exception_owner_fiber; + extern int g_pending_exception_longjmp; + extern jmp_buf exception_jmpbuf; + if (g_pending_exception_longjmp && GetCurrentFiber() == g_exception_owner_fiber) { + int code = g_pending_exception_longjmp; + g_pending_exception_longjmp = 0; + longjmp(exception_jmpbuf, code); + } + debug_server_log_thread_event(9, cpu, target_tcb, current_tcb, 0); cpu->pc = 0; return 1; diff --git a/tools/_options_session/_analyze_baseline.py b/tools/_options_session/_analyze_baseline.py new file mode 100644 index 00000000..2226441f --- /dev/null +++ b/tools/_options_session/_analyze_baseline.py @@ -0,0 +1,109 @@ +"""Analyze the captured options_baseline_*.json snapshot. + +Goal: characterize the divergence between runtime (stuck in OPTIONS-black, +constantly rebuilding display list) and beetle (stable OPTIONS, only +touching state cells). + +For each side, group the wtrace_all entries by (addr, pc, ra) and +report counts. Tells us: + - which PCs are writing the OPTIONS-area cells on each backend + - whether the same PCs exist on both (= same code, wrong data) or + different PCs (= different code paths entirely) +""" +from __future__ import annotations +import sys, os, json, glob +from collections import defaultdict + +if len(sys.argv) > 1: + path = sys.argv[1] +else: + out_dir = os.path.join(os.environ.get("TEMP", "/tmp"), "optsess") + matches = sorted(glob.glob(os.path.join(out_dir, "options_baseline_*.json"))) + if not matches: + print("no snapshot found", file=sys.stderr); sys.exit(1) + path = matches[-1] +print(f"using {path}") + +with open(path) as f: + snap = json.load(f) + + +def hx(v): + if isinstance(v, str): return int(v, 16) if v.lower().startswith("0x") else int(v) + return v + + +def analyze_side(side_name, side): + print(f"\n{'='*70}\n {side_name.upper()}\n{'='*70}") + print(f" frame={side['ping']['frame']}") + if "freeze_check" in side: + fc = side["freeze_check"] + if isinstance(fc, dict) and fc.get("ok"): + print(f" freeze: current_func={fc.get('current_func')} " + f"last_store_pc={fc.get('last_store_pc')} " + f"in_exc={fc.get('in_exception')} " + f"exc_reentry={fc.get('exception_reentry_blocks')}") + + # OPTIONS-area cluster (filtered) + dmp = side["wtrace_all_dump_optstate"] + entries = dmp.get("entries", []) + print(f"\n optstate writes in ring: {len(entries)} (filter 0x80090C00..0x80091000)") + if not entries: return + + # Group by addr (which cells are written most) + by_addr = defaultdict(int) + for e in entries: + by_addr[e["addr"]] += 1 + top_addr = sorted(by_addr.items(), key=lambda x: -x[1])[:12] + print(f"\n top 12 addrs (count of writes):") + for a, c in top_addr: + print(f" {a} {c}") + + # Group by (pc, ra) — who is writing + by_pcra = defaultdict(int) + for e in entries: + by_pcra[(e["pc"], e["ra"])] += 1 + top_pcra = sorted(by_pcra.items(), key=lambda x: -x[1])[:10] + print(f"\n top 10 (pc, ra) (count):") + for (pc, ra), c in top_pcra: + print(f" pc={pc} ra={ra} {c}") + + # Distinct PCs (writers) and distinct RAs (callers of writers) + distinct_pcs = sorted({e["pc"] for e in entries}) + distinct_ras = sorted({e["ra"] for e in entries}) + print(f"\n distinct write PCs: {len(distinct_pcs)}") + print(f" distinct write RAs (callers): {len(distinct_ras)}") + print(f" first 6 distinct PCs: {distinct_pcs[:6]}") + print(f" first 6 distinct RAs: {distinct_ras[:6]}") + + # Frame range covered in this window + frames = sorted({e["frame"] for e in entries}) + print(f"\n frame range in ring: [{min(frames)}, {max(frames)}] ({len(frames)} distinct frames)") + + # Unfiltered tail — where IS the rest of the activity? + tail = side["wtrace_all_dump_tail"] + tail_entries = tail.get("entries", []) + if tail_entries: + # Top 8 addr bins (granularity: 256-byte buckets) + bucket = defaultdict(int) + for e in tail_entries: + a = hx(e["addr"]) + bucket[a & ~0xFF] += 1 + top_bucket = sorted(bucket.items(), key=lambda x: -x[1])[:8] + print(f"\n top 8 256-byte buckets in unfiltered tail of {len(tail_entries)} entries:") + for a, c in top_bucket: + print(f" 0x{a:08X}-0x{a+0xFF:08X} {c}") + + +analyze_side("runtime", snap["runtime"]) +analyze_side("beetle", snap["beetle"]) + +# Cross-side: are the same PCs writing the same cells on both? +r_pc_set = {e["pc"] for e in snap["runtime"]["wtrace_all_dump_optstate"]["entries"]} +b_pc_set = {e["pc"] for e in snap["beetle"]["wtrace_all_dump_optstate"]["entries"]} +print(f"\n{'='*70}\n CROSS-SIDE\n{'='*70}") +print(f" runtime distinct PCs writing optstate: {len(r_pc_set)}") +print(f" beetle distinct PCs writing optstate: {len(b_pc_set)}") +print(f" intersection: {len(r_pc_set & b_pc_set)}") +print(f" runtime-only PCs (first 10): {sorted(r_pc_set - b_pc_set)[:10]}") +print(f" beetle-only PCs (first 10): {sorted(b_pc_set - r_pc_set)[:10]}") diff --git a/tools/_options_session/_analyze_dump.py b/tools/_options_session/_analyze_dump.py new file mode 100644 index 00000000..e869af69 --- /dev/null +++ b/tools/_options_session/_analyze_dump.py @@ -0,0 +1,72 @@ +"""Quick analysis of a freeze auto-dump file.""" +import json, sys +from collections import Counter + +path = sys.argv[1] if len(sys.argv) > 1 else \ + 'F:/Projects/TombaRecomp/psx_freeze_dump_psx-runtime_1778800465.json' + +with open(path) as f: + d = json.load(f) + +print(f'== Dump: {path}') +print(f' wall_clock_epoch={d["wall_clock_epoch"]}') +print(f' wedge={d["wedge_kind_name"]} frame={d["frame_count"]} ' + f'exc_re={d["exception_reentry_blocks"]} ' + f'dispatch_count={d["dispatch_count"]}') +print(f' in_exc={d["in_exception"]} cur_fn={d["current_func"]} ' + f'last_store_pc={d["last_store_pc"]}') +print(f' i_stat={d["i_stat"]} i_mask={d["i_mask"]} ' + f'sio_card_active={d["sio_card_active"]} mc_max={d["mc_max_state"]}') + +print() +print(f'== wtrace_all: {len(d["wtrace_all"])} entries') +addr_c = Counter(e['addr'] for e in d['wtrace_all']) +pc_c = Counter(e['pc'] for e in d['wtrace_all']) +print('Top 15 ADDRS:') +for a, c in addr_c.most_common(15): + print(f' {a}: {c}') +print('Top 15 PCs:') +for p, c in pc_c.most_common(15): + print(f' {p}: {c}') + +print() +print(f'== fn_entry: {len(d["fn_entry"])} entries') +fn_c = Counter(e['func'] for e in d['fn_entry']) +print('Top 10 funcs entered:') +for f_, c in fn_c.most_common(10): + print(f' {f_}: {c}') + +print() +print(f'== restore_trace: {len(d["restore_trace"])} entries') +if d['restore_trace']: + kind_c = Counter(e['name'] for e in d['restore_trace']) + print('Kinds:', dict(kind_c)) + pc_c2 = Counter(e['cpu_pc'] for e in d['restore_trace']) + print('Top 10 cpu_pcs:') + for p, c in pc_c2.most_common(10): + print(f' {p}: {c}') + +print() +print(f'== thread_trace: {len(d["thread_trace"])} entries') +if d['thread_trace']: + kind_c = Counter(e['name'] for e in d['thread_trace']) + print('Kinds:', dict(kind_c)) + +print() +print(f'== sio_pc_trace: {len(d["sio_pc_trace"])} entries') +if d['sio_pc_trace']: + addr_c = Counter(e['addr'] for e in d['sio_pc_trace']) + print('Top 5 SIO addrs:') + for a, c in addr_c.most_common(5): + print(f' {a}: {c}') + +print() +print(f'== frame_history: {len(d["frame_history"])} frames') +if d['frame_history']: + first = d['frame_history'][0] + last = d['frame_history'][-1] + print(f' first frame {first["frame"]}: sr={first["sr"]} i_stat={first["i_stat"]} pad={first["pad"]} disp={first["disp"]}') + print(f' last frame {last["frame"]}: sr={last["sr"]} i_stat={last["i_stat"]} pad={last["pad"]} disp={last["disp"]}') + # see if display went off + off_count = sum(1 for f in d['frame_history'] if f['disp']['off']) + print(f' display_off frames: {off_count}/{len(d["frame_history"])}') diff --git a/tools/_options_session/_b9d0_writes.py b/tools/_options_session/_b9d0_writes.py new file mode 100644 index 00000000..55a378d2 --- /dev/null +++ b/tools/_options_session/_b9d0_writes.py @@ -0,0 +1,33 @@ +"""Search for any writes to the polled flag region 0xB9D0..0xB9E4.""" +import json, sys + +path = sys.argv[1] if len(sys.argv) > 1 else \ + 'F:/Projects/TombaRecomp/psx_freeze_dump_psx-runtime_1778800465.json' + +with open(path) as f: + d = json.load(f) + +LO = 0xB9C0 +HI = 0xB9F0 + +hits = [] +for e in d['wtrace_all']: + a = int(e['addr'], 16) + if LO <= a < HI: + hits.append(e) + +print(f'Writes in [{hex(LO)}..{hex(HI)}): {len(hits)} of {len(d["wtrace_all"])} total') +for e in hits[:30]: + print(f' seq={e["seq"]} addr={e["addr"]} new={e["new"]} pc={e["pc"]} ra={e["ra"]} frame={e["frame"]}') + +# Also check broader kernel-data scan to find what IS being written nearby +print() +print('--- broader scan 0xB000..0xC800 ---') +addr_c = {} +for e in d['wtrace_all']: + a = int(e['addr'], 16) + if 0xB000 <= a < 0xC800: + addr_c[e['addr']] = addr_c.get(e['addr'], 0) + 1 +print(f'Total in 0xB000..0xC800: {sum(addr_c.values())}') +for a, c in sorted(addr_c.items(), key=lambda x: -x[1])[:20]: + print(f' {a}: {c}') diff --git a/tools/_options_session/_beetle_diff.py b/tools/_options_session/_beetle_diff.py new file mode 100644 index 00000000..f362a0f9 --- /dev/null +++ b/tools/_options_session/_beetle_diff.py @@ -0,0 +1,83 @@ +"""Diff critical memory addresses between runtime (4470) and beetle (4380) +to find where Tomba's state machine diverges in OPTIONS-black.""" +import sys, struct +sys.path.insert(0, 'F:/Projects/psxrecomp-v4/tools/_options_session') +import _dbg + +def read_word(port, addr): + try: + return _dbg.read_word(port, addr) + except Exception as e: + return f"ERR: {e}" + +def read_bytes(port, addr, n): + try: + r = _dbg.call(port, 'read_ram', addr=f'0x{addr:08X}', len=n, timeout=4) + if not r.get('ok'): return f"ERR: {r}" + return bytes.fromhex(r['hex']) + except Exception as e: + return f"ERR: {e}" + +# Ping both +p_rt = _dbg.call(4470, "ping", timeout=2) +p_be = _dbg.call(4380, "ping", timeout=2) +print(f"runtime fr={p_rt.get('frame','?')} | beetle fr={p_be.get('frame','?')}") +print() + +# Critical addresses to compare +print(f"{'addr':>12} {'runtime':>12} {'beetle':>12} {'match':>6}") +addrs = [ + (0x1F8001D4, "scratchpad+0x1D4 (state-struct ptr)"), + (0x80097520, "fn ptr table+0"), + (0x80097524, "fn ptr table+4 (state-0 helper)"), + (0x80097528, "fn ptr table+8"), + (0x8009752C, "fn ptr table+C"), + (0x8009B3A0, "state-0 helper return ptr (first word)"), + (0x8009B3D4, "*** mem[ptr+0x34] high half check"), + (0x8009EB58, "side-path read"), +] +for addr, label in addrs: + rt = read_word(4470, addr) + be = read_word(4380, addr) + if isinstance(rt, int) and isinstance(be, int): + m = "OK" if rt == be else "*DIFF*" + print(f" 0x{addr:08X} 0x{rt:08X} 0x{be:08X} {m} {label}") + else: + print(f" 0x{addr:08X} {rt} {be} ? {label}") + +# Compare the full state struct (256 bytes from runtime's ptr) +print() +print("=== Full state struct comparison ===") +rt_ptr = read_word(4470, 0x1F8001D4) +be_ptr = read_word(4380, 0x1F8001D4) +print(f"runtime ptr = 0x{rt_ptr:08X}, beetle ptr = 0x{be_ptr:08X}") +if rt_ptr == be_ptr and isinstance(rt_ptr, int): + rt_buf = read_bytes(4470, rt_ptr, 256) + be_buf = read_bytes(4380, be_ptr, 256) + if isinstance(rt_buf, bytes) and isinstance(be_buf, bytes): + for i in range(0, 256, 16): + rt_row = rt_buf[i:i+16] + be_row = be_buf[i:i+16] + if rt_row != be_row: + diff = ' '.join('!!' if rt_row[j] != be_row[j] else '..' for j in range(16)) + print(f" +0x{i:03X} RT: {' '.join(f'{x:02x}' for x in rt_row)}") + print(f" BE: {' '.join(f'{x:02x}' for x in be_row)}") + print(f" {diff}") + print() + +# Compare 0x8009B3A0 helper return struct too +print() +print("=== 0x8009B3A0 helper-return struct (256 bytes) ===") +rt_buf = read_bytes(4470, 0x8009B3A0, 256) +be_buf = read_bytes(4380, 0x8009B3A0, 256) +if isinstance(rt_buf, bytes) and isinstance(be_buf, bytes): + any_diff = False + for i in range(0, 256, 16): + rt_row = rt_buf[i:i+16] + be_row = be_buf[i:i+16] + if rt_row != be_row: + any_diff = True + print(f" +0x{i:03X} RT: {' '.join(f'{x:02x}' for x in rt_row)}") + print(f" BE: {' '.join(f'{x:02x}' for x in be_row)}") + if not any_diff: + print(" (IDENTICAL)") diff --git a/tools/_options_session/_bmp2png.py b/tools/_options_session/_bmp2png.py new file mode 100644 index 00000000..f966ab84 --- /dev/null +++ b/tools/_options_session/_bmp2png.py @@ -0,0 +1,7 @@ +"""Convert one or more BMPs (cmd-line args) into PNGs of the same name.""" +from PIL import Image +import sys +for f in sys.argv[1:]: + out = f.rsplit('.', 1)[0] + '.png' + Image.open(f).convert('RGB').save(out) + print(f"{f} -> {out}") diff --git a/tools/_options_session/_capture_now.py b/tools/_options_session/_capture_now.py new file mode 100644 index 00000000..b9c44eda --- /dev/null +++ b/tools/_options_session/_capture_now.py @@ -0,0 +1,56 @@ +"""Capture live state on whichever backend is reachable, RIGHT NOW. + +Reads: + - dispatch miss totals (runtime only) + - frame counters + - the two probe cells (0x80090CAC, 0x80090DA0) on both + - surrounding range 0x80090C80..0x80090DE0 on both + - hex diff of the surrounding range + +No probes are armed — this is a pure ring/state read. Always-on rings +are preserved; we only read what's already captured. +""" +from __future__ import annotations +import sys, os +sys.path.insert(0, os.path.dirname(os.path.abspath(__file__))) +from _dbg import call, read_block, read_word, RUNTIME_PORT, BEETLE_PORT + +PROBE_CELLS = [0x80090CAC, 0x80090DA0] +RANGE_LO = 0x80090C80 +RANGE_HI = 0x80090DE0 + +def safe(port, cmd, **kw): + try: return call(port, cmd, **kw) + except Exception as e: return {"error": str(e)} + +print("=== ping / frame / dispatch ===") +rp = safe(RUNTIME_PORT, "ping") +bp = safe(BEETLE_PORT, "ping") +print(f"runtime: {rp}") +print(f"beetle : {bp}") + +print("\n=== probe cells ===") +print(f"{'addr':<14} {'runtime':<12} {'beetle':<12} {'eq?':<4}") +for a in PROBE_CELLS: + try: rv = read_word(RUNTIME_PORT, a) + except Exception as e: rv = -1; rv_err = str(e) + try: bv = read_word(BEETLE_PORT, a) + except Exception as e: bv = -1; bv_err = str(e) + eq = "Y" if rv == bv else "N" + print(f"0x{a:08X} 0x{rv:08X} 0x{bv:08X} {eq}") + +print(f"\n=== range 0x{RANGE_LO:08X}..0x{RANGE_HI:08X} (diff only) ===") +try: + r = read_block(RUNTIME_PORT, RANGE_LO, RANGE_HI - RANGE_LO) + b = read_block(BEETLE_PORT, RANGE_LO, RANGE_HI - RANGE_LO) + n_diff = 0 + print(f"{'addr':<12} runtime beetle") + for i in range(0, len(r), 4): + rw = int.from_bytes(r[i:i+4], "little") + bw = int.from_bytes(b[i:i+4], "little") + if rw != bw: + n_diff += 1 + print(f"0x{RANGE_LO+i:08X} {rw:08X} {bw:08X}") + print(f"\n{n_diff} divergent words out of {(RANGE_HI-RANGE_LO)//4}") +except Exception as e: + print(f"range read failed: {e}") diff --git a/tools/_options_session/_capture_options_baseline.py b/tools/_options_session/_capture_options_baseline.py new file mode 100644 index 00000000..0b90bda9 --- /dev/null +++ b/tools/_options_session/_capture_options_baseline.py @@ -0,0 +1,86 @@ +"""Capture beetle's OPTIONS-screen baseline + runtime's current state. + +After this, when the user presses OPTIONS on runtime (with delay) we +can query the SAME windows on runtime and diff against this baseline. +No racing — always-on rings give us retroactive visibility. +""" +from __future__ import annotations +import sys, os, json, time +sys.path.insert(0, os.path.dirname(os.path.abspath(__file__))) +from _dbg import call, RUNTIME_PORT, BEETLE_PORT + + +def safe(port, cmd, **kw): + try: return call(port, cmd, timeout=20, **kw) + except Exception as e: return {"error": str(e)} + + +def capture(port, label): + out = {"label": label, "port": port, "ts": time.time()} + p = safe(port, "ping") + out["ping"] = p + out["history"] = safe(port, "history") + out["wtrace_all_stats"] = safe(port, "wtrace_all_stats") + + # Pull the entire always-on ring (just the OPTIONS area writes via filter) + # Cluster around 0x80090C00..0x80091000 — wider net than first probe. + out["wtrace_all_dump_optstate"] = safe(port, "wtrace_all_dump", + addr_lo="0x80090C00", addr_hi="0x80091000", count=2048) + + # Also full last 4K writes (unfiltered) so we can mine for unexpected cells. + out["wtrace_all_dump_tail"] = safe(port, "wtrace_all_dump", count=4096) + + h = out["history"] + if h.get("ok"): + newest = h["newest"] + start = max(0, newest - 199) + out["frame_range_start"] = start + out["frame_range_end"] = newest + out["frame_timeseries"] = safe(port, "frame_timeseries", start=start, end=newest) + out["get_frame_newest"] = safe(port, "get_frame", frame=newest) + + if label == "runtime": + out["freeze_check"] = safe(port, "freeze_check", window=512) + return out + + +print("Capturing OPTIONS baseline (beetle = good state; runtime = whatever it is now)…") +snap = { + "ts": time.strftime("%Y-%m-%dT%H:%M:%S"), + "purpose": "OPTIONS-screen baseline (beetle), runtime current-state", + "runtime": capture(RUNTIME_PORT, "runtime"), + "beetle": capture(BEETLE_PORT, "beetle"), +} + +out_dir = os.path.join(os.environ.get("TEMP", "/tmp"), "optsess") +os.makedirs(out_dir, exist_ok=True) +path = os.path.join(out_dir, f"options_baseline_{int(time.time())}.json") +with open(path, "w") as f: + json.dump(snap, f, indent=2) +print(f"wrote {path} ({os.path.getsize(path)} bytes)") + +# Summary +for side in ("runtime", "beetle"): + s = snap[side] + pg = s["ping"] + wa = s["wtrace_all_stats"] + ws = s["wtrace_all_dump_optstate"] + print(f"\n=== {side} ===") + print(f" frame={pg.get('frame')}") + print(f" wtrace_all total={wa.get('total')} cap={wa.get('capacity')}") + print(f" optstate-range writes in ring: {ws.get('emitted', 0)} of {ws.get('available', 0)} ring entries") + # Distinct addrs in optstate window + entries = ws.get("entries", []) + distinct = sorted({e["addr"] for e in entries}) + print(f" distinct optstate addrs: {len(distinct)}") + if distinct: + print(f" first 8: {distinct[:8]}") + +# Live read of the probe cells we care about +print("\n=== live read of OPTIONS-probe cells ===") +def lr(port, addr): + r = safe(port, "read_ram", addr=addr, len=4) + return r.get("hex", "??") +for cell in ("0x80090CAC", "0x80090DA0", "0x80090DB8", "0x80090DA4", "0x80090DAC", "0x80090DB4"): + rv = lr(RUNTIME_PORT, cell); bv = lr(BEETLE_PORT, cell) + print(f" {cell} runtime={rv} beetle={bv} {'DIFF' if rv != bv else 'same'}") diff --git a/tools/_options_session/_capture_stuck.py b/tools/_options_session/_capture_stuck.py new file mode 100644 index 00000000..14d04a50 --- /dev/null +++ b/tools/_options_session/_capture_stuck.py @@ -0,0 +1,75 @@ +"""Capture the current divergence snapshot between runtime and beetle +when runtime is in a stuck/black-screen state. + +Reads from the rings we just built — no arming, no probes: + - always-on wtrace_all on BOTH (last 200 writes) + - per-frame ring last 200 frames on BOTH (CPU/display/IRQ over time) + - freeze_check on runtime (handler/dispatch/dirty diagnostics) + +Writes everything to /tmp/optsess/stuck_.json so we don't +keep re-querying as state churns. +""" +from __future__ import annotations +import sys, os, json, time +sys.path.insert(0, os.path.dirname(os.path.abspath(__file__))) +from _dbg import call, RUNTIME_PORT, BEETLE_PORT + + +def safe(port, cmd, **kw): + try: return call(port, cmd, **kw, timeout=15) + except Exception as e: return {"error": str(e)} + + +def capture(port, label): + out = {"label": label, "port": port} + out["ping"] = safe(port, "ping") + out["history"] = safe(port, "history") + out["wtrace_all_stats"] = safe(port, "wtrace_all_stats") + out["wtrace_all_dump"] = safe(port, "wtrace_all_dump", count=512) + # Per-frame ring: pull last 200 frames + h = out["history"] + if h.get("ok"): + newest = h["newest"] + start = max(0, newest - 199) + out["frame_range_start"] = start + out["frame_range_end"] = newest + out["frame_timeseries"] = safe(port, "frame_timeseries", start=start, end=newest) + out["get_frame_newest"] = safe(port, "get_frame", frame=newest) + if label == "runtime": + out["freeze_check"] = safe(port, "freeze_check", window=512) + out["wtrace_ranges"] = safe(port, "wtrace_ranges") + return out + + +print("Capturing snapshot…") +snap = { + "ts": time.strftime("%Y-%m-%dT%H:%M:%S"), + "runtime": capture(RUNTIME_PORT, "runtime"), + "beetle": capture(BEETLE_PORT, "beetle"), +} + +out_dir = os.path.join(os.environ.get("TEMP", "/tmp"), "optsess") +os.makedirs(out_dir, exist_ok=True) +out_path = os.path.join(out_dir, f"stuck_{int(time.time())}.json") +with open(out_path, "w") as f: + json.dump(snap, f, indent=2) +print(f"wrote {out_path} ({os.path.getsize(out_path)} bytes)") + +# Print a one-screen summary +print(f"\nruntime: frame={snap['runtime']['ping']['frame']} disp_miss={snap['runtime']['ping']['dispatch_miss_total']}") +print(f"beetle : frame={snap['beetle']['ping']['frame']}") +fc = snap["runtime"]["freeze_check"] +if fc.get("ok"): + print(f"\nruntime freeze_check:") + for k in ("current_func", "last_store_pc", "i_stat", "i_mask", + "exception_reentry_blocks", "dirty_ram_blocks", "dispatch_count", + "frame_count", "in_exception", "sio_stat", "mc_max_state"): + if k in fc: print(f" {k:32s} = {fc[k]}") + +# Last 5 writes on each backend's catch-all +print(f"\nruntime wtrace_all newest 3:") +for e in snap["runtime"]["wtrace_all_dump"]["entries"][-3:]: + print(f" seq={e['seq']} addr={e['addr']} new={e['new']} pc={e['pc']} ra={e['ra']} fr={e['frame']}") +print(f"beetle wtrace_all newest 3:") +for e in snap["beetle"]["wtrace_all_dump"]["entries"][-3:]: + print(f" seq={e['seq']} addr={e['addr']} new={e['new']} pc={e['pc']} ra={e['ra']} fr={e['frame']}") diff --git a/tools/_options_session/_card_bytes.py b/tools/_options_session/_card_bytes.py new file mode 100644 index 00000000..a102c83a --- /dev/null +++ b/tools/_options_session/_card_bytes.py @@ -0,0 +1,95 @@ +"""Extract the card-data byte stream the BIOS received during OPTIONS-black. + +The kernel SIO byte ISR at 0xBFC16024 emits `sb v0,0x0(k0)` — every byte +the card delivers gets stored at k0 (which increments per byte). Filter +wtrace_all by that PC, sort by seq, and reconstruct the byte stream. +Compare to tomba.0.mcr / tomba.1.mcr. +""" +import json, os, sys +from collections import defaultdict + +path = sys.argv[1] if len(sys.argv) > 1 else \ + 'F:/Projects/TombaRecomp/psx_freeze_dump_psx-runtime_1778800465.json' +mcr_root = 'F:/Projects/TombaRecomp/saves' + +with open(path) as f: + d = json.load(f) + +# Filter by the kernel-SIO-handler byte-store PC. The handler lives at +# BIOS 0xBFC16024, but the recompiler runs the RAM mirror at 0x00006524 +# (= 0xBFC16024 - 0xBFC10000 + 0x500). Either could show up depending +# on whether code came from ROM (BIOS path) or RAM-mirror (kernel). +STORE_PCS = ('0xBFC16024', '0x00006524', '0x06524') + +hits = [e for e in d['wtrace_all'] + if e['pc'].upper() in (p.upper() for p in STORE_PCS) + and e.get('w', 1) == 1] +print(f'BIOS card-byte stores: {len(hits)} hits') +if not hits: + sys.exit(1) + +hits.sort(key=lambda e: int(e['seq'])) + +# Group by contiguous bursts. Each card command reads N bytes consecutively +# into a buffer; bursts are separated by gaps in seq (handler not running). +bursts = [] +cur = [] +for i, e in enumerate(hits): + if cur and int(e['seq']) > int(cur[-1]['seq']) + 5000: + bursts.append(cur) + cur = [] + cur.append(e) +if cur: + bursts.append(cur) +print(f'Bursts: {len(bursts)}') +for i, b in enumerate(bursts): + addrs = [int(e['addr'], 16) for e in b] + print(f' Burst {i}: {len(b)} bytes, addr range ' + f'{hex(min(addrs))}..{hex(max(addrs))}, seq ' + f'{b[0]["seq"]}..{b[-1]["seq"]}') + +# Examine the most-recent (likely complete) burst. +b = bursts[-1] if bursts else [] +print(f'\n=== Last burst ({len(b)} bytes) ===') +print('First 32 entries:') +for e in b[:32]: + print(f' seq={e["seq"]} addr={e["addr"]} val=0x{int(e["new"], 16) & 0xFF:02X} frame={e["frame"]}') +print('...') +print('Last 16 entries:') +for e in b[-16:]: + print(f' seq={e["seq"]} addr={e["addr"]} val=0x{int(e["new"], 16) & 0xFF:02X} frame={e["frame"]}') + +# Bytes in the order they were stored. +recv = bytes(int(e['new'], 16) & 0xFF for e in b) +print(f'\nReceived stream hex (first 256 bytes):') +for i in range(0, min(256, len(recv)), 32): + print(f' {i:04x}: ' + ' '.join(f'{b:02x}' for b in recv[i:i+32])) + +# Compute the BIOS-style XOR checksum over the first 128 bytes. +if len(recv) >= 129: + xor = 0 + for byte in recv[:128]: + xor ^= byte + print(f'\nXOR of first 128 bytes: 0x{xor:02X}') + print(f'Byte at offset 128 (claimed checksum): 0x{recv[128]:02X}') + print(f'Match: {xor == recv[128]}') + +# Compare to the actual save files. +for fp in ('F:/Projects/TombaRecomp/saves/card1.mcd', + 'F:/Projects/TombaRecomp/saves/card2.mcd'): + fname = os.path.basename(fp) + if not os.path.exists(fp): + print(f'\n{fname}: not found') + continue + with open(fp, 'rb') as fh: + mcr = fh.read() + print(f'\n{fname}: {len(mcr)} bytes') + print('First 256 bytes:') + for i in range(0, 256, 32): + print(f' {i:04x}: ' + ' '.join(f'{b:02x}' for b in mcr[i:i+32])) + # See if our recv stream matches any window of the mcr. + if len(recv) > 32: + needle = recv[:32] + idx = mcr.find(needle) + print(f' Match of first 32 received bytes anywhere in {fname}: ' + f'{hex(idx) if idx >= 0 else "NO"}') diff --git a/tools/_options_session/_card_bytes2.py b/tools/_options_session/_card_bytes2.py new file mode 100644 index 00000000..4d23f7f3 --- /dev/null +++ b/tools/_options_session/_card_bytes2.py @@ -0,0 +1,96 @@ +"""Properly split the SIO byte stream into sector-sized groups. + +Each sector read fills the buffer at 0xBE48..0xBEC7 (128 bytes). k0 resets +when a new sector starts. Group by addr-decrease, then compare each +captured sector against the real card1.mcd content. +""" +import json, os, sys + +path = sys.argv[1] if len(sys.argv) > 1 else \ + 'F:/Projects/TombaRecomp/psx_freeze_dump_psx-runtime_1778800465.json' + +with open(path) as f: + d = json.load(f) + +STORE_PCS = {'0xBFC16024', '0x00006524'} +hits = [e for e in d['wtrace_all'] + if e['pc'].upper() in {p.upper() for p in STORE_PCS} + and e.get('w', 1) == 1] +hits.sort(key=lambda e: int(e['seq'])) +print(f'{len(hits)} byte-store events captured') + +# Group by sector: a new sector starts when the destination address +# decreases (or, more reliably, when it equals the lowest seen base). +addrs = [int(e['addr'], 16) for e in hits] +base = min(addrs) +print(f'Buffer base: 0x{base:04X}') + +sectors = [] +cur = [] +prev_addr = -1 +for e in hits: + a = int(e['addr'], 16) + if a < prev_addr or (a == base and cur): + sectors.append(cur) + cur = [] + cur.append(e) + prev_addr = a +if cur: + sectors.append(cur) + +print(f'Sectors identified: {len(sectors)}') +for i, s in enumerate(sectors): + addrs = [int(e['addr'], 16) for e in s] + print(f' Sector {i}: {len(s)} bytes, addr range 0x{min(addrs):04X}..0x{max(addrs):04X}, ' + f'frames {s[0]["frame"]}..{s[-1]["frame"]}') + +def sector_bytes(s): + """Reconstruct sector buffer from the stores (last write wins per addr).""" + buf = {} + for e in s: + buf[int(e['addr'], 16)] = int(e['new'], 16) & 0xFF + base = min(buf) + return bytes(buf[base + i] if (base + i) in buf else 0 + for i in range(max(buf) - base + 1)) + +# Pull real card data for comparison. +with open('F:/Projects/TombaRecomp/saves/card1.mcd', 'rb') as fh: + card1 = fh.read() + +# A PS1 memcard read typically starts at the directory (sector 0), then +# reads sectors 1..15. Each "frame" in the .mcd is 128 bytes. +for i, s in enumerate(sectors): + recv = sector_bytes(s) + print(f'\n=== Sector {i}: {len(recv)} bytes ===') + print('Received hex (full):') + for off in range(0, len(recv), 32): + print(f' {off:03x}: ' + ' '.join(f'{b:02x}' for b in recv[off:off+32])) + + # Try to find a window in card1.mcd that this matches. + if len(recv) >= 8: + for fr in range(0, 16): + real = card1[fr*128:(fr+1)*128] + if recv[:len(recv)] == real[:len(recv)]: + print(f' EXACT match: card1.mcd frame {fr}') + break + # Try matching the prefix + common = 0 + for j in range(min(len(recv), len(real))): + if recv[j] == real[j]: + common += 1 + else: + break + if common >= 8: + print(f' Prefix match with card1.mcd frame {fr}: {common}/{len(recv)} bytes') + # If mismatch starts mid-stream, show the divergence + if common < len(recv): + div = common + print(f' Divergence at offset 0x{div:02X}:') + print(f' received[{div}..{div+16}]: ' + ' '.join(f'{b:02x}' for b in recv[div:div+16])) + print(f' real [{div}..{div+16}]: ' + ' '.join(f'{b:02x}' for b in real[div:div+16])) + # See if received[div:] matches real[div+1:] (shifted by 1) + if div+1 < len(real): + shifted = real[div+1:div+1+min(16, len(recv)-div)] + match_shift = recv[div:div+len(shifted)] == shifted + print(f' SHIFT-BY-1 match: {match_shift}') + break diff --git a/tools/_options_session/_check_checksum.py b/tools/_options_session/_check_checksum.py new file mode 100644 index 00000000..7c0a53c8 --- /dev/null +++ b/tools/_options_session/_check_checksum.py @@ -0,0 +1,38 @@ +"""Compute expected per-frame XOR for card1.mcd frames 0..3 and compare to +the running XOR captured in the dump trace (at 0x7560 after byte 127 store).""" +import json, sys + +dump = sys.argv[1] if len(sys.argv) > 1 else \ + 'F:/Projects/TombaRecomp/psx_freeze_dump_psx-runtime_1778800465.json' + +with open('F:/Projects/TombaRecomp/saves/card1.mcd', 'rb') as fh: + card = fh.read() + +print(f"Card file: {len(card)} bytes ({len(card)//128} frames)") + +# Compute XOR over each frame for sectors 0..3 +for frame in range(0, 16): + fbytes = card[frame*128:(frame+1)*128] + msb = (frame >> 8) & 0xFF + lsb = frame & 0xFF + xor_bytes = 0 + for b in fbytes: + xor_bytes ^= b + expected = msb ^ lsb ^ xor_bytes + print(f" Frame {frame:2d}: MSB={msb:02X} LSB={lsb:02X} " + f"XOR(bytes 0..127)={xor_bytes:02X} " + f"expected_checksum_byte={expected:02X} " + f"on-disk-byte-127={fbytes[127]:02X} " + f"first_4_bytes={fbytes[0]:02X} {fbytes[1]:02X} {fbytes[2]:02X} {fbytes[3]:02X}") + +# Now find each sector's running XOR end value in the dump +with open(dump) as f: + d = json.load(f) + +print("\n\nRunning XOR end-of-sector values from trace (writes to 0x7560 from pc=0xBFC155AC):") +events = d['wtrace_all'] +ac_writes = [(i, e) for i, e in enumerate(events) + if e['pc'].upper() == '0XBFC155AC' and int(e['addr'], 16) == 0x7560] +for i, e in ac_writes: + val = int(e['new'], 16) & 0xFF + print(f" idx={i} seq={e['seq']} fr={e.get('frame')} 0x7560 -> 0x{val:02X}") diff --git a/tools/_options_session/_compare_frames.py b/tools/_options_session/_compare_frames.py new file mode 100644 index 00000000..b135645e --- /dev/null +++ b/tools/_options_session/_compare_frames.py @@ -0,0 +1,16 @@ +"""Are card1.mcd frames 1..15 byte-identical? If yes, the 'frame 1' label +in _card_bytes2.py output may actually be frames 1, 2, 3, 4 etc. +Print full hex for each first-byte-differing pair.""" +with open('F:/Projects/TombaRecomp/saves/card1.mcd', 'rb') as fh: + card = fh.read() + +f1 = card[128:256] +for fr in range(0, 16): + fb = card[fr*128:(fr+1)*128] + # diff vs f1 + diffs = [(i, f1[i], fb[i]) for i in range(128) if f1[i] != fb[i]] + if diffs: + diff_str = ', '.join(f'@{i}(f1={a:02X},f{fr}={b:02X})' for i, a, b in diffs[:6]) + else: + diff_str = '(IDENTICAL to frame 1)' + print(f"Frame {fr:2d}: {diff_str}") diff --git a/tools/_options_session/_dbg.py b/tools/_options_session/_dbg.py new file mode 100644 index 00000000..a2ae66f2 --- /dev/null +++ b/tools/_options_session/_dbg.py @@ -0,0 +1,86 @@ +"""Tiny TCP-debug-server client used by the OPTIONS-black session. + +Single source of truth for talking to: + - psx-runtime (TombaRecomp build) on port 4470 + - psx-beetle on port 4380 + +No game-specific knowledge here. Just request/response and command-name +adapters so the rest of the session scripts read the same way against +either backend, even though the wire verbs differ +(e.g. wtrace_add vs wtrace_arm). +""" +from __future__ import annotations +import json, socket, sys, time + +RUNTIME_PORT = 4470 +BEETLE_PORT = 4380 + + +def call(port: int, cmd: str, timeout: float = 30.0, **kw): + payload = {"id": 1, "cmd": cmd, **kw} + s = socket.create_connection(("127.0.0.1", port), timeout=timeout) + try: + s.sendall((json.dumps(payload) + "\n").encode()) + buf = bytearray() + while not buf.endswith(b"\n"): + chunk = s.recv(1 << 20) + if not chunk: + break + buf.extend(chunk) + finally: + s.close() + return json.loads(buf.decode("utf-8", "replace").strip() or "{}") + + +def hx(v): + if isinstance(v, int): + return v + if isinstance(v, str): + return int(v, 16) if v.lower().startswith("0x") else int(v) + return v + + +def read_word(port: int, addr: int) -> int: + """Little-endian word read at addr via read_ram.""" + r = call(port, "read_ram", addr=f"0x{addr:08X}", len=4) + if not r.get("ok"): + raise RuntimeError(f"read_ram failed at 0x{addr:08X}: {r}") + b = bytes.fromhex(r["hex"]) + return int.from_bytes(b, "little") + + +def read_block(port: int, addr: int, n: int) -> bytes: + out = bytearray() + off = 0 + while off < n: + chunk = min(0x40000, n - off) + r = call(port, "read_ram", addr=f"0x{addr+off:08X}", len=chunk) + if not r.get("ok"): + raise RuntimeError(f"read_ram failed at 0x{addr+off:08X}: {r}") + out.extend(bytes.fromhex(r["hex"])) + off += chunk + return bytes(out) + + +def ping_both(): + out = {} + for name, port in [("runtime", RUNTIME_PORT), ("beetle", BEETLE_PORT)]: + try: + out[name] = call(port, "ping", timeout=3) + except Exception as e: + out[name] = {"error": str(e)} + return out + + +if __name__ == "__main__": + if len(sys.argv) == 1 or sys.argv[1] == "ping": + for k, v in ping_both().items(): + print(f"{k:8} {v}") + sys.exit(0) + cmd = sys.argv[1] + port = int(sys.argv[2]) + args = {} + for a in sys.argv[3:]: + k, _, v = a.partition("=") + args[k] = v + print(json.dumps(call(port, cmd, **args), indent=2)) diff --git a/tools/_options_session/_decode_b0_callers.py b/tools/_options_session/_decode_b0_callers.py new file mode 100644 index 00000000..bda9e609 --- /dev/null +++ b/tools/_options_session/_decode_b0_callers.py @@ -0,0 +1,58 @@ +"""Read MIPS at the B0 call sites to identify what BIOS function each calls. +The t1 register holds the B0 function index when calling B0 trampoline.""" +import sys, struct +sys.path.insert(0, 'F:/Projects/psxrecomp-v4/tools/_options_session') +import _dbg + +call_sites = [0x800171F8, 0x800170BC, 0x8006825C] +# These are RA values (i.e., return-from-call PCs). The JAL instruction was at ra-8. + +def disasm_li(insn): + """Decode `li/addiu rt, rs, imm` or similar t1-loading instructions.""" + op = (insn >> 26) & 0x3F + rs = (insn >> 21) & 0x1F + rt = (insn >> 16) & 0x1F + imm = insn & 0xFFFF + if imm > 0x7FFF: + imm = imm - 0x10000 + funct = insn & 0x3F + if op == 0x9: # addiu + return f"addiu r{rt},r{rs},{imm:#x}" + if op == 0xD: # ori + return f"ori r{rt},r{rs},{imm:#x}" + if op == 0xF: # lui + return f"lui r{rt},{imm:#x}" + if op == 0: # SPECIAL + if funct == 9: + return f"jalr r{rs}" + if funct == 8: + return f"jr r{rs}" + return f"SPECIAL funct={funct:#x}" + if op == 0x3: # jal + target = (insn & 0x3FFFFFF) << 2 + return f"jal target_relative=0x{target:08x}" + if op == 0x2: # j + target = (insn & 0x3FFFFFF) << 2 + return f"j target_relative=0x{target:08x}" + return f"op={op:#x} insn={insn:08x}" + +for site in call_sites: + print(f"=== Call site (return-to PC) 0x{site:08X} ===") + print(f" JAL was at 0x{site-8:08X}") + # Read 8 instructions before site (32 bytes back) + base = site - 0x20 + r = _dbg.call(4470, "read_ram", addr=f"0x{base:08X}", len=0x30, timeout=3) + if not r.get("ok"): + print(f" read_ram failed: {r}") + continue + b = bytes.fromhex(r["hex"]) + for i in range(0, len(b), 4): + addr = base + i + if addr >= site + 0x4: break + insn = struct.unpack_from(" 1 else \ + 'F:/Projects/TombaRecomp/psx_freeze_dump_psx-runtime_1778822828.json' + +with open(dump) as f: + d = json.load(f) + +print(f"=== Core ===") +print(f" backend: {d['backend']}") +print(f" wall_clock_epoch: {d['wall_clock_epoch']}") +print(f" frame_count: {d['frame_count']}") +print(f" psx_cycle_count: {d['psx_cycle_count']:,}") +print(f" in_exception: {d['in_exception']}") +print(f" current_func: {d['current_func']}") +print(f" last_store_pc: {d['last_store_pc']}") +print(f" exc_entries: {d['exception_entries']:,}") +print(f" exc_reentry_blocks: {d['exception_reentry_blocks']:,}") +print(f" dispatch_count: {d['dispatch_count']:,}") +print(f" dirty_ram_blocks: {d['dirty_ram_blocks']:,}") +print(f" dirty_ram_insns: {d['dirty_ram_insns']:,}") +print(f" wedge_kind: {d.get('wedge_kind','?')} ({d.get('wedge_kind_name','?')})") +print(f" i_stat: {d['i_stat']}") +print(f" i_mask: {d['i_mask']}") +print(f" mc_max_state: {d['mc_max_state']}") +print(f" sio_card_active: {d['sio_card_active']}") +print(f" sio_stat / sio_ctrl: {d['sio_stat']} / {d['sio_ctrl']}") +print(f" caps: {d.get('caps','?')}") + +db = d.get('dirty_block', []) +print(f"\n=== dirty_block ring: {len(db)} entries ===") +if not db: + print(" EMPTY — interpreter never ran (or accessor failed)") + sys.exit(0) + +# Spread by frame +frames = collections.Counter(e['frame'] for e in db) +print(f" frame range: {min(frames)}..{max(frames)} ({len(frames)} distinct)") +print(f" top frames: " + ", ".join(f"fr{f}={c}" for f,c in frames.most_common(8))) + +# Most frequent target +target_count = collections.Counter(e['target'] for e in db) +print(f"\n=== top dirty-block targets (the chain handlers being hammered) ===") +for tgt, cnt in target_count.most_common(20): + print(f" target={tgt}: {cnt} entries") + +# Top RA (caller) +ra_count = collections.Counter(e['ra'] for e in db) +print(f"\n=== top RA values (who called these blocks) ===") +for ra, cnt in ra_count.most_common(15): + print(f" ra={ra}: {cnt} entries") + +# What are the LAST N entries — show full +print(f"\n=== Last 30 dirty_block entries (newest) ===") +for e in db[-30:]: + print(f" seq={e['seq']:>10} fr={e['frame']:>3} target={e['target']} ra={e['ra']} " + f"a0={e.get('a0')} sp={e.get('sp')}") + +# Look for "tight loops": pairs (target, ra) that repeat heavily +pair_count = collections.Counter((e['target'], e['ra']) for e in db) +print(f"\n=== Top (target, ra) pairs — exact tight-loop signature ===") +for (t, r), cnt in pair_count.most_common(15): + print(f" target={t} ra={r}: {cnt} entries") diff --git a/tools/_options_session/_dump_bios_bytes.py b/tools/_options_session/_dump_bios_bytes.py new file mode 100644 index 00000000..659fbfdb --- /dev/null +++ b/tools/_options_session/_dump_bios_bytes.py @@ -0,0 +1,11 @@ +import struct, sys +with open('F:/Projects/psxrecomp-v4/bios/SCPH1001.BIN', 'rb') as f: + data = f.read() +# Read inputs as pc, length +start_pc = int(sys.argv[1], 16) if len(sys.argv) > 1 else 0xBFC16060 +length = int(sys.argv[2], 0) if len(sys.argv) > 2 else 0x40 +off0 = start_pc - 0xBFC00000 +for i in range(0, length, 4): + w = struct.unpack_from(' 2 else 0x200 +r = _dbg.call(4470, 'read_ram', addr=f'0x{addr:08X}', len=size, timeout=4) +b = bytes.fromhex(r['hex']) +print(f"Contents of 0x{addr:08X} ({size} bytes):") +for i in range(0, len(b), 32): + line = ' '.join(f'{x:02x}' for x in b[i:i+32]) + non_zero = sum(1 for x in b[i:i+32] if x != 0) + marker = "" if non_zero == 0 else f" ({non_zero}/32 non-zero)" + print(f" +0x{i:03X}: {line}{marker}") diff --git a/tools/_options_session/_event_spin.py b/tools/_options_session/_event_spin.py new file mode 100644 index 00000000..1ff41f06 --- /dev/null +++ b/tools/_options_session/_event_spin.py @@ -0,0 +1,44 @@ +"""Find what's calling TestEvent / what Tomba is spinning on.""" +import json, sys +from collections import Counter + +path = sys.argv[1] if len(sys.argv) > 1 else \ + 'F:/Projects/TombaRecomp/psx_freeze_dump_psx-runtime_1778800465.json' + +with open(path) as f: + d = json.load(f) + +# fn_entry: who calls the Tomba chain handlers (RA tells us the caller) +print('=== fn_entry RA distribution for Tomba functions ===') +for target in ('0x80068024', '0x80068098', '0x80068554'): + ra_c = Counter(e['ra'] for e in d['fn_entry'] if e['func'] == target) + print(f'\n{target}:') + for ra, c in ra_c.most_common(5): + print(f' RA {ra}: {c}') + +print() +print('=== Top 20 RA addrs across ALL fn_entry ===') +ra_c = Counter(e['ra'] for e in d['fn_entry']) +for ra, c in ra_c.most_common(20): + print(f' RA {ra}: {c}') + +# Check stores to the EvCB region (typical EvCB starts at 0xE000+) +print() +print('=== Stores in EvCB region (0xE000..0xEC00) ===') +ev_writes = [e for e in d['wtrace_all'] if 0xE000 <= int(e['addr'], 16) < 0xEC00] +print(f'Total EvCB writes: {len(ev_writes)}') +addr_c = Counter(e['addr'] for e in ev_writes) +print('By addr:') +for a, c in addr_c.most_common(15): + print(f' {a}: {c}') +# Show a sample of unique values written, to see what modes are being set +val_c = Counter(e['new'] for e in ev_writes) +print('By value:') +for v, c in val_c.most_common(10): + print(f' {v}: {c}') + +# fn_entry order: see the cycle pattern around the chain handlers +print() +print('=== Last 30 fn_entry events (chronological) ===') +for e in d['fn_entry'][-30:]: + print(f' seq={e["seq"]} fn={e["func"]} ra={e["ra"]} a0={e["a0"]} a1={e["a1"]}') diff --git a/tools/_options_session/_event_waits.py b/tools/_options_session/_event_waits.py new file mode 100644 index 00000000..202e416a --- /dev/null +++ b/tools/_options_session/_event_waits.py @@ -0,0 +1,36 @@ +"""Sample fntrace and identify the event IDs Tomba is polling each frame.""" +import sys, time, collections, json +sys.path.insert(0, 'F:/Projects/psxrecomp-v4/tools/_options_session') +import _dbg + +_dbg.call(4470, "fntrace_arm", target="0xFFFFFFFF", timeout=2) +time.sleep(1) + +d = _dbg.call(4470, "fntrace_dump", count=300, timeout=4) +es = d.get('entries', []) +print(f"Got {len(es)} entries") + +# The B0 trampoline is at 0xB0; calls there carry t1=B0 index, a0/a1 = args. +# Filter B0 calls and TestEvent-style entries. +b0 = [e for e in es if e['target'] == '0x000000B0'] +print(f"\nB0 trampoline calls: {len(b0)}") +# Group by (ra, t1) +sigs = collections.Counter((e['ra'], e.get('t1','?')) for e in b0) +print(f"Top (ra, t1=B0_idx) signatures:") +for (ra, t1), c in sigs.most_common(10): + print(f" ra={ra} t1={t1}: {c}") + +# Find every distinct (ra, a0, a1, t1) for B0 calls +sigs2 = collections.Counter((e['ra'], e.get('a0'), e.get('a1'), e.get('t1','?')) for e in b0) +print(f"\nTop (ra, a0, a1, t1) signatures:") +for (ra, a0, a1, t1), c in sigs2.most_common(15): + print(f" ra={ra} t1={t1} a0={a0} a1={a1}: {c}") + +# Now look at non-B0 calls — what's Tomba running? +non_b0 = [e for e in es if e['target'] != '0x000000B0'] +tomba_funcs = collections.Counter(e['target'] for e in non_b0 if e['target'].startswith('0x800')) +print(f"\nTomba (0x800...) functions called:") +for f, c in tomba_funcs.most_common(15): + callers = collections.Counter(e['ra'] for e in non_b0 if e['target'] == f) + top_ra = callers.most_common(3) + print(f" {f}: {c} hits, top callers: {top_ra}") diff --git a/tools/_options_session/_fn_tail.py b/tools/_options_session/_fn_tail.py new file mode 100644 index 00000000..259b54aa --- /dev/null +++ b/tools/_options_session/_fn_tail.py @@ -0,0 +1,22 @@ +import json, sys +dump = sys.argv[1] if len(sys.argv) > 1 else \ + 'F:/Projects/TombaRecomp/psx_freeze_dump_psx-runtime_1778822828.json' +with open(dump) as f: + d = json.load(f) +fe = d['fn_entry'] +print(f'fn_entry count: {len(fe)}') +print(f'Last 40 entries:') +for e in fe[-40:]: + print(f' seq={e["seq"]} fr={e["frame"]} func={e["func"]} ra={e["ra"]} ' + f'a0={e.get("a0","?")} a1={e.get("a1","?")} t1={e.get("t1","?")}') + +print() +print(f'Last 30 wtrace_all entries:') +for e in d['wtrace_all'][-30:]: + print(f' seq={e["seq"]} fr={e["frame"]} pc={e["pc"]} addr={e["addr"]} ->{e.get("new","?")}') + +print() +print(f'Last 20 restore_trace entries:') +for e in d['restore_trace'][-20:]: + print(f' seq={e["seq"]} fr={e["frame"]} kind={e["kind"]} name={e.get("name","?")} ' + f'target={e["target"]} cpu_pc={e["cpu_pc"]} epc={e["epc"]} in_exc={e["in_exc"]}') diff --git a/tools/_options_session/_fn_what_runs.py b/tools/_options_session/_fn_what_runs.py new file mode 100644 index 00000000..e1d427c0 --- /dev/null +++ b/tools/_options_session/_fn_what_runs.py @@ -0,0 +1,30 @@ +"""Arm fntrace, sample, find what Tomba functions actually run during black screen.""" +import sys, time, collections, json +sys.path.insert(0, 'F:/Projects/psxrecomp-v4/tools/_options_session') +import _dbg + +# Make sure fntrace is armed for the entire Tomba RAM range +_dbg.call(4470, "fntrace_arm", target="0x80000000", timeout=2) + +time.sleep(2) + +d = _dbg.call(4470, "fntrace_dump", count=500, timeout=4) +es = d.get('entries', []) +print(f"Got {len(es)} entries (armed: {d.get('armed')})") + +funcs = collections.Counter(e.get('target') for e in es) +print(f"\nTop 20 hottest functions:") +for f, c in funcs.most_common(20): + print(f" {f}: {c} hits") + +# RA distribution per top target +print(f"\nDecomposition of top 5 functions by caller:") +for f, _ in funcs.most_common(5): + callers = collections.Counter(e['ra'] for e in es if e['target'] == f) + print(f" {f}:") + for ra, c in callers.most_common(5): + print(f" ra={ra}: {c}") + +print(f"\nLast 25 entries (newest first):") +for e in es[:25]: + print(f" fr={e.get('frame')} target={e['target']} ra={e['ra']} a0={e.get('a0')} a1={e.get('a1')}") diff --git a/tools/_options_session/_heartbeat_arc.py b/tools/_options_session/_heartbeat_arc.py new file mode 100644 index 00000000..77517c6b --- /dev/null +++ b/tools/_options_session/_heartbeat_arc.py @@ -0,0 +1,20 @@ +"""Print full heartbeat-ring progression to identify the moment frames stopped.""" +import json, sys +dump = sys.argv[1] if len(sys.argv) > 1 else \ + 'F:/Projects/TombaRecomp/psx_freeze_dump_psx-runtime_1778822828.json' +with open(dump) as f: + d = json.load(f) + +hb = sorted(d['heartbeat_ring'], key=lambda e: e['wall']) +print(f"{'idx':>4} {'wall':>11} {'frame':>8} {'cyc':>14} {'fr-d':>5} {'cyc-d':>10} " + f"{'exc_re-d':>10} {'dirty-d':>10} {'cur_fn':>12} {'in_exc':>2}") +for i, e in enumerate(hb): + if i == 0: + print(f"{i:>4} {e['wall']:>11} {e['frame']:>8} {e['cyc']:>14,} " + f"{'-':>5} {'-':>10} {'-':>10} {'-':>10} {e['cur_fn']:>12} {e['in_exc']:>2}") + else: + a = hb[i-1] + print(f"{i:>4} {e['wall']:>11} {e['frame']:>8} {e['cyc']:>14,} " + f"{e['frame']-a['frame']:>5} {e['cyc']-a['cyc']:>10,} " + f"{e['exc_re']-a['exc_re']:>10,} {e['dirty_insns']-a['dirty_insns']:>10,} " + f"{e['cur_fn']:>12} {e['in_exc']:>2}") diff --git a/tools/_options_session/_inspect_entries.py b/tools/_options_session/_inspect_entries.py new file mode 100644 index 00000000..15cf00e7 --- /dev/null +++ b/tools/_options_session/_inspect_entries.py @@ -0,0 +1,30 @@ +import json,os,glob +out_dir = os.path.join(os.environ.get('TEMP','/tmp'),'optsess') +p = sorted(glob.glob(os.path.join(out_dir,'options_baseline_*.json')))[-1] +print('file:', p) +s = json.load(open(p)) + +print() +print('--- runtime: first 6 writes from PC=0x000000BC ---') +ents = s['runtime']['wtrace_all_dump_optstate']['entries'] +for e in [x for x in ents if x['pc']=='0x000000BC'][:6]: + print(e) +print() +print('--- runtime: writes from PC=0xBFC11BF0 (last 3) ---') +for e in [x for x in ents if x['pc']=='0xBFC11BF0'][-3:]: + print(e) +print() +print('--- beetle: first 4 writes (cell DB8 stream) ---') +ents_b = s['beetle']['wtrace_all_dump_optstate']['entries'] +for e in ents_b[:4]: + print(e) +print() +print('--- beetle: last 2 writes ---') +for e in ents_b[-2:]: + print(e) +print() +print('--- runtime: write SIZES distribution ---') +from collections import Counter +print(Counter(e['w'] for e in ents)) +print('--- beetle: write SIZES distribution ---') +print(Counter(e['w'] for e in ents_b)) diff --git a/tools/_options_session/_live_loop.py b/tools/_options_session/_live_loop.py new file mode 100644 index 00000000..a0dbc67a --- /dev/null +++ b/tools/_options_session/_live_loop.py @@ -0,0 +1,43 @@ +"""Query live runtime's recent activity rings to see what's looping.""" +import sys, json, collections +sys.path.insert(0, 'F:/Projects/psxrecomp-v4/tools/_options_session') +import _dbg + +# Try fntrace_dump first +try: + fn = _dbg.call(4470, "fntrace_dump", count=512, timeout=4) + if fn.get('ok') and fn.get('entries'): + print(f"=== fntrace_dump ({len(fn['entries'])} entries, newest-first) ===") + recent = fn['entries'][:60] + # Hot targets + targets = collections.Counter(e.get('target') for e in fn['entries']) + print(f"Top 15 targets in last {len(fn['entries'])}:") + for t, c in targets.most_common(15): + print(f" {t}: {c} hits") + print() + print("Last 15 entries (newest first):") + for e in recent[:15]: + print(f" {e}") + else: + print(f"fntrace_dump empty / error: {fn}") +except Exception as e: + print(f"fntrace_dump exception: {e}") + +# Also try dirty_block_log +print() +try: + db = _dbg.call(4470, "dirty_block_log", count=512, timeout=4) + if db.get('ok') and db.get('entries'): + print(f"=== dirty_block_log ({len(db['entries'])} entries, newest-first) ===") + targets = collections.Counter(e.get('target') for e in db['entries']) + print(f"Top 15 targets:") + for t, c in targets.most_common(15): + print(f" {t}: {c} hits") + print() + print("Last 12 entries (newest-first):") + for e in db['entries'][:12]: + print(f" {e}") + else: + print(f"dirty_block_log empty / error: {db}") +except Exception as e: + print(f"dirty_block_log exception: {e}") diff --git a/tools/_options_session/_outer_caller.py b/tools/_options_session/_outer_caller.py new file mode 100644 index 00000000..66e90a1c --- /dev/null +++ b/tools/_options_session/_outer_caller.py @@ -0,0 +1,47 @@ +"""Look for the outer caller of FUN_bfc08b3c (= 0x00008B3C in recompiled form).""" +import json, sys +from collections import Counter + +path = sys.argv[1] if len(sys.argv) > 1 else \ + 'F:/Projects/TombaRecomp/psx_freeze_dump_psx-runtime_1778800465.json' + +with open(path) as f: + d = json.load(f) + +# Print all distinct func addresses in fn_entry, sorted by occurrence +fn_c = Counter(e['func'] for e in d['fn_entry']) +print(f'Total distinct funcs in fn_entry: {len(fn_c)}') +print() + +# Are there any direct entries to 0x00008B3C or 0xBFC08B3C? +candidates = [f for f in fn_c if int(f, 16) in (0x00008B3C, 0xBFC08B3C, 0x80008B3C)] +print(f'Direct entries to FUN_bfc08b3c: {candidates}') + +# Any entries to 0x9144 (FUN_bfc09144)? +candidates = [f for f in fn_c if int(f, 16) in (0x00009144, 0xBFC09144)] +print(f'Direct entries to FUN_bfc09144: {[(f, fn_c[f]) for f in candidates]}') + +# What about all funcs in 0x8000-0x9999 range (BIOS shell card area)? +print() +print('All BIOS shell area funcs in fn_entry (0x8000-0x9FFF):') +for f, c in sorted(fn_c.items(), key=lambda x: int(x[0], 16)): + addr = int(f, 16) + if 0x8000 <= addr < 0xA000: + print(f' {f}: {c}') + +# What about Tomba code (0x80000000+)? +print() +print('All Tomba code funcs in fn_entry (0x80000000+):') +for f, c in sorted(fn_c.items(), key=lambda x: int(x[0], 16)): + addr = int(f, 16) + if 0x80000000 <= addr: + print(f' {f}: {c}') + +# What RA values come back from Tomba functions? +print() +print('Distinct RA values for Tomba-function entries:') +for target in ('0x80068024', '0x80068098', '0x80068554'): + print(f' {target}:') + ra_c = Counter(e['ra'] for e in d['fn_entry'] if e['func'] == target) + for ra, c in ra_c.most_common(5): + print(f' RA={ra}: {c}') diff --git a/tools/_options_session/_pre_wedge.py b/tools/_options_session/_pre_wedge.py new file mode 100644 index 00000000..1e2410c1 --- /dev/null +++ b/tools/_options_session/_pre_wedge.py @@ -0,0 +1,40 @@ +"""Find what was happening right before the exception-reentry wedge fired. +The dump captured the wedge — exc_re spikes in heartbeat ticks 62-63. +Look at the LAST wtrace_all entries (frame 763) and the final restore_trace +events to identify the trigger.""" +import json, collections + +dump = 'F:/Projects/TombaRecomp/psx_freeze_dump_psx-runtime_1778800465.json' +with open(dump) as f: + d = json.load(f) + +events = d['wtrace_all'] +print(f"=== Last 60 wtrace_all entries (frame near 763) ===") +for e in events[-60:]: + pc = e['pc'] + addr = int(e['addr'], 16) + new = e.get('new', '?') + seq = e['seq'] + fr = e['frame'] + print(f" seq={seq:,} fr={fr} pc={pc} addr=0x{addr:08X} ->{new}") + +print() +print("=== Last 30 restore_trace events ===") +rt = d['restore_trace'] +for e in rt[-30:]: + print(f" seq={e.get('seq')} fr={e['frame']} kind={e['kind']} name={e.get('name')} " + f"jmp={e.get('jmp')} target={e.get('target')} cpu_pc={e.get('cpu_pc')} " + f"sr={e.get('sr')} epc={e.get('epc')} istat={e.get('istat')} imask={e.get('imask')} " + f"in_exc={e.get('in_exc')}") + +print() +print("=== Last 30 sio_pc_trace events ===") +for e in d['sio_pc_trace'][-30:]: + print(f" seq={e['seq']} pc={e['pc']} func={e.get('func')} addr={e['addr']} " + f"value={e.get('value')} byte_seq={e.get('byte_seq')}") + +print() +print("=== Last 20 fn_entry events ===") +for e in d['fn_entry'][-20:]: + print(f" seq={e['seq']} fr={e['frame']} func={e['func']} ra={e['ra']} " + f"a0={e.get('a0','?')} a1={e.get('a1','?')}") diff --git a/tools/_options_session/_probe_byte127.py b/tools/_options_session/_probe_byte127.py new file mode 100644 index 00000000..06fcff40 --- /dev/null +++ b/tools/_options_session/_probe_byte127.py @@ -0,0 +1,102 @@ +"""Diagnose why the 128th SIO-card-data byte never lands in the BIOS buffer. + +The BIOS handler at 0xBFC15F08 has gates: + (1) mem[0x75c0] != 0 (active flag) + (2) I_STAT bit 0x80 set + (3) I_MASK bit 0x80 set + (4) op-byte at *mem[0x75c8] == 2 (READ mode) +On miss, jr ra (no buffer store). + +For sector 0 (sees 127 stores 0xBE48..0xBEC6), find: + - last buffer store seq + frame + - immediately following writes to 0x75c0 / 0x75c4 / 0x72f0 / I_STAT (1F801070) + - any unrelated SIO traffic between byte 127 and byte 128 that could + have flipped a gate. +""" +import json, sys + +path = sys.argv[1] if len(sys.argv) > 1 else \ + 'F:/Projects/TombaRecomp/psx_freeze_dump_psx-runtime_1778800465.json' + +with open(path) as f: + d = json.load(f) + +STORE_PCS_UPPER = {'0xBFC16024', '0x00006524', '0X00006524'} +GATE_ADDRS = { + 0x000075c0: "active_flag", + 0x000075c4: "buffer_ptr", + 0x00007570: "buffer_ptr_alt", # in case the var is at 0x7570 region + 0x000075c8: "op_byte_ptr", + 0x000075cc: "checksum_ptr", + 0x000072f0: "counter", + 0x1f801070: "I_STAT", + 0x1f801074: "I_MASK", + 0x1f801040: "SIO_DATA", + 0x1f80104a: "SIO_CTRL", +} + +events = d['wtrace_all'] +print(f"Total wtrace events: {len(events)}") + +# Find all buffer stores (the 0xBE48..0xBEC7 range) +buf_stores = [] +for i, e in enumerate(events): + pc = e['pc'].upper() + if pc in STORE_PCS_UPPER and int(e['addr'], 16) >= 0xBE48 and int(e['addr'], 16) <= 0xBEC7: + buf_stores.append((i, e)) + +print(f"Buffer stores 0xBE48..0xBEC7: {len(buf_stores)}") + +# Group by sector +sectors = [] +cur = [] +prev_addr = -1 +for i, e in buf_stores: + a = int(e['addr'], 16) + if a < prev_addr or (a == 0xBE48 and cur): + sectors.append(cur) + cur = [] + cur.append((i, e)) + prev_addr = a +if cur: + sectors.append(cur) + +print(f"Sectors: {len(sectors)}") + +# For sector 0, look at events between last byte store and the next +# byte store of sector 1 — that's where the gate-flip must have happened. +for s_idx in range(min(2, len(sectors))): + s = sectors[s_idx] + last_i, last_e = s[-1] + print(f"\n=== Sector {s_idx}: {len(s)} stores ===") + print(f" First store: idx {s[0][0]}, addr {s[0][1]['addr']}, frame {s[0][1].get('frame')}") + print(f" Last store: idx {last_i}, addr {last_e['addr']}, frame {last_e.get('frame')}") + print(f" Expected next store addr: 0xBEC7 (the 128th byte)") + print() + + # Show next 60 events after the last byte 127 store, look for any + # writes to gate addresses, OR any SIO traffic + print(f" Events immediately after last store (idx {last_i}):") + next_buf_idx = sectors[s_idx + 1][0][0] if s_idx + 1 < len(sectors) else last_i + 200 + count = 0 + for j in range(last_i + 1, min(last_i + 200, next_buf_idx)): + e = events[j] + addr = int(e['addr'], 16) + pc = e['pc'] + new = e['new'] + old = e.get('old', '') + seq = e.get('seq', '?') + frame = e.get('frame', '?') + + label = GATE_ADDRS.get(addr) + # Show high-pri gate writes, plus near-buffer writes, plus all SIO writes + if (label or (0xBE48 <= addr <= 0xBED0) + or (0x1F801040 <= addr <= 0x1F80104F) + or (0x1F801070 <= addr <= 0x1F801077) + or (0x7500 <= addr <= 0x76C0)): + tag = f"[{label}]" if label else "" + print(f" idx={j} seq={seq} fr={frame} pc={pc} addr=0x{addr:08X} {old}->{new} {tag}") + count += 1 + if count > 50: + print(" ... (truncated)") + break diff --git a/tools/_options_session/_read_state.py b/tools/_options_session/_read_state.py new file mode 100644 index 00000000..3dc78c26 --- /dev/null +++ b/tools/_options_session/_read_state.py @@ -0,0 +1,30 @@ +import sys, struct +sys.path.insert(0, 'F:/Projects/psxrecomp-v4/tools/_options_session') +import _dbg + +# Read scratchpad ptr at 0x1F8001D4 +ptr_word = _dbg.read_word(4470, 0x1F8001D4) +print(f"scratchpad[0x1D4] = ptr 0x{ptr_word:08X}") + +# Read mem[ptr + 0x4E] (halfword), and surrounding bytes for context +r = _dbg.call(4470, 'read_ram', addr=f'0x{ptr_word:08X}', len=0x80, timeout=3) +b = bytes.fromhex(r['hex']) +print(f"\nContents of mem[{ptr_word:08X}..]:") +for i in range(0, len(b), 16): + line = ' '.join(f'{x:02x}' for x in b[i:i+16]) + print(f" +{i:02X}: {line}") + +state = struct.unpack_from(' would dispatch via jump table 0x800E738C[{state}]") +else: + print(f" -> state >= 6, chain handler SKIPS (this is the 'do nothing' branch)") + +# Read the jump table itself to see what each state would do +jt = _dbg.call(4470, 'read_ram', addr='0x800E738C', len=6*4, timeout=3) +jtb = bytes.fromhex(jt['hex']) +print(f"\nJump table 0x800E738C (6 entries):") +for i in range(6): + tgt = struct.unpack_from(' 1 else 0x0005B40C +size = int(sys.argv[2], 0) if len(sys.argv) > 2 else 64 +r = _dbg.call(4470, 'read_ram', addr=f'0x{addr:08X}', len=size, timeout=3) +b = bytes.fromhex(r['hex']) +for i in range(0, len(b), 4): + insn = struct.unpack_from('>26)&0x3F + rs = (insn>>21)&0x1F + rt = (insn>>16)&0x1F + rd = (insn>>11)&0x1F + imm16 = insn&0xFFFF + if imm16 > 0x7FFF: imm16 -= 0x10000 + funct = insn&0x3F + target26 = insn & 0x3FFFFFF + s = f'op={op:02x} rs={rs} rt={rt} rd={rd} imm={imm16:#x} funct={funct:02x}' + # Try basic decoding + if op == 0: + if funct == 9: s = f'jalr r{rs}' + elif funct == 8: s = f'jr r{rs}' + elif funct == 0: s = 'nop' + else: s = f'SPECIAL funct={funct:#x}' + elif op == 9: s = f'addiu r{rt}, r{rs}, {imm16}' + elif op == 0xD: s = f'ori r{rt}, r{rs}, 0x{insn&0xFFFF:x}' + elif op == 0xF: s = f'lui r{rt}, 0x{insn&0xFFFF:x}' + elif op == 0x2: s = f'j 0x{target26<<2:08x}' + elif op == 0x3: s = f'jal 0x{target26<<2:08x}' + elif op == 0x4: s = f'beq r{rs}, r{rt}, off={imm16:#x}' + elif op == 0x5: s = f'bne r{rs}, r{rt}, off={imm16:#x}' + elif op == 0x23: s = f'lw r{rt}, {imm16:#x}(r{rs})' + elif op == 0x2B: s = f'sw r{rt}, {imm16:#x}(r{rs})' + print(f' 0x{addr+i:08X}: {insn:08x} {s}') diff --git a/tools/_options_session/_read_word.py b/tools/_options_session/_read_word.py new file mode 100644 index 00000000..4a927684 --- /dev/null +++ b/tools/_options_session/_read_word.py @@ -0,0 +1,6 @@ +import sys +sys.path.insert(0, 'F:/Projects/psxrecomp-v4/tools/_options_session') +import _dbg +addr = int(sys.argv[1], 16) +v = _dbg.read_word(4470, addr) +print(f"mem[0x{addr:08X}] = 0x{v:08X}") diff --git a/tools/_options_session/_region_breakdown.py b/tools/_options_session/_region_breakdown.py new file mode 100644 index 00000000..e094810e --- /dev/null +++ b/tools/_options_session/_region_breakdown.py @@ -0,0 +1,46 @@ +"""Break down fn_entry and wtrace by execution region.""" +import json, sys +from collections import Counter + +path = sys.argv[1] if len(sys.argv) > 1 else \ + 'F:/Projects/TombaRecomp/psx_freeze_dump_psx-runtime_1778800465.json' + +with open(path) as f: + d = json.load(f) + +def region_of(addr): + if addr >= 0xBFC00000: + return 'BIOS-ROM' + if addr >= 0x10000: + return 'TOMBA' + return 'low-kernel' + +fn_c = Counter(e['func'] for e in d['fn_entry']) +print('Top 30 funcs by fn_entry count:') +for f, c in fn_c.most_common(30): + print(f' {f} {c:5} [{region_of(int(f, 16))}]') + +print() +pc_c = Counter(e['pc'] for e in d['wtrace_all']) +buckets = Counter() +for p, c in pc_c.items(): + buckets[region_of(int(p, 16))] += c +print('wtrace_all distribution by store-PC source:') +for r, c in buckets.most_common(): + print(f' {r:12} {c}') + +print() +# Show top Tomba-region PCs (writes from Tomba code) +tomba_pcs = [(p, c) for p, c in pc_c.items() if region_of(int(p, 16)) == 'TOMBA'] +tomba_pcs.sort(key=lambda x: -x[1]) +print('Top 15 TOMBA-region store PCs:') +for p, c in tomba_pcs[:15]: + print(f' {p} {c}') + +# Same for low-kernel +kern_pcs = [(p, c) for p, c in pc_c.items() if region_of(int(p, 16)) == 'low-kernel'] +kern_pcs.sort(key=lambda x: -x[1]) +print() +print('Top 15 low-kernel-region store PCs:') +for p, c in kern_pcs[:15]: + print(f' {p} {c}') diff --git a/tools/_options_session/_search_ec_bytes.py b/tools/_options_session/_search_ec_bytes.py new file mode 100644 index 00000000..291d1690 --- /dev/null +++ b/tools/_options_session/_search_ec_bytes.py @@ -0,0 +1,40 @@ +"""Find where 'EC' bytes (0x45, 0x43) appear in runtime memory but not beetle. +That tells us if 0x43450000 at 0x8009B3D4 is from a stale buffer/string.""" +import sys +sys.path.insert(0, 'F:/Projects/psxrecomp-v4/tools/_options_session') +import _dbg + +# Scan a wide range of low RAM (0x80010000..0x80100000) for any place where +# runtime has bytes "45 43" but beetle doesn't. +# Too wide; let's narrow to 0x8009B000..0x8009B600 (around the diverging struct). + +ranges = [ + (0x80097000, 0x800A0000, "fn ptr table region + 0x8009B... region"), + (0x801FD000, 0x801FE000, "TCB region"), +] + +for lo, hi, label in ranges: + print(f"=== {label}: 0x{lo:08X}..0x{hi:08X} ===") + chunk = 0x800 + for base in range(lo, hi, chunk): + sz = min(chunk, hi - base) + try: + r_rt = _dbg.call(4470, 'read_ram', addr=f'0x{base:08X}', len=sz, timeout=4) + r_be = _dbg.call(4380, 'read_ram', addr=f'0x{base:08X}', len=sz, timeout=4) + if not r_rt.get('ok') or not r_be.get('ok'): continue + bt_rt = bytes.fromhex(r_rt['hex']) + bt_be = bytes.fromhex(r_be['hex']) + for i in range(len(bt_rt) - 1): + if bt_rt[i] == 0x45 and bt_rt[i+1] == 0x43: + if bt_be[i] != 0x45 or bt_be[i+1] != 0x43: + # runtime has "EC", beetle doesn't + addr = base + i + ctx_lo = max(0, i-4) + ctx_hi = min(len(bt_rt), i+8) + rt_ctx = ' '.join(f'{x:02x}' for x in bt_rt[ctx_lo:ctx_hi]) + be_ctx = ' '.join(f'{x:02x}' for x in bt_be[ctx_lo:ctx_hi]) + print(f" 0x{addr:08X} RT: {rt_ctx}") + print(f" BE: {be_ctx}") + except Exception as e: + print(f" err at 0x{base:08X}: {e}") + break diff --git a/tools/_options_session/_show_stack.py b/tools/_options_session/_show_stack.py new file mode 100644 index 00000000..9450f13e --- /dev/null +++ b/tools/_options_session/_show_stack.py @@ -0,0 +1,23 @@ +"""Show main_stack from a freeze dump.""" +import json, sys +dump = sys.argv[1] if len(sys.argv) > 1 else \ + 'F:/Projects/TombaRecomp/psx_freeze_dump_psx-runtime_1778826348.json' +with open(dump) as f: + d = json.load(f) + +print(f"=== {d['backend']} @ wall={d['wall_clock_epoch']} ===") +print(f" frame_count: {d['frame_count']}, psx_cyc: {d['psx_cycle_count']:,}") +print(f" wedge_kind: {d['wedge_kind']} ({d['wedge_kind_name']})") +print(f" in_exception: {d['in_exception']}, cur_fn: {d['current_func']}, last_store_pc: {d['last_store_pc']}") +print(f" exc_entries: {d['exception_entries']:,}, exc_reentry: {d['exception_reentry_blocks']:,}") +print(f" i_stat: {d['i_stat']}, i_mask: {d['i_mask']}") +print(f" sio_stat: {d['sio_stat']}, sio_ctrl: {d['sio_ctrl']}, sio_card_active: {d['sio_card_active']}, mc_max_state: {d['mc_max_state']}") +print() + +ms = d.get('main_stack', []) +print(f"=== main_stack ({len(ms)} frames) ===") +for f in ms: + s = f.get('symbol', '???') + o = f.get('displacement', '?') + m = f.get('module', '?') + print(f" [{f['depth']:>3}] {f['addr']} {m}!{s}+0x{int(o):X}" if o != '?' else f" [{f['depth']:>3}] {f['addr']} {m}!{s}") diff --git a/tools/_options_session/_smoke_normalized.py b/tools/_options_session/_smoke_normalized.py new file mode 100644 index 00000000..1414889d --- /dev/null +++ b/tools/_options_session/_smoke_normalized.py @@ -0,0 +1,61 @@ +"""Smoke-test the normalized wtrace verb set on BOTH backends. + +Both backends must accept identical JSON for the same verbs. This +script issues the same six probes against runtime (4470) and beetle +(4380) and compares response shapes. Any divergence is a parity bug +in the debug server; fix it before relying on cross-backend tooling. +""" +from __future__ import annotations +import sys, os, json +sys.path.insert(0, os.path.dirname(os.path.abspath(__file__))) +from _dbg import call, RUNTIME_PORT, BEETLE_PORT + + +def probe(name, **kw): + out = {} + for label, port in [("runtime", RUNTIME_PORT), ("beetle", BEETLE_PORT)]: + try: + out[label] = call(port, name, **kw) + except Exception as e: + out[label] = {"error": str(e)} + return out + + +def shape(r): + if not isinstance(r, dict): return type(r).__name__ + return sorted(k for k in r.keys() if k != "id") + + +print("== wtrace_disarm_all (idempotent reset of armed ranges) ==") +r = probe("wtrace_disarm_all") +print(" runtime:", r["runtime"]) +print(" beetle :", r["beetle"]) + +print("\n== wtrace_arm lo=0x80090C80 hi=0x80090DE0 ==") +r = probe("wtrace_arm", lo="0x80090C80", hi="0x80090DE0") +print(" runtime:", r["runtime"]) +print(" beetle :", r["beetle"]) + +print("\n== wtrace_ranges ==") +r = probe("wtrace_ranges") +print(" runtime shape:", shape(r["runtime"])) +print(" beetle shape:", shape(r["beetle"])) +print(" runtime count:", r["runtime"].get("count")) +print(" beetle count:", r["beetle"].get("count")) + +print("\n== wtrace_stats ==") +r = probe("wtrace_stats") +print(" runtime:", r["runtime"]) +print(" beetle :", r["beetle"]) + +print("\n== wtrace_dump count=3 ==") +r = probe("wtrace_dump", count=3) +for label in ("runtime", "beetle"): + resp = r[label] + print(f" {label} top-level shape:", shape(resp)) + entries = resp.get("entries", []) + print(f" {label} entries: {len(entries)}") + if entries: + e0 = entries[0] + print(f" {label} entry[0] keys:", sorted(e0.keys())) + print(f" {label} entry[0] sample: addr={e0.get('addr')} new={e0.get('new')} pc={e0.get('pc')} w={e0.get('w')} frame={e0.get('frame')}") diff --git a/tools/_options_session/_snapshot.py b/tools/_options_session/_snapshot.py new file mode 100644 index 00000000..b619838e --- /dev/null +++ b/tools/_options_session/_snapshot.py @@ -0,0 +1,19 @@ +"""Compact one-line snapshot of runtime state for diff'ing across nav events.""" +import sys, json +sys.path.insert(0, 'F:/Projects/psxrecomp-v4/tools/_options_session') +import _dbg + +label = sys.argv[1] if len(sys.argv) > 1 else "snap" + +p = _dbg.call(4470, "ping", timeout=2) +g = _dbg.call(4470, "gpu_state", timeout=2) +s = _dbg.call(4470, "sio_state", timeout=2) +irq = _dbg.call(4470, "irq_state", timeout=2) +mc = _dbg.call(4470, "mc_status", timeout=2) + +print(f"=== [{label}] fr={p['frame']} ===") +print(f" GPU: draw={g['gp0_draw']} fill={g['gp0_fill']} env={g['gp0_env']} copy={g['gp0_copy']} writes={g['gp0_writes']:,} disabled={g['disabled']}") +print(f" disp=({g['display_x']},{g['display_y']}) draw_area={g['draw_area']} gpustat={g['gpustat']}") +print(f" SIO: mc_probes={s['mc_probes']} mc_reads={s['mc_reads']} mc_max_state={s['mc_max_state']} tx_writes={s['tx_writes']} sio_stat={s['sio_stat']} sio_ctrl={s['sio_ctrl']} card_caller={s['mc_last_caller']}") +print(f" IRQ: i_stat={irq['i_stat']} i_mask={irq['i_mask']} pending={irq['pending']} cop0_sr={irq['cop0_sr']} IEc={irq['IEc']} IM2={irq['IM2']}") +print(f" MC: {mc}") diff --git a/tools/_options_session/_state_diff.py b/tools/_options_session/_state_diff.py new file mode 100644 index 00000000..76d82084 --- /dev/null +++ b/tools/_options_session/_state_diff.py @@ -0,0 +1,41 @@ +import sys +sys.path.insert(0, 'F:/Projects/psxrecomp-v4/tools/_options_session') +import _dbg + +print(f"{'thing':>40} {'runtime':>12} {'beetle':>12}") +for label, addr, width in [ + ("scratchpad+0x1D4 (ptr)", 0x1F8001D4, 'w'), + ("ptr+0x4C (full word w/ state)", 0, 'special_state'), + ("0x8009B3A0+0x34", 0x8009B3D4, 'w'), + ("0x8009B3A0+0x49 (byte at 0x49)", 0x8009B3E9, 'b'), + ("0x8009EB58", 0x8009EB58, 'w'), + ("frame count", -1, 'frame'), +]: + if width == 'frame': + rt = _dbg.call(4470, "ping", timeout=2).get('frame','?') + be = _dbg.call(4380, "ping", timeout=2).get('frame','?') + print(f" {label:>40} {rt:>12} {be:>12}") + continue + if width == 'special_state': + # state is halfword at ptr+0x4E + rt_ptr = _dbg.read_word(4470, 0x1F8001D4) + be_ptr = _dbg.read_word(4380, 0x1F8001D4) + rt_state_word = _dbg.read_word(4470, rt_ptr + 0x4C) + be_state_word = _dbg.read_word(4380, be_ptr + 0x4C) + rt_state = (rt_state_word >> 16) & 0xFFFF + be_state = (be_state_word >> 16) & 0xFFFF + print(f" {'state @ ptr+0x4E':>40} {rt_state:>12} {be_state:>12}") + continue + if width == 'w': + rt = _dbg.read_word(4470, addr) + be = _dbg.read_word(4380, addr) + mark = "" if rt == be else " *DIFF*" + print(f" {label:>40} 0x{rt:08X} 0x{be:08X}{mark}") + elif width == 'b': + rt = _dbg.read_word(4470, addr & ~3) + be = _dbg.read_word(4380, addr & ~3) + byte_off = addr & 3 + rt_byte = (rt >> (byte_off * 8)) & 0xFF + be_byte = (be >> (byte_off * 8)) & 0xFF + mark = "" if rt_byte == be_byte else " *DIFF*" + print(f" {label:>40} 0x{rt_byte:02X}{' '} 0x{be_byte:02X}{' '}{mark}") diff --git a/tools/_options_session/_symbolize.py b/tools/_options_session/_symbolize.py new file mode 100644 index 00000000..ebc36385 --- /dev/null +++ b/tools/_options_session/_symbolize.py @@ -0,0 +1,61 @@ +"""Map captured stack offsets to nearest preceding symbol from nm output.""" +import subprocess, sys + +# captured stack-frame offsets (relative to runtime image base) +offsets = [ + ("[ 2] SleepEx caller", 0x000B2219), + ("[ 3]", 0x000B4E51), + ("[ 4]", 0x000BE7F7), + ("[ 5]", 0x00460B2D), + ("[ 6]", 0x0063ECC7), + ("[ 7]", 0x006B12B0), + ("[ 8]", 0x000D889C), + ("[ 9]", 0x0045FCF0), + ("[10] dispatcher", 0x0045FDC9), + ("[11]", 0x00011BC0A & 0xFFFFFF), # 0x11BC0A is unusual + ("[12] dispatcher", 0x0045FC97), + ("[14] dispatcher", 0x0045FDC9), + ("[15]", 0x001A37AB), + ("[16] dispatcher", 0x0045FC97), + ("[18]", 0x00142516), + ("[20]", 0x0013D8AC), + ("[23]", 0x00144B00), + ("[26]", 0x000B2B77), + ("[27]", 0x006BB07C), + ("[28]", 0x000B10C9), + ("[29] start", 0x000B1416), +] + +# Load nm output +nm = subprocess.run( + ['nm', 'F:/Projects/TombaRecomp/build/psx-runtime.exe'], + capture_output=True, text=True +).stdout + +# Build sorted list of (addr, name) for text symbols +syms = [] +for line in nm.splitlines(): + parts = line.split() + if len(parts) >= 3 and parts[1] in ('t','T','w','W'): + try: + a = int(parts[0], 16) + except: + continue + # filter to image-base range (0x140000000+ standard mingw) + if 0x140000000 <= a < 0x150000000: + syms.append((a - 0x140000000, ' '.join(parts[2:]))) +syms.sort() +print(f"Loaded {len(syms)} text symbols") + +import bisect +addrs = [a for a,_ in syms] +for label, off in offsets: + i = bisect.bisect_right(addrs, off) - 1 + if i < 0: + print(f" {label}: offset 0x{off:08X} -> (before all symbols)") + continue + sym_off, sym_name = syms[i] + disp = off - sym_off + # only show if displacement is reasonable (< 0x10000 = 64KB) + note = "" if disp < 0x10000 else " (LARGE displacement — probably between symbols)" + print(f" {label}: offset 0x{off:08X} -> {sym_name} + 0x{disp:X}{note}") diff --git a/tools/_options_session/_thread_audit.py b/tools/_options_session/_thread_audit.py new file mode 100644 index 00000000..3e671ce9 --- /dev/null +++ b/tools/_options_session/_thread_audit.py @@ -0,0 +1,44 @@ +"""Inspect thread_trace and look for fiber switches near the freeze.""" +import json, sys, collections +dump = sys.argv[1] if len(sys.argv) > 1 else \ + 'F:/Projects/TombaRecomp/psx_freeze_dump_psx-runtime_1778822828.json' +with open(dump) as f: + d = json.load(f) + +tt = d.get('thread_trace', []) +print(f"thread_trace: {len(tt)} entries") +if tt: + print(f" first: {tt[0]}") + print(f" last : {tt[-1]}") + kinds = collections.Counter(e.get('kind') for e in tt) + print(f" kind distribution: {kinds}") + print() + print(f"Last 30 thread_trace entries:") + for e in tt[-30:]: + print(f" {e}") + +# Count 0x650 dispatches (SwitchThread) +db = d.get('dirty_block', []) +print() +print(f"=== 0x650 (SwitchThread) calls in dirty_block ring ===") +sw = [e for e in db if e['target'] == '0x00000650'] +print(f" count: {len(sw)}") +for e in sw[-15:]: + print(f" seq={e['seq']} fr={e['frame']} target=0x650 ra={e['ra']} " + f"a0={e['a0']} a1={e['a1']} sp={e['sp']}") + +# Look in fn_entry for 0x650 to count and see all params +fe = d.get('fn_entry', []) +print() +sw2 = [e for e in fe if e['func'] == '0x00000650'] +print(f"=== 0x650 calls in fn_entry: {len(sw2)} ===") +for e in sw2[-15:]: + print(f" seq={e['seq']} fr={e['frame']} ra={e['ra']} a0={e['a0']} a1={e['a1']}") + +# Look at any function in fn_entry with a0=3 (likely ChangeThread syscalls) +a0_3 = [e for e in fe if e.get('a0') == '0x00000003'] +print() +print(f"=== fn_entry with a0=0x3 (ChangeThread param) ===") +print(f" count: {len(a0_3)}") +for e in a0_3[-15:]: + print(f" seq={e['seq']} fr={e['frame']} func={e['func']} ra={e['ra']} a1={e['a1']}") diff --git a/tools/_options_session/_thread_live.py b/tools/_options_session/_thread_live.py new file mode 100644 index 00000000..36dd7e51 --- /dev/null +++ b/tools/_options_session/_thread_live.py @@ -0,0 +1,29 @@ +"""Query live thread_trace and see if ChangeTh ping-pong is active now.""" +import sys, json, collections +sys.path.insert(0, 'F:/Projects/psxrecomp-v4/tools/_options_session') +import _dbg + +try: + tt = _dbg.call(4470, "thread_trace", count=512, timeout=4) + if not tt.get('ok'): + print(f"err: {tt}") + sys.exit(1) + es = tt.get('entries', []) + print(f"thread_trace: {len(es)} entries (total={tt.get('total')}, available={tt.get('available')})") + if not es: + print("(empty)") + sys.exit(0) + # Last 20 + print(f"Last 20 (newest first):") + for e in es[:20]: + print(f" seq={e.get('seq')} fr={e.get('frame')} kind={e.get('kind')} name={e.get('name')} " + f"cur={e.get('current_tcb')} tgt={e.get('target_tcb')} pc={e.get('target_pc')}") + + # Pairs of (cur_tcb, target_tcb) + pairs = collections.Counter((e['current_tcb'], e['target_tcb'], e['name']) for e in es) + print() + print("Top transition signatures:") + for (c,t,n), cnt in pairs.most_common(15): + print(f" {n}: {c} -> {t}: {cnt}") +except Exception as e: + print(f"err: {e}") diff --git a/tools/_options_session/_throughput_analysis.py b/tools/_options_session/_throughput_analysis.py new file mode 100644 index 00000000..b7fbcf7b --- /dev/null +++ b/tools/_options_session/_throughput_analysis.py @@ -0,0 +1,108 @@ +"""Compute per-byte cycle cost and per-frame breakdown from the freeze dump.""" +import json, sys, collections + +dump = sys.argv[1] if len(sys.argv) > 1 else \ + 'F:/Projects/TombaRecomp/psx_freeze_dump_psx-runtime_1778800465.json' + +with open(dump) as f: + d = json.load(f) + +print("=== Core state at dump time ===") +print(f" frame_count: {d['frame_count']}") +print(f" psx_cycle_count: {d['psx_cycle_count']:,}") +print(f" exc_reentry_blocks: {d['exception_reentry_blocks']:,}") +print(f" exc_entries: {d['exception_entries']:,}") +print(f" dispatch_count: {d['dispatch_count']:,}") +print(f" dirty_ram_blocks: {d['dirty_ram_blocks']:,}") +print(f" dirty_ram_insns: {d['dirty_ram_insns']:,}") +print() + +# Heartbeat ring: psx_cycle_count over time +hb = d['heartbeat_ring'] +print(f"=== Heartbeat ring ({len(hb)} entries) ===") +if len(hb) >= 2: + # entries are time-ordered, oldest first based on 'wall' + hb_sorted = sorted(hb, key=lambda e: e['wall']) + first, last = hb_sorted[0], hb_sorted[-1] + cyc_delta = last['cyc'] - first['cyc'] + fr_delta = last['frame'] - first['frame'] + exc_re_delta = last['exc_re'] - first['exc_re'] + dirty_delta = last['dirty_insns'] - first['dirty_insns'] + wall_delta = last['wall'] - first['wall'] # seconds (integer) + print(f" wall delta: {wall_delta} sec") + print(f" cycle delta: {cyc_delta:,} ({cyc_delta/33868800:.2f}s of PSX time)") + print(f" frame delta: {fr_delta}") + print(f" exc_re delta: {exc_re_delta:,}") + print(f" dirty_insns delta: {dirty_delta:,}") + print() + if wall_delta: + print(f" frames/sec (wall): {fr_delta/wall_delta:.1f}") + print(f" PSX cycles/sec (wall): {cyc_delta/wall_delta:,.0f} (real PSX = 33,868,800)") + print(f" speed pct: {(cyc_delta/wall_delta)/33868800*100:.1f}%") + print(f" dirty_insns/sec: {dirty_delta/wall_delta:,.0f}") + print(f" exc_re/sec: {exc_re_delta/wall_delta:,.0f}") + +# Count buffer stores per frame from wtrace +events = d['wtrace_all'] +# Newest events; estimate window +seqs = [e['seq'] for e in events] +print() +print(f"=== wtrace_all window ===") +print(f" seq range: {min(seqs):,} .. {max(seqs):,}") + +frames_seen = sorted({e['frame'] for e in events}) +print(f" frame range: {min(frames_seen)} .. {max(frames_seen)} ({len(frames_seen)} distinct)") + +# stores per frame +STORE_PCS_UPPER = {'0X00006524', '0XBFC15590'} +stores_per_frame = collections.Counter() +total_buffer_stores = 0 +for e in events: + pc = e['pc'].upper() + if pc in STORE_PCS_UPPER and 0xBE48 <= int(e['addr'], 16) <= 0xBEC7: + stores_per_frame[e['frame']] += 1 + total_buffer_stores += 1 +print(f" card-buffer stores total: {total_buffer_stores}") +print(f" per frame:") +for fr in sorted(stores_per_frame): + print(f" fr {fr}: {stores_per_frame[fr]} stores") + +# How many bytes did SIO process? Look at sio_pc_trace for tx_data writes (1F801040) +sio_pc = d['sio_pc_trace'] +tx_writes = [e for e in sio_pc if int(e['addr'], 16) == 0x1F801040] +print() +print(f"=== SIO TX activity ===") +print(f" total sio_pc_trace entries: {len(sio_pc)}") +print(f" TX writes (to 0x1F801040): {len(tx_writes)}") +tx_seqs = [e['seq'] for e in tx_writes] +if tx_seqs: + seq_window = max(tx_seqs) - min(tx_seqs) + print(f" TX byte_seq range: {min(tx_seqs):,} .. {max(tx_seqs):,} (span {seq_window:,})") + +# What's the largest cycle gap between successive heartbeat entries? +print() +print(f"=== Heartbeat: per-tick analysis ===") +for i in range(1, min(8, len(hb_sorted))): + a, b = hb_sorted[i-1], hb_sorted[i] + cd = b['cyc'] - a['cyc'] + fd = b['frame'] - a['frame'] + rd = b['exc_re'] - a['exc_re'] + dd = b['dirty_insns'] - a['dirty_insns'] + print(f" tick {i}: cyc+{cd:,} fr+{fd} exc_re+{rd} dirty+{dd:,} cur_fn={a['cur_fn']} in_exc={a['in_exc']}") +print(" ...") +for i in range(max(1, len(hb_sorted)-6), len(hb_sorted)): + a, b = hb_sorted[i-1], hb_sorted[i] + cd = b['cyc'] - a['cyc'] + fd = b['frame'] - a['frame'] + rd = b['exc_re'] - a['exc_re'] + dd = b['dirty_insns'] - a['dirty_insns'] + print(f" tick {i}: cyc+{cd:,} fr+{fd} exc_re+{rd} dirty+{dd:,} cur_fn={a['cur_fn']} in_exc={a['in_exc']}") + +# Function entry counts — what's running most +print() +print(f"=== Function entry hotspots ===") +fe = d['fn_entry'] +fc = collections.Counter(e['func'] for e in fe) +print(f" Total fn_entry events: {len(fe)}") +for func, ct in fc.most_common(15): + print(f" {func}: {ct} calls") diff --git a/tools/_options_session/_watch_display.py b/tools/_options_session/_watch_display.py new file mode 100644 index 00000000..1a1db50c --- /dev/null +++ b/tools/_options_session/_watch_display.py @@ -0,0 +1,27 @@ +"""Sample gpu_state every 500ms for 10 sec and see if display origin moves.""" +import time, json, sys +sys.path.insert(0, 'F:/Projects/psxrecomp-v4/tools/_options_session') +import _dbg + +prev = None +for i in range(20): + g = _dbg.call(4470, "gpu_state", timeout=2) + sig = (g['display_x'], g['display_y'], g['draw_area'][0], g['draw_area'][1], + g['gp0_writes'], g['gp0_draw'], g['gp0_fill']) + # Get frame from ping + p = _dbg.call(4470, "ping", timeout=2) + fr = p.get('frame', '?') + sig_disp = f"disp=({g['display_x']},{g['display_y']}) draw_ofs=({g['draw_offset'][0]},{g['draw_offset'][1]}) draw_area=({g['draw_area'][0]},{g['draw_area'][1]}..{g['draw_area'][2]},{g['draw_area'][3]}) gpustat={g['gpustat']}" + sig_cnt = f"gp0_writes={g['gp0_writes']:,} gp0_draw={g['gp0_draw']} gp0_fill={g['gp0_fill']} gp0_copy={g['gp0_copy']} disabled={g['disabled']}" + print(f"[{i:2}] fr={fr:>5} {sig_disp}") + print(f" {sig_cnt}") + if prev and prev != sig: + diff = [] + for k in g: + if k in prev_full and prev_full[k] != g[k]: + diff.append(f"{k}: {prev_full[k]} -> {g[k]}") + if diff: + print(f" CHANGED: {', '.join(diff[:6])}") + prev = sig + prev_full = g + time.sleep(0.5) diff --git a/tools/_options_session/_watch_iec.py b/tools/_options_session/_watch_iec.py new file mode 100644 index 00000000..cd9f2053 --- /dev/null +++ b/tools/_options_session/_watch_iec.py @@ -0,0 +1,17 @@ +"""Sample SR / IRQ state to check if IEc ever goes back to 1.""" +import time, sys +sys.path.insert(0, 'F:/Projects/psxrecomp-v4/tools/_options_session') +import _dbg + +print(f"{'i':>3} {'frame':>6} {'sr':>10} {'IEc':>3} {'IEp':>3} {'IEo':>3} " + f"{'i_stat':>10} {'i_mask':>10} {'pending':>10}") +for i in range(20): + p = _dbg.call(4470, "ping", timeout=2) + irq = _dbg.call(4470, "irq_state", timeout=2) + sr_v = int(irq['cop0_sr'], 16) + IEc = sr_v & 1 + IEp = (sr_v >> 2) & 1 + IEo = (sr_v >> 4) & 1 + print(f"{i:>3} {p['frame']:>6} {irq['cop0_sr']:>10} {IEc:>3} {IEp:>3} {IEo:>3} " + f"{irq['i_stat']:>10} {irq['i_mask']:>10} {irq['pending']:>10}") + time.sleep(0.5) diff --git a/tools/_options_session/_watch_state.py b/tools/_options_session/_watch_state.py new file mode 100644 index 00000000..08fa346c --- /dev/null +++ b/tools/_options_session/_watch_state.py @@ -0,0 +1,19 @@ +"""Sample Tomba's state machine state every 500ms for 15 sec.""" +import time, sys +sys.path.insert(0, 'F:/Projects/psxrecomp-v4/tools/_options_session') +import _dbg + +prev = None +for i in range(30): + ptr = _dbg.read_word(4470, 0x1F8001D4) + state_word = _dbg.read_word(4470, ptr + 0x4C) # halfword at +0x4E in upper16 + state = (state_word >> 16) & 0xFFFF + # Also read the first 16 bytes of the struct (likely has fields) + head = _dbg.read_word(4470, ptr + 0x00) + flag2 = _dbg.read_word(4470, ptr + 0x44) + p = _dbg.call(4470, "ping", timeout=2) + sig = (ptr, state, head, flag2) + star = " *CHANGED*" if prev and prev != sig else "" + print(f"[{i:2}] fr={p.get('frame','?')} ptr=0x{ptr:08X} state=0x{state:04X} head=0x{head:08X} flag2=0x{flag2:08X}{star}") + prev = sig + time.sleep(0.5) diff --git a/tools/_options_session/_wtrace_query.py b/tools/_options_session/_wtrace_query.py new file mode 100644 index 00000000..c50fd012 --- /dev/null +++ b/tools/_options_session/_wtrace_query.py @@ -0,0 +1,13 @@ +import sys, json, time +sys.path.insert(0, 'F:/Projects/psxrecomp-v4/tools/_options_session') +import _dbg + +# wtrace_dump returns ALL captured events for the armed ranges +d = _dbg.call(4470, "wtrace_dump", count=100, timeout=4) +es = d.get('entries', []) +print(f"wtrace_dump: {len(es)} entries") +for e in es[:20]: + print(f" seq={e.get('seq')} fr={e.get('frame')} pc={e.get('pc')} addr={e.get('addr')} ->{e.get('new')} func={e.get('func','?')} cpu_pc={e.get('cpu_pc','?')}") + +# Also look at wtrace_all filtered by addr (the always-on ring) +d2 = _dbg.call(4470, "wtrace_all_dump", count=100, timeout=4) if False else None