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 <noreply@anthropic.com>
This commit is contained in:
Matthew Stanley
2026-06-24 10:44:35 -07:00
parent c6f5193ac4
commit 1252c61c9d
4 changed files with 268 additions and 0 deletions
+73
View File
@@ -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 <port> native.json 4096 <flo> <fhi> # native run
t2probe.py fpcap <port> interp.json 4096 <flo> <fhi> # 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=<N> (and PSX_OVERLAY_NATIVE_OFF=1 for the interp run)
t2probe.py recdump <port> native_rec.json
t2probe.py recdump <port> 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.
+15
View File
@@ -0,0 +1,15 @@
#!/usr/bin/env python3
"""shot.py <port> <out.png> - 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()
+147
View File
@@ -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 <port> <out.json> [count=4096] [flo=-1] [fhi=-1]
fpdiff <a.json> <b.json> first divergent frame per column
(wr/pc/mmio/sp/cyc)
recarm <port> <frame> arm the unified recorder (or seed
PSX_RECORD_FRAME at boot - race-free)
recdump <port> <out.json> drain the unified ordered access log
recdiff <a.json> <b.json> first divergent access incl. pc
recdiff_state <a.json> <b.json> 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:])
+33
View File
@@ -0,0 +1,33 @@
#!/usr/bin/env python3
"""waitf.py <port> <target_frame> [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()