From 1252c61c9d6f054aa0dc4abb7bcaa8e87bea623d Mon Sep 17 00:00:00 2001 From: Matthew Stanley <1379tech@gmail.com> Date: Wed, 24 Jun 2026 10:44:35 -0700 Subject: [PATCH] tools/divergence: persist the native-vs-interp first-divergence toolkit Dev tooling only (never shipped: tools/ is not bundled in releases, and the debug-server commands it drives are all PSX_NO_DEBUG_TOOLS-stripped in release builds). Saved so the first-divergence workflow that root-caused the Tomba2 logo->FMV stall is never re-invented. - t2probe.py layer 1 fingerprint cap/diff; layer 2 unified-recorder dump + recdiff/recdiff_state (state fork, addr/val only); resolves the debug_client import relative to tools/. - waitf.py retry-connect + poll-until-frame (survives socket aborts). - shot.py screenshot to PNG for VISUAL end-state verification. - README.md the 3-layer method (always-on fingerprint ring -> divergent frame; frame-gated recorder -> divergent access; read-watch + per-entry cyc -> value/pointer/timing), env seeds, and the Tomba2 worked example. Co-Authored-By: Claude Opus 4.8 --- tools/divergence/README.md | 73 ++++++++++++++++++ tools/divergence/shot.py | 15 ++++ tools/divergence/t2probe.py | 147 ++++++++++++++++++++++++++++++++++++ tools/divergence/waitf.py | 33 ++++++++ 4 files changed, 268 insertions(+) create mode 100644 tools/divergence/README.md create mode 100644 tools/divergence/shot.py create mode 100644 tools/divergence/t2probe.py create mode 100644 tools/divergence/waitf.py diff --git a/tools/divergence/README.md b/tools/divergence/README.md new file mode 100644 index 00000000..9acf88fa --- /dev/null +++ b/tools/divergence/README.md @@ -0,0 +1,73 @@ +# Native-vs-interp first-divergence tooling + +**Dev tooling only — never shipped.** The Python scripts here drive debug-server +commands that are all `PSX_NO_DEBUG_TOOLS`-stripped from release builds, so none +of this reaches production. It exists so we never have to re-invent the +first-divergence workflow that root-caused the Tomba 2 logo→FMV stall. + +## The idea + +A recomp title run two ways — **native** (compiled BIOS + compiled overlays + +the sanctioned dirty-RAM interp) vs the **interp reference** +(`PSX_OVERLAY_NATIVE_OFF=1`, full dirty-interp from boot) — is the *same +deterministic program*. They must emit an identical sequence of guest +side-effects until a codegen or timing bug forks them. Find that fork in three +ever-narrowing layers. Ring-buffer-first: never arm-then-time; the fingerprint +ring is always-on, you query it after the fact. + +### Layer 1 — which FRAME forks (always-on ring, O(1)) +`frame_fingerprint` keeps cumulative rolling hashes, snapshotted per guest +frame, over guest writes: `wr` (main-RAM addr/val), `pc` (store-PC path), +`mmio` (device-register writes), `sp` (scratchpad writes — separate so it +classifies instead of hiding), plus `cyc` (psx_get_cycle_count) and counts. +``` +t2probe.py fpcap native.json 4096 # native run +t2probe.py fpcap interp.json 4096 # PSX_OVERLAY_NATIVE_OFF=1 run +t2probe.py fpdiff native.json interp.json # first divergent frame per column +``` +`wr` differs ⇒ state fork. `pc` only ⇒ same writes, different path. `mmio`/`sp` +⇒ device/scratchpad fork. `cyc` ⇒ timing. + +### Layer 2 — which ACCESS forks (frame-gated unified recorder) +Arm the recorder for the divergent frame N *before the run reaches it* — seed +`PSX_RECORD_FRAME=N` at boot (race-free; do NOT connect-and-arm, you'll lose the +race). It records every main-RAM/scratchpad/MMIO write **and** MMIO read for that +one frame, in true execution order (array index = order), each with `cyc`. +``` +# launch with PSX_RECORD_FRAME= (and PSX_OVERLAY_NATIVE_OFF=1 for the interp run) +t2probe.py recdump native_rec.json +t2probe.py recdump interp_rec.json +t2probe.py recdiff_state native_rec.json interp_rec.json # first divergent RAM WRITE +``` +Use **`recdiff_state`** (addr,val only) for the genuine state fork. Plain +`recdiff` includes `pc` and will flag benign store-PC attribution differences +(e.g. a RAM routine executed as a byte-identical BIOS alias) before the real +fork. MMIO read counts also differ benignly once the backends diverge, so don't +align reads by index. + +### Layer 3 — value vs pointer vs timing +- **Read-watch**: `PSX_READ_WATCH="0xLO,0xHI"` at boot records main-RAM *reads* + in `[LO,HI)` (kind `ramr`) interleaved in the recorder. Proves what value each + backend loads from a suspect address, and whether it even reads it (pointer + equality). Hot-path cost is one `int` flag check; off by default. +- **Per-entry `cyc`**: every recorder entry carries the cycle count, so you can + see the exact cycle position at a divergent MMIO/timer read — distinguishing a + timing/timer fork from a data fork. + +Always confirm the end state **visually** (`shot.py`), not by a frame counter. + +## Files +- `t2probe.py` — the probe (fpcap/fpdiff/recarm/recdump/recdiff/recdiff_state). +- `waitf.py` — retry-connect + poll until a target frame. +- `shot.py` — screenshot to PNG for visual verification. +- (`debug_client.py` lives one dir up in `tools/`.) + +## Worked example — Tomba 2 logo→FMV stall (2026-06-24) +Frames 1..1822 byte-identical incl. scratchpad and cycle count. First fork at a +Timer1 (`0x1F801110`) debounce loop (game pc `0x8008592C`): native read 1, interp +read 2 → logo never advances to the intro FMV. Root cause was a guest-cycle +divergence: compiled-overlay code was built **without** `PSX_ENABLE_BLOCK_CYCLES` +so it charged ~0 cycles while the dirty-interp charged per-instruction. The +read-watch proved the jalr target was identical in both backends (`[a0]=0x800896E0`), +killing the "jalr divergence" theory; `recdiff_state` + per-entry `cyc` pinned the +Timer1 value fork; the `sp` column ruled out a scratchpad blind spot. diff --git a/tools/divergence/shot.py b/tools/divergence/shot.py new file mode 100644 index 00000000..89ad5094 --- /dev/null +++ b/tools/divergence/shot.py @@ -0,0 +1,15 @@ +#!/usr/bin/env python3 +"""shot.py - screenshot the runtime to a PNG (then Read it to +verify VISUALLY; a frame counter advancing != visually progressing). Dev tooling.""" +import sys, os +sys.path.insert(0, os.path.dirname(os.path.dirname(os.path.abspath(__file__)))) +from debug_client import connect, send_cmd + +port = int(sys.argv[1]); path = sys.argv[2] +s = connect(port=port, timeout=15) +for cmd in ("screenshot_file", "screenshot"): + r = send_cmd(s, {"cmd": cmd, "path": path}) + print(cmd, "->", {k: r.get(k) for k in ("ok", "error", "path")}) + if r.get("ok"): + break +s.close() diff --git a/tools/divergence/t2probe.py b/tools/divergence/t2probe.py new file mode 100644 index 00000000..7042912b --- /dev/null +++ b/tools/divergence/t2probe.py @@ -0,0 +1,147 @@ +#!/usr/bin/env python3 +"""t2probe.py - native-vs-interp FIRST-DIVERGENCE probe for any PSX recomp title. + +Dev tooling (NOT shipped in releases). Pairs with the debug-server commands in +runtime/src/debug_server.c (all PSX_NO_DEBUG_TOOLS-stripped in release): + frame_fingerprint, record_frame, record_frame_dump, record_reads_dump +and the boot env seeds PSX_RECORD_FRAME and PSX_READ_WATCH (debug_server_init), +PSX_OVERLAY_NATIVE_OFF (overlay_loader.c, forces full dirty-interp = the oracle). + +METHOD (see README.md): two deterministic runs of the same title (native vs the +interp reference) are byte-identical until a codegen/timing bug forks them. + Layer 1 always-on per-frame fingerprint ring -> O(1) first divergent FRAME. + Layer 2 frame-gated unified ordered recorder -> first divergent ACCESS. + Layer 3 targeted read-watch + per-entry cycle count -> value vs pointer vs + timing classification at the fork. + +Commands: + fpcap [count=4096] [flo=-1] [fhi=-1] + fpdiff first divergent frame per column + (wr/pc/mmio/sp/cyc) + recarm arm the unified recorder (or seed + PSX_RECORD_FRAME at boot - race-free) + recdump drain the unified ordered access log + recdiff first divergent access incl. pc + recdiff_state first divergent RAM-WRITE (addr,val + only; ignores pc + reads) = real state + fork. Use this, not recdiff, once the + backends differ in store-PC attribution + or MMIO read interleaving. + +Tip: a `pc`-only difference in recdiff is usually a benign store-PC attribution +artifact (e.g. a RAM routine aliased to a byte-identical BIOS body); recdiff_state +finds the genuine machine-state fork. Per-entry `cyc` (psx_get_cycle_count) +distinguishes a timing/timer fork from a data fork. +""" +import json, sys, os + +# Resolve the sibling tools/ dir (holds debug_client.py) relative to this file. +_TOOLS = os.path.dirname(os.path.dirname(os.path.abspath(__file__))) +sys.path.insert(0, _TOOLS) +from debug_client import connect, send_cmd + + +def q(port, d): + s = connect(port=int(port)) + try: + return send_cmd(s, d) + finally: + s.close() + + +def fpcap(port, out, count=4096, flo=-1, fhi=-1): + r = q(port, {"cmd": "frame_fingerprint", "count": int(count), + "frame_lo": int(flo), "frame_hi": int(fhi)}) + ents = r.get("entries", []) + json.dump(ents, open(out, "w")) + print(f"captured {len(ents)} frames (total={r.get('total')}) -> {out}") + if ents: + print(f" frame range {ents[0]['frame']}..{ents[-1]['frame']}") + + +def fpdiff(a, b): + A = json.load(open(a)); B = json.load(open(b)) + ma = {e["frame"]: e for e in A}; mb = {e["frame"]: e for e in B} + common = sorted(set(ma) & set(mb)) + print(f"{a} frames={len(A)} {b} frames={len(B)} common={len(common)}" + f" [{common[0] if common else '-'}..{common[-1] if common else '-'}]") + cols = ["wr", "pc", "mmio", "sp", "cyc"] + first = {c: None for c in cols} + for f in common: + for c in cols: + if first[c] is None and ma[f].get(c) != mb[f].get(c): + first[c] = f + print("First divergent frame per column:") + for c in cols: + f = first[c] + if f is None: + print(f" {c:>5}: (identical across common range)") + else: + print(f" {c:>5}: frame {f}\n A={ma[f].get(c)} B={mb[f].get(c)}") + for cc in ("wc", "mc", "sc"): + print(f" {cc}: A={ma[f].get(cc)} B={mb[f].get(cc)}") + + +def recarm(port, frame): + print(q(port, {"cmd": "record_frame", "frame": int(frame)})) + + +def recdump(port, out): + ents, off = [], 0 + while True: + r = q(port, {"cmd": "record_frame_dump", "offset": off, "count": 4000}) + e = r.get("entries", []) + if not e: + break + ents.extend(e); off += len(e) + if off >= r.get("total", 0): + break + json.dump({"entries": ents}, open(out, "w")) + kinds = {} + for e in ents: + kinds[e["kind"]] = kinds.get(e["kind"], 0) + 1 + print(f"dumped {len(ents)} unified entries -> {out}\n kinds: {kinds}") + + +def recdiff(a, b): + A = json.load(open(a))["entries"]; B = json.load(open(b))["entries"] + print(f"A={len(A)} entries B={len(B)} entries") + n = min(len(A), len(B)); div = None + for i in range(n): + if (A[i]["kind"], A[i]["addr"], A[i]["val"], A[i]["pc"]) != \ + (B[i]["kind"], B[i]["addr"], B[i]["val"], B[i]["pc"]): + div = i; break + if div is None: + print(f"common prefix identical; lengths differ at i={n}" if len(A) != len(B) else "identical") + return + print(f"FIRST DIVERGENT ACCESS at execution index i={div}") + for i in range(max(0, div - 4), min(n, div + 4)): + m = ">>" if i == div else " " + print(f"{m} i={i}\n A {A[i]['kind']:>5} addr={A[i]['addr']} val={A[i]['val']} pc={A[i]['pc']} cyc={A[i].get('cyc')}" + f"\n B {B[i]['kind']:>5} addr={B[i]['addr']} val={B[i]['val']} pc={B[i]['pc']} cyc={B[i].get('cyc')}") + + +def recdiff_state(a, b): + """First divergent RAM-WRITE (addr,val) ignoring pc and reads. This is the + real state fork (what wr_hash/sp_hash measure); store-PC attribution and MMIO + read interleaving differ benignly between backends.""" + A = [e for e in json.load(open(a))["entries"] if e["kind"] in ("ramw", "spw")] + B = [e for e in json.load(open(b))["entries"] if e["kind"] in ("ramw", "spw")] + print(f"A ramw+spw={len(A)} B ramw+spw={len(B)}") + n = min(len(A), len(B)); div = None + for i in range(n): + if (A[i]["kind"], A[i]["addr"], A[i]["val"]) != (B[i]["kind"], B[i]["addr"], B[i]["val"]): + div = i; break + if div is None: + print(f"common write-prefix identical; lengths differ at i={n}" if len(A) != len(B) else "identical") + return + print(f"FIRST DIVERGENT RAM WRITE at write-index {div}") + for i in range(max(0, div - 4), min(n, div + 5)): + m = ">>" if i == div else " " + print(f"{m} w{i} A {A[i]['kind']:>4} {A[i]['addr']}={A[i]['val']} (pc {A[i]['pc']} cyc {A[i].get('cyc')})" + f" B {B[i]['kind']:>4} {B[i]['addr']}={B[i]['val']} (pc {B[i]['pc']} cyc {B[i].get('cyc')})") + + +if __name__ == "__main__": + cmd = sys.argv[1] + globals()[cmd](*sys.argv[2:]) diff --git a/tools/divergence/waitf.py b/tools/divergence/waitf.py new file mode 100644 index 00000000..73dfa80a --- /dev/null +++ b/tools/divergence/waitf.py @@ -0,0 +1,33 @@ +#!/usr/bin/env python3 +"""waitf.py [timeout_s=180] - retry-connect, poll `frame` +until >= target, print progress. The debug server may abort a persistent socket +between commands under load; this reconnects and keeps polling. Dev tooling.""" +import sys, time, os +sys.path.insert(0, os.path.dirname(os.path.dirname(os.path.abspath(__file__)))) +from debug_client import connect, send_cmd + +port = int(sys.argv[1]); target = int(sys.argv[2]) +deadline = time.time() + (float(sys.argv[3]) if len(sys.argv) > 3 else 180) +s = None +while time.time() < deadline and s is None: + try: + s = connect(port=port, timeout=10) + except OSError: + time.sleep(0.3) +if not s: + print("ERR connect"); sys.exit(1) +last = -1 +while time.time() < deadline: + try: + f = send_cmd(s, {"cmd": "frame"}).get("frame") + except Exception: + time.sleep(0.3) + try: s = connect(port=port, timeout=10) + except OSError: pass + continue + if f != last: + print("frame", f, flush=True); last = f + if isinstance(f, int) and f >= target: + print("REACHED", f); break + time.sleep(0.5) +s.close()