phase4: SELECT-deassert protocol reset + slot-state instrumentation

Real card protocol restarts on every fresh 0x81 — SELECT deassert is
a bus-wide reset signal. Earlier model preserved mc_state across
deassert via mc_save_slot, which caused every subsequent 0x81 to land
on a stale non-IDLE saved state and trigger abort_reselect bookkeeping.
Audit confirmed the BIOS-visible RX was still correct (the abort path
itself reset mc_state), but the retained sector/cmd/counter context
across logically-independent transactions was wrong per no$psx.

Clear volatile protocol state on SELECT deassert (state, cmd, sector,
sector_msb, sector_lsb, data_idx, checksum on both slots). Preserve
mc_slots[].flag (persistent "new card" metadata) and mc_slots[].data
(sector buffer, harmless to retain).

Result on a 4-press boot run: 6 transactions reach READ_DATA (ts=10)
and successfully read the "MC" header magic (RX bytes 0x4D 0x43);
remaining txns continue as 4-byte presence pings. Pre-fix: 0 reads
of card data ever; post-fix: card protocol can complete the setup
phase and enter data phase.

The byte-15 abort that follows is a separate blocker — kernel chain
dispatcher interleaves pad polling into the card data read. Tracked
for next session via the chain dispatcher disassembly.

Also includes:
- Slot-state capture in SioTraceEntry + sio_trace JSON emission
- dirty_ram_interp: replace mid-block fprintf+fflush with a counter
  (CLAUDE.md §3 — synchronous Windows console I/O at high rate
  starves the dispatch loop)
- Passive Python TCP probes (raw_tcp, trace_audit, trace_range,
  txn_summary, txn_dist, txn_bytes, drs_filter, readram_test,
  step_audit{,2}, verify_card_buffer, wtrace_filter)
- docs/MEMCARD_AUDIT_2026_04_28.md (prior session's 7-layer audit)

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
This commit is contained in:
Matthew Stanley
2026-04-29 14:46:26 -07:00
parent 5b3c7dd08d
commit 8b0fc34714
20 changed files with 1242 additions and 28 deletions
+294
View File
@@ -0,0 +1,294 @@
# Memory-Card End-to-End Audit — 2026-04-28
Branch: `feature/cycle-paced-sio-irq` @ commit `5b3c7dd`
Date: 2026-04-28
Operator: full audit run on a freshly-rebuilt native runtime (`psx-runtime.exe`).
End-to-end success criterion: real `.mcr` save data (e.g. the
`BISLPS-01234SAVE00` save title in `card1.mcd`) appears as a list entry
on the BIOS MEMORY CARD screen, having travelled through the real SIO
protocol — no HLE shims, no fake directory entries, no edits to
generated code.
This audit walks all seven layers, fills the table, and identifies the
first failed layer with a fix proposal scoped to it. No source change
beyond two infrastructure additions made during the audit
(`tools/debug_client.py` JSON-read fix; new `card_buffer_dump` TCP
command).
---
## Audit table
| # | Layer | Component | Expected | Observed | Evidence | Verdict |
|---|---|---|---|---|---|---|
| 1.1 | L1 | `bios/dummy.0.mcr` exists | exists per session prompt | does NOT exist | `ls -la bios/` shows only `SCPH1001.BIN`, `dummy.bin`, `dummy.cue`, `scph5501.bin` | **FAIL (prompt-only — informational)** |
| 1.2 | L1 | All `.mcr`/`.mcd` files are 131072 B | 131072 | all four are 131072 B | `ls -la card1.mcd card2.mcd dummy.0.mcr dummy.1.mcr` | PASS |
| 1.3 | L1 | "MC" magic at offset 0 | `4D 43` | `4D 43` on all four | `xxd -s 0 -l 0x80` on each | PASS |
| 1.4 | L1 | Frame 1 dir entry semantics | "used" or "free" with valid checksum | card1.mcd: 2 used (BISLPS-01234SAVE00, BASLUS-56789DATA01); card2.mcd: empty; dummy.0.mcr: 2 used (same first two as card1 but blocks 3-15 differ); dummy.1.mcr: 1 used (BASLUS-0125100000-00) | hex dump | PASS |
| 1.5 | L1 | Native source = Beetle source (sha256) | byte-equal | sha256 differs across all four pairs (even the first 16-frame directory region differs) | `sha256sum card1.mcd dummy.0.mcr` → `f79bfc41…` vs `e146de7c…` | **FAIL (test-setup, blocks oracle byte-diff)** |
| 2.1 | L2 | slot 0 in-memory buffer = `card1.mcd` on disk | byte-equal sha256 | MATCH | `python tools/verify_card_buffer.py` slot 0 sha = disk sha = `f79bfc41…` | PASS |
| 2.2 | L2 | slot 1 in-memory buffer = `card2.mcd` on disk | byte-equal sha256 | MATCH | same script slot 1 sha = `7706c7d4…` | PASS |
| 3.1 | L3 | Card transactions occur after entering MC screen | ≥1 closed READ txn | 542 attempted | `card_txn_dump count=10000` yields 542 entries | PASS |
| 3.2 | L3 | Each READ TX byte sequence matches protocol | 0x81, 0x52, 0x00, 0x00, … | first 4 TX correct, txn never gets past byte 4 | `card_txn_dump`: every entry has `tx:[0x81,0x52,0x00,0x00]` | PARTIAL |
| 3.3 | L3 | Each READ RX matches no$psx protocol | 0xFF, 0x00 (flag), 0x5A, 0x5D, 0x00, 0x00, 0x5C, 0x5D, echo_msb, echo_lsb, 128 data, chk, 0x47 | `[0xFF, 0x00, 0x5A, 0x5D]` only — protocol-correct for the first 4 bytes (mc_flag=0 after first read; ID bytes 0x5A 0x5D follow) | `card_txn_dump` rx field | PASS for the bytes seen |
| 3.4 | L3 | Transaction reaches END (terminal_state=12) | success | **all aborted** — 537 / 542 = `abort_reselect` at terminal_state=4 (MC_ADDR_MSB); 6 = `abort_reset` at terminal_state=0; 1 open; 0 success | `card_txn_dump` aggregate (see transcript A) | **FAIL** |
| 3.5 | L3 | RX matches Beetle byte-for-byte | byte equal | NOT MEASURED — gated on Layer 1 file equality, currently FAIL | (would be `card_txn_diff`) | BLOCKED-BY-L1 |
| 4.1 | L4 | Install handler at RAM 0xCF0 fires per byte | one fire per RX byte | install handler fired 26,030 times (3 insns/fire); chain entry 0x641C fired 26,030 times | `dirty_ram_stats` → per_pc 0xCF0 hits=26030 | PASS (handler runs) |
| 4.2 | L4 | `[0x72F0]` data-byte counter advances 0..127 | monotonic increase to 127 per sector | currently `[0x72F0] = 0`; never observed > 1 in any window | `read_ram addr=0x800072F0 len=4` | **FAIL** |
| 4.3 | L4 | `[0x755A]` abort flag = 0 across a transaction | 0 | currently 0; setter pattern matches prior memo `phase4_real_blocker_2026_04_28.md` (R1/D1 set unconditionally) | `read_ram addr=0x8000755A` (and `wtrace_dump` for slot 7) | needs deeper trace |
| 5.1 | L5 | I_MASK bit 7 (SIO) gets set during chain enter | ≥1 set | bit7_sets=205, bit7_clears=205 — toggled 205× during exception entries | `imask_trace count=64` | PASS |
| 5.2 | L5 | One IRQ #7 fires per card-protocol byte | 4-138 card IRQs per txn | **0 card-source IRQs in 200,000 most-recent IRQ entries** (full ring) — every recent IRQ is `src=pad` | `sio_irq_dump count=200000 src=1` → `entries:[]`, `emitted:0` | **FAIL — root signal** |
| 5.3 | L5 | `sio_irq_pending` arms after card TX byte | nonzero for ~delay cycles | `sio_irq_countdown` is set to `SIO_IRQ_DELAY_CARD=8` on every TX, but ticks happen only on SIO register access (`sio.c:830,961`) and on interpreter-step (`psx_interpreter.c:517`); between two card TX bursts the BIOS does <8 SIO accesses, so the countdown is rearmed before reaching 0 → IRQ never fires for cards | code read of `sio.c:854-894,974-1008` | **FAIL — proximate cause of 5.2** |
| 6.1 | L6 | `[0x80007568]` slot gates non-zero after card detect | ≥1 byte set | `01 01 00 00 01 …` — both slots flagged | `read_ram addr=0x80007568 len=16` | PASS |
| 6.2 | L6 | `[0x800074BC]` read flag set | 1 during read | `01 00 00 00` | `read_ram` | PASS |
| 6.3 | L6 | `[0x800075C0]` mode word | nonzero during read | `00 00 00 00` (currently idle) | `read_ram` | inconclusive (state machine returned idle by audit time) |
| 6.4 | L6 | `[0x80007550]` buffer ptr set before data phase | nonzero RAM pointer | `00 00 00 00` | `read_ram` | **FAIL** (buffer never set up — read never reached data phase) |
| 7.1 | L7 | MEMORY CARD screen reaches per-card directory listing | 15-row directory grid with save titles | screen shows MEMORY CARD operations menu (EXIT/COPY/COPY ALL/DELETE) only — no per-slot directory listing rendered; CARD 1 and CARD 2 column headers are visible but directory contents are blank | `screenshot_file` → `psx_screenshot.bmp` (see image: `MEMORY CARD operations` menu, no titles) | **FAIL** |
---
## Evidence transcripts
### Transcript A — card transaction outcome distribution
```
$ python tools/raw_tcp.py 4370 card_txn_dump count=10000 | grep -oE '"end_reason":"[^"]+"' | sort | uniq -c
537 "end_reason":"abort_reselect"
6 "end_reason":"abort_reset"
1 "end_reason":"open"
$ python tools/raw_tcp.py 4370 card_txn_dump count=10000 | grep -oE '"terminal_state":[0-9]+' | sort | uniq -c
7 "terminal_state":0 # MC_IDLE — never even started CMD
539 "terminal_state":4 # MC_ADDR_MSB — got 4 bytes, then aborted
$ python tools/debug_client.py card_txn_dump count=2 | head -40
{
"id": 0, "ok": true, "total_closed": 94, "open": true, …
"entries": [
{
"txn_seq": 78, "slot": 0, "cmd": "0x52", "sector": "0xFFFF",
"bytes": 4, "acks": 1,
"end_reason": "abort_reselect", "terminal_state": 4,
"tx": ["0x81", "0x52", "0x00", "0x00"],
"rx": ["0xFF", "0x00", "0x5A", "0x5D"]
}, …
```
Note: the `acks` field counts only the SELECT-byte ACK (`sio_mc_ack_count`
incremented at `sio.c:442`; subsequent state transitions set
`SIO_STAT_ACK` but don't increment that counter). It is misleading
without context.
### Transcript B — IRQ ring delivery profile
```
$ python tools/raw_tcp.py 4370 sio_irq_dump count=200000 src=1
{"id":1,"ok":true,"total":200000,"shown":200000,"src_filter":1,"entries":[
],"emitted":0}
$ python tools/raw_tcp.py 4370 sio_irq_dump count=20000 | grep -c '"src": "card"'
0
$ python tools/raw_tcp.py 4370 sio_irq_dump count=20000 | grep -c '"src": "pad"'
~20000 # 100% pad
```
### Transcript C — I_MASK toggle history (bit 7 SIO)
```
$ python tools/debug_client.py imask_trace count=4
… "bit7_sets": 205, "bit7_clears": 205, …
{"old":"0x04D","new":"0x0CD","func":"0x00005D98","pc":"0xBFC14930","b7s":1,"exc":1}
{"old":"0x0CD","new":"0x04D","func":"0x00001444","pc":"0xBFC14A28","b7c":1,"exc":1}
… (repeated 205 times)
```
I_MASK bit 7 IS being toggled in exception entry — masking is not the
problem. The problem is upstream of mask: the IRQ never fires.
### Transcript D — install-handler aggregate
```
$ python tools/raw_tcp.py 4370 dirty_ram_stats
{"blocks_run":26036, "insns_run":135391627, "aborts":38264, …
per_pc:[
{"pc":"0x00000CF0", "hits":26030, "insns":78090}, ← install handler stub
{"pc":"0x0000641C", "hits":26030, "insns":104120}, ← chain dispatcher entry
{"pc":"0x00006594", "hits":26024, "insns":26024},
{"pc":"0x000000B0", "hits":33642758, "insns":100928274}, ← B0 trampoline
…
]}
```
### Transcript E — state-word snapshot
```
$ python tools/raw_tcp.py 4370 read_ram addr=0x80007568 len=16
{"hex":"01010000010000000000000000000000"} # slot 0 + slot 1 detected
$ python tools/raw_tcp.py 4370 read_ram addr=0x800074BC len=4
{"hex":"01000000"} # read-flag = 1
$ python tools/raw_tcp.py 4370 read_ram addr=0x800072F0 len=4
{"hex":"00000000"} # data-byte counter = 0
$ python tools/raw_tcp.py 4370 read_ram addr=0x80007550 len=4
{"hex":"00000000"} # buffer ptr never set
$ python tools/raw_tcp.py 4370 read_ram addr=0x8000755A len=4
{"hex":"00000000"} # abort flag currently clear
```
### Transcript F — visual ground truth
`psx_screenshot.bmp` (after pressing CROSS to enter MEMORY CARD): the
"MEMORY CARD" operations menu is visible with EXIT / COPY / COPY ALL /
DELETE entries and CARD 1 / CARD 2 column headers, but **no per-slot
directory listing is rendered**. The save title "BISLPS-01234SAVE00"
that exists in `card1.mcd` frame 1 does not appear anywhere on screen.
---
## First failed layer
**Layer 3 — transaction completion** is the highest-numbered layer
where the user-visible failure crystallises (transactions truncate at
byte 4 of 138, `mc_read_done = 0`), but the **proximate cause is
Layer 5 — IRQ delivery**. Every other failed row (4.2, 4.3, 6.4, 7.1)
is downstream of "no card IRQ ever fires".
Specifically: in the 200,000-entry IRQ ring (full SIO_IRQ_RING_CAP),
**zero entries have source = `card`**. 542 transactions were attempted,
each rearmed `sio_irq_countdown = SIO_IRQ_DELAY_CARD = 8` on the TX
write, and zero of those countdowns ever reached 0.
### Why the existing access-paced model can't deliver card IRQs
`sio_tick()` decrements the countdown on each call. It is called from
(`grep -rn 'sio_tick' runtime/`):
- every `sio_read()` (sio.c:830) — SIO_RX_DATA / SIO_STAT / etc.
- every I_STAT read (memory.c:220, 309)
- every read of an `0x1F801070..0x1F801074` register (memory.c:365)
- every interpreter step (psx_interpreter.c:517)
For pads (delay = 4), the BIOS pad-poll routine touches SIO heavily —
it tight-polls SIO_STAT after each TX byte until RX_RDY appears.
4 ticks accumulate easily, IRQ fires.
For cards (delay = 8), the BIOS card-protocol path is **chain-driven,
not poll-driven**: the chain handler writes one TX byte and returns,
expecting the next IRQ to drive the next byte. Between TX writes the
BIOS performs only a handful of SIO accesses. The countdown does not
reach 0 before the next TX rearms it. The IRQ never fires, so the
chain never re-enters, so the next byte never goes out, so the BIOS
times out and writes SIO_CTRL.RESET — which `txn_close` records as
`abort_reselect`.
This is not an unmasked-IRQ issue (Transcript C confirms I_MASK bit 7
is set on every chain enter). It is not a state-machine-byte issue
(Transcript A confirms the bytes our state machine returns are correct
for the first 4 positions). It is a pacing-model issue.
---
## Proposed fix (scoped to Layer 5)
The fix must move from access-paced to **time/cycle-paced** SIO IRQ
delivery, which is what real hardware does (~170 cycles after each
ACK, independent of register-access count). The branch name
`feature/cycle-paced-sio-irq` already states this intention; the
implementation has not landed.
### Concrete proposal
1. **Replace `sio_irq_countdown` with a frame-clock deadline.** Add a
monotonic counter ticked once per dispatched recompiled function
(or once per VBlank — the runtime does not have a true cycle
counter). On TX write, set
`sio_irq_deadline = sio_clock + N` where N is calibrated to "fires
within the same VBlank for a 138-byte card sector at 60 Hz" → at
most ~430 µs per byte → calibrate to ~1 dispatch loop iteration for
pads, similar for cards.
2. **Drive `sio_tick()` from the dispatch loop**, not from register
accesses. Call `sio_tick()` from `psx_dispatch` once per dispatched
function (or once per N functions). This gives consistent pacing
regardless of what the BIOS happens to be doing between bytes.
3. **Keep the access-paced ticks as a faster fast-path** so existing
pad protocol stays correct (or — preferably — re-validate pad
timing after the change and consolidate to the single model).
### Risk-bounded interim step
Before doing the full rework, run a **calibration probe**: change
`SIO_IRQ_DELAY_CARD` from 8 → 4 (matching pad). If 4 is enough to let
even one card IRQ through, we will see card-source entries appear in
`sio_irq_dump`, mc_max_state will exceed 4, and `card_txn_dump` will
show a transaction that gets past `terminal_state=4`. If yes — the
diagnosis is correct and we plan the cycle-paced rewrite. If no — the
problem is elsewhere (chain abort flag at [0x755A], install-handler
miswire) and we revisit.
This calibration is exactly the kind of "is the hypothesis true"
measurement the audit was designed to gate. **No code change should
land until the calibration probe demonstrates a measurable shift in
the metrics this audit captured.**
### Out of scope for the first fix
- Layer 1 file-name divergence (card?.mcd vs dummy.?.mcr) — should be
unified before the next cross-oracle byte-diff session, but does not
block the native-side card path from working.
- The 23k-line/min `[dirty_ram_interp] WARN` fprintf flood
(CLAUDE.md §3 violation in `runtime/src/dirty_ram_interp.c`) —
separate cleanup task; doesn't block this fix.
- Visual sprite corruption on highlighted UI items (cursor sprite
rendering) — not on the card data path.
- The MEMORY CARD operations menu rendering after no-data — that's
expected BIOS behavior when the directory read fails. Once Layer 5
is fixed, we re-test Layer 7.
---
## Verification (after fix lands)
End-to-end success of the fix:
1. `python tools/raw_tcp.py 4370 sio_irq_dump count=200 src=1` — must
show non-empty entries (≥1 card-source IRQ).
2. `python tools/raw_tcp.py 4370 card_txn_dump count=20` — must show
≥1 entry with `terminal_state` reaching `MC_READ_END=12` and
`end_reason: success`.
3. `python tools/raw_tcp.py 4370 read_ram addr=0x800072F0 len=4` —
must show `[0x72F0]` reaching values > 1 (confirming the
`phase4_72f0_one_byte_per_vblank` hypothesis is resolved).
4. `python tools/raw_tcp.py 4370 sio_state` — `mc_read_done` must be
≥ 1.
5. `screenshot_file` after navigating into CARD 1 — the BMP must show
the save title `BISLPS-01234SAVE00` (from `card1.mcd` frame 1) as
a list entry.
The screenshot (5) is ground truth. Until the save title is on screen
the session is not complete.
---
## Tooling additions / fixes made during this audit
These are minor infrastructure touch-ups, not BIOS-path changes. They
are committed regardless of whether the fix proposal is accepted, so
the audit harness stays repeatable.
- `tools/debug_client.py` — `send_cmd()` now reads multi-line JSON via
brace/bracket balance instead of stopping at the first `\n`; the
`pretty_regs` formatter now also reads the server's `gpr` array
(positional) when no `regs` dict is present. Both were broken
before, hiding all GPRs and corrupting `card_txn_dump` parsing.
- `tools/raw_tcp.py` — same brace-balance read; `0x…` arg values are
preserved as JSON strings (server's `read_ram` etc. expect strings).
- `runtime/include/memcard.h` + `runtime/src/memcard.c` — new
`memcard_debug_read_buffer()` accessor.
- `runtime/src/debug_server.c` — new `card_buffer_dump` TCP command
(slot, offset, len → hex). Used by `tools/verify_card_buffer.py` to
prove Layer 2.
- `tools/verify_card_buffer.py` — pulls slot 0/1 buffers and
sha256-compares to disk.
No edits to generated code (Rule 4 / Rule 14). No fprintf added.
+6
View File
@@ -30,6 +30,12 @@ int memcard_debug_info(int card, const char **path_out,
uint8_t magic_out[2], int *present_out,
int *dirty_out);
/* Copy raw bytes out of the in-memory card image. Used by the debug server
* to verify that what the runtime loaded matches the on-disk file.
* Returns the number of bytes copied (0 if slot empty / range invalid). */
int memcard_debug_read_buffer(int card, uint32_t offset, uint32_t len,
uint8_t *dst);
#ifdef __cplusplus
}
#endif
+6 -1
View File
@@ -49,8 +49,13 @@ typedef struct {
uint8_t was_abort; /* 1 if this byte caused mc_state abort */
uint8_t irq_countdown; /* sio_irq_countdown at entry */
uint8_t in_exception; /* psx_get_in_exception() at time of byte */
uint8_t counter_7514; /* RAM[0x7514] at time of byte */
uint8_t counter_7514; /* RAM[0x7514] at time of byte */
uint32_t cop0_sr; /* COP0 SR at time of byte (IEc=bit0, IM2=bit10) */
/* Saved slot states captured AT TRACE TIME (after the byte was processed
* and any mc_save/load_slot has run). Lets the audit show whether a
* SELECT-deassert preserved state into the next 0x81. */
uint8_t slot0_state;
uint8_t slot1_state;
} SioTraceEntry;
/* Get pointer to ring buffer and current write index.
+92 -2
View File
@@ -1254,6 +1254,91 @@ static void handle_mc_status(int id, const char *json)
m1[0], m1[1]);
}
/* ---- SIO IRQ-arm audit -----------------------------------------------
* Reports counts of TX writes that reached the IRQ-arm decision in
* sio_write SIO_TX_DATA, partitioned by active_device. Tells us at the
* arm-time gate whether ACK + ACK_IRQ_EN were set, or which side blocked
* the arm. Steps 3-4 of the IRQ-chain audit. */
extern void sio_get_card_arm_audit(uint32_t out[3][7]);
extern int sio_get_card_arm_countdown_after(void);
extern void sio_get_burst_stats(uint64_t out[10]);
static void handle_sio_burst_stats(int id, const char *json)
{
(void)json;
uint64_t s[10];
sio_get_burst_stats(s);
const char *reason_str =
s[8] == 1 ? "idle" :
s[8] == 2 ? "mode_clear" :
s[8] == 3 ? "capped" : "n/a";
send_fmt("{\"id\":%d,\"ok\":true,"
"\"calls\":%llu,\"iters_total\":%llu,\"iter_max\":%llu,"
"\"break_idle\":%llu,\"break_mode_clear\":%llu,\"break_capped\":%llu,"
"\"fires_in_burst\":%llu,\"last_iters\":%llu,"
"\"last_break_reason\":\"%s\"}\n",
id,
(unsigned long long)s[0], (unsigned long long)s[1], (unsigned long long)s[2],
(unsigned long long)s[3], (unsigned long long)s[4], (unsigned long long)s[5],
(unsigned long long)s[6], (unsigned long long)s[7],
reason_str);
}
static void handle_sio_arm_audit(int id, const char *json)
{
(void)json;
uint32_t a[3][7];
sio_get_card_arm_audit(a);
int cd_after = sio_get_card_arm_countdown_after();
const char *names[3] = { "card", "pad", "none" };
send_fmt("{\"id\":%d,\"ok\":true,\"countdown_after_last_card\":%d,\"by_device\":{",
id, cd_after);
for (int i = 0; i < 3; i++) {
if (i > 0) send_fmt(",");
send_fmt("\"%s\":{\"tx_total\":%u,\"armed\":%u,\"no_ack\":%u,\"no_ackirqen\":%u,"
"\"ctrl_last\":\"0x%04X\",\"stat_pre_last\":\"0x%04X\",\"stat_post_last\":\"0x%04X\"}",
names[i], a[i][0], a[i][1], a[i][2], a[i][3], a[i][4], a[i][5], a[i][6]);
}
send_fmt("}}\n");
}
/* ---- Memory card raw buffer dump (in-memory cards[].data) ----
* Used by the audit harness to verify that what the runtime loaded matches
* the on-disk file byte-for-byte. Returns hex string, chunked. */
static void handle_card_buffer_dump(int id, const char *json)
{
int slot = json_get_int(json, "slot", 0);
int offset = json_get_int(json, "offset", 0);
int len = json_get_int(json, "len", 256);
if (slot < 0 || slot > 1) { send_err(id, "bad slot"); return; }
if (offset < 0 || offset > 0x20000) { send_err(id, "bad offset"); return; }
if (len < 1) { send_err(id, "bad len"); return; }
if (len > 0x20000) len = 0x20000;
if (offset + len > 0x20000) len = 0x20000 - offset;
uint8_t *buf = (uint8_t *)malloc((size_t)len);
if (!buf) { send_err(id, "alloc failed"); return; }
int got = memcard_debug_read_buffer(slot, (uint32_t)offset, (uint32_t)len, buf);
if (got <= 0) { free(buf); send_err(id, "slot empty or read failed"); return; }
/* hex envelope: 2 chars/byte + ~256 envelope */
size_t env = 256;
size_t total = (size_t)got * 2 + env;
char *out = (char *)malloc(total);
if (!out) { free(buf); send_err(id, "alloc failed"); return; }
int hdr = snprintf(out, env,
"{\"id\":%d,\"ok\":true,\"slot\":%d,\"offset\":%d,\"len\":%d,\"hex\":\"",
id, slot, offset, got);
char *hex = out + hdr;
for (int i = 0; i < got; i++)
snprintf(hex + (size_t)i * 2, 3, "%02x", buf[i]);
char *tail = hex + (size_t)got * 2;
memcpy(tail, "\"}", 3);
debug_server_send_line(out);
free(out);
free(buf);
}
/* ---- I_MASK bit 7 trace (card protocol flow) ---- */
typedef struct {
uint32_t old_mask;
@@ -1333,13 +1418,15 @@ static void handle_sio_trace(int id, const char *json)
"\"dev_pre\":%d,\"dev_post\":%d,"
"\"ctrl\":\"0x%04X\",\"func\":\"0x%08X\","
"\"abort\":%d,\"irq_cd\":%d,\"in_exc\":%d,\"ctr\":%d,"
"\"sr\":\"0x%08X\"}",
"\"sr\":\"0x%08X\","
"\"slot0\":%d,\"slot1\":%d}",
(unsigned)e->seq, e->tx, e->rx,
e->mc_state_pre, e->mc_state_post,
e->dev_pre, e->dev_post,
e->ctrl, (unsigned)e->func_addr,
e->was_abort, e->irq_countdown, e->in_exception,
e->counter_7514, (unsigned)e->cop0_sr);
e->counter_7514, (unsigned)e->cop0_sr,
e->slot0_state, e->slot1_state);
}
send_fmt("]}\n");
@@ -2743,6 +2830,9 @@ static const CmdEntry s_commands[] = {
{ "irq_state", handle_irq_state },
{ "sio_state", handle_sio_state },
{ "mc_status", handle_mc_status },
{ "card_buffer_dump", handle_card_buffer_dump },
{ "sio_arm_audit", handle_sio_arm_audit },
{ "sio_burst_stats", handle_sio_burst_stats },
{ "chain_trace", handle_chain_trace },
{ "sio_trace", handle_sio_trace },
{ "sio_pc_trace", handle_sio_pc_trace },
+18 -9
View File
@@ -35,6 +35,15 @@ uint64_t g_dirty_ram_blocks_run = 0;
uint64_t g_dirty_ram_insns_run = 0;
uint64_t g_dirty_ram_aborts = 0;
/* Mid-block unsupported-opcode counters. Bumped instead of fprintf-spamming
* stderr (CLAUDE.md §3). Read via dirty_ram_get_unsupported(). The "last_*"
* fields capture the most recent occurrence so a TCP query can see what
* opcode is missing without needing log scraping. */
uint64_t g_dirty_ram_unsupported_midblock = 0;
uint32_t g_dirty_ram_last_unsupported_pc = 0;
uint32_t g_dirty_ram_last_unsupported_insn = 0;
const char *g_dirty_ram_last_unsupported_reason = NULL;
DirtyRamPcEntry g_dirty_ram_pc_table[DIRTY_RAM_PC_TABLE_SIZE] = {0};
/* Linear-probed insert/lookup keyed on entry PC. Table is small (64) and
@@ -410,15 +419,15 @@ int dirty_ram_dispatch(CPUState* cpu, uint32_t addr) {
* targets — set cpu->pc=0 so the trampoline exits cleanly.
* If this turns out to be load-bearing, measurement will
* surface it as a card-protocol stall and we can add the
* missing opcode. */
fprintf(stderr,
"[dirty_ram_interp] WARN: unsupported opcode mid-block "
"at PC=0x%08X insn=0x%08X (%s) after %d insns; treating "
"block as no-op return.\n",
g_unsupported_pc, g_unsupported_insn,
g_unsupported_reason ? g_unsupported_reason : "?",
insns_executed);
fflush(stderr);
* missing opcode.
*
* No fprintf — read the last-* globals via TCP if needed
* (CLAUDE.md §3). Synchronous stderr at the rate this fires
* starves the dispatch loop and the debug-server poll. */
g_dirty_ram_unsupported_midblock++;
g_dirty_ram_last_unsupported_pc = g_unsupported_pc;
g_dirty_ram_last_unsupported_insn = g_unsupported_insn;
g_dirty_ram_last_unsupported_reason = g_unsupported_reason;
cpu->pc = 0;
return 1;
}
+12
View File
@@ -151,3 +151,15 @@ int memcard_debug_info(int card, const char **path_out,
if (dirty_out) *dirty_out = cards[card].dirty;
return 0;
}
int memcard_debug_read_buffer(int card, uint32_t offset, uint32_t len,
uint8_t *dst) {
if (card < 0 || card >= MAX_CARDS) return 0;
if (!cards[card].present) return 0;
if (!dst || len == 0) return 0;
if (offset >= MEMCARD_SIZE) return 0;
uint32_t avail = (uint32_t)MEMCARD_SIZE - offset;
if (len > avail) len = avail;
memcpy(dst, cards[card].data + offset, len);
return (int)len;
}
+230 -13
View File
@@ -192,6 +192,11 @@ int sio_card_protocol_active(void) {
return 0;
}
/* Forward decl: defined below sio_get_freeze_diag. */
static int sio_card_burst_drain(int max_iters);
extern int psx_get_in_exception(void);
extern uint8_t psx_read_byte(uint32_t addr);
/* ---- Card transaction ring buffer ---- */
static SioTxnEntry sio_txn_buf[SIO_TXN_CAP];
@@ -270,6 +275,77 @@ uint32_t sio_get_irq_ring(const SioIrqEntry **buf_out, int *write_idx_out) {
return sio_irq_seq;
}
/* ---- Card IRQ-arm audit -----------------------------------------------
* Per-call counters that record what happened at the IRQ-arm decision
* point in sio_write SIO_TX_DATA, partitioned by active_device==DEV_MEMCARD
* (card path) vs not (pad/none). For each card-path call we further
* record:
* - "tx_card": total card TX writes that reached this point
* - "armed_card": cases where (ACK && ACK_IRQ_EN) — countdown was set
* - "no_ack": cases where SIO_STAT_ACK was clear (state machine didn't ACK)
* - "no_ackirqen": cases where ACK was set but ACK_IRQ_EN bit was clear
* - "ctrl_last": last ctrl seen at decision time (for sanity)
* - "stat_pre_last", "stat_post_last": last seen sio_stat
* - "countdown_after_last": value of sio_irq_countdown after the if-block
* Same fields tracked for pad path so we can compare. Always-on; cheap. */
typedef struct {
uint32_t tx_total;
uint32_t armed;
uint32_t no_ack;
uint32_t no_ackirqen;
uint16_t ctrl_last;
uint16_t stat_pre_last;
uint16_t stat_post_last;
int32_t countdown_after_last;
} CardArmAudit;
static CardArmAudit s_card_arm_audit_card;
static CardArmAudit s_card_arm_audit_pad;
static CardArmAudit s_card_arm_audit_none;
void sio_card_arm_audit_record(int dev, uint16_t ctrl_pre,
uint16_t stat_pre, uint16_t stat_post,
int armed, int countdown_after) {
CardArmAudit *a = (dev == DEV_MEMCARD) ? &s_card_arm_audit_card
: (dev == DEV_PAD) ? &s_card_arm_audit_pad
: &s_card_arm_audit_none;
a->tx_total++;
if (armed) {
a->armed++;
} else {
/* SIO_STAT_ACK = (1<<7) = 0x0080;
* SIO_CTRL_ACK_IRQ_EN = (1<<12) = 0x1000.
* Constants are #define'd later in this file; re-state them here
* to avoid forward-decl ordering issues. */
if (!(stat_post & 0x0080u)) a->no_ack++;
else if (!(ctrl_pre & 0x1000u)) a->no_ackirqen++;
}
a->ctrl_last = ctrl_pre;
a->stat_pre_last = stat_pre;
a->stat_post_last = stat_post;
a->countdown_after_last = countdown_after;
}
void sio_get_card_arm_audit(uint32_t out[3][7]) {
/* row 0 = card, row 1 = pad, row 2 = none.
* cols: tx_total, armed, no_ack, no_ackirqen, ctrl_last, stat_pre, stat_post */
const CardArmAudit *src[3] = {
&s_card_arm_audit_card, &s_card_arm_audit_pad, &s_card_arm_audit_none };
for (int i = 0; i < 3; i++) {
out[i][0] = src[i]->tx_total;
out[i][1] = src[i]->armed;
out[i][2] = src[i]->no_ack;
out[i][3] = src[i]->no_ackirqen;
out[i][4] = (uint32_t)src[i]->ctrl_last;
out[i][5] = (uint32_t)src[i]->stat_pre_last;
out[i][6] = (uint32_t)src[i]->stat_post_last;
}
}
int sio_get_card_arm_countdown_after(void) {
return s_card_arm_audit_card.countdown_after_last;
}
int sio_get_mc_probe_count(void) { return sio_mc_probe_count; }
int sio_get_mc_ack_count(void) { return sio_mc_ack_count; }
int sio_get_mc_cmd_count(void) { return sio_mc_cmd_count; }
@@ -815,6 +891,8 @@ static void sio_process_byte(uint8_t tx_byte) {
{ extern uint8_t psx_read_byte(uint32_t addr);
/* Read card counter 0x7514 — low byte only for trace */
e->counter_7514 = psx_read_byte(0x7514); }
e->slot0_state = (uint8_t)mc_slots[0].state;
e->slot1_state = (uint8_t)mc_slots[1].state;
sio_trace_idx = (sio_trace_idx + 1) % SIO_TRACE_CAP;
sio_trace_seq++;
}
@@ -867,7 +945,16 @@ void sio_write(uint32_t addr, uint32_t value) {
sio_last_ctrl_on_tx = sio_ctrl;
if (!(sio_ctrl & SIO_CTRL_TX_EN)) sio_tx_gated++;
if (sio_ctrl & SIO_CTRL_TX_EN) {
/* IRQ-arm chain audit: capture pre-state for diagnostics.
* NOTE: bucket by active_device AT-DECISION-TIME (post-process),
* not pre-process — sio_process_byte (re)assigns active_device
* on its first byte / on deselect-continuation. */
uint16_t arm_dbg_ctrl_pre = sio_ctrl;
uint16_t arm_dbg_stat_pre = sio_stat;
sio_process_byte(sio_tx_data);
/* Capture the device the if-block will read. */
uint8_t arm_dbg_dev_at_decision = (uint8_t)active_device;
/* Model SIO busy: on real hardware TX_RDY clears during the
* byte transfer (~BAUD*8 cycles) and re-sets when complete.
* The BIOS pad polling tight-loops on TX_RDY before sending
@@ -875,6 +962,15 @@ void sio_write(uint32_t addr, uint32_t value) {
* over a card byte that's still "in flight", interleaving
* pad and card protocols within the same interrupt. */
sio_stat &= ~(SIO_STAT_TX_RDY | SIO_STAT_TX_EMPTY);
/* IRQ-arm chain audit: count attempts and failure reasons.
* Counted only for the card path (active_device==DEV_MEMCARD).
* Exposed via sio_get_card_arm_audit() / debug_server. */
extern void sio_card_arm_audit_record(int dev, uint16_t ctrl_pre,
uint16_t stat_pre, uint16_t stat_post,
int armed, int countdown_after);
int armed_now = 0;
if ((sio_stat & SIO_STAT_ACK) && (sio_ctrl & SIO_CTRL_ACK_IRQ_EN)) {
sio_stat &= ~SIO_STAT_ACK;
sio_irq_pending = 1;
@@ -889,7 +985,12 @@ void sio_write(uint32_t addr, uint32_t value) {
sio_irq_pending_delay = (uint8_t)sio_irq_countdown;
sio_irq_pending_mc_state = (uint8_t)mc_state;
sio_irq_pending_byte_seq = sio_trace_seq;
armed_now = 1;
}
sio_card_arm_audit_record(arm_dbg_dev_at_decision, arm_dbg_ctrl_pre,
arm_dbg_stat_pre, sio_stat,
armed_now, sio_irq_countdown);
}
break;
@@ -926,20 +1027,43 @@ void sio_write(uint32_t addr, uint32_t value) {
sio_irq_pending = 0;
sio_irq_countdown = 0;
}
/* On SELECT deassert, reset pad_state and active_device so the
* next byte exchange correctly identifies the device type.
* However, do NOT reset mc_state — the card protocol must
* survive brief SELECT drops between bytes. The BIOS writes
* CTRL=0x0000 between SIO byte exchanges to acknowledge IRQs,
* which briefly deasserts SELECT. On real hardware the card
* stays selected because DSR timing prevents instant deselect.
* sio_process_byte resumes the card protocol via mc_state when
* active_device has been cleared but mc_state is still active. */
/* On SELECT deassert: reset all volatile protocol state.
*
* Earlier model preserved mc_state into mc_slots[] so a card
* protocol could resume across brief SELECT drops (e.g. CTRL
* ACK writes during pad polling). Audit confirmed this caused
* EVERY new 0x81 after a SELECT-deassert to land on a saved
* non-IDLE state, triggering abort_reselect bookkeeping. The
* abort path itself resets mc_state, so the BIOS-visible RX is
* still correct — but the simulated card retaining sector/cmd/
* counter context across what BIOS treats as independent
* transactions is wrong per the no$psx model: real cards
* restart on every fresh 0x81. SELECT is a bus-wide signal;
* both physical cards see the deassert and reset their state
* machines simultaneously.
*
* Cleared: state, cmd, sector, sector_msb, sector_lsb,
* data_idx, checksum (volatile protocol state).
* Preserved: flag (persistent "new card" metadata, only cleared
* after first read/write completes; carries across
* SELECT drops on real hardware) and data (sector
* buffer; harmless to retain since the next read
* overwrites it). */
if ((old_ctrl & SIO_CTRL_SELECT) && !(value & SIO_CTRL_SELECT)) {
/* Save card state back to slot before deselecting. The
* card retains its state across brief SELECT drops. */
if (active_device == DEV_MEMCARD && mc_state != MC_IDLE) {
mc_save_slot(mc_slot);
if (active_device == DEV_MEMCARD && mc_state != MC_IDLE && sio_txn_open) {
extern uint32_t g_debug_current_func_addr;
txn_close(SIO_TXN_END_ABORT_OTHER, mc_state, g_debug_current_func_addr);
}
mc_state = MC_IDLE;
for (int i = 0; i < 2; i++) {
mc_slots[i].state = MC_IDLE;
mc_slots[i].cmd = 0;
mc_slots[i].sector = 0;
mc_slots[i].sector_msb = 0;
mc_slots[i].sector_lsb = 0;
mc_slots[i].data_idx = 0;
mc_slots[i].checksum = 0;
/* keep mc_slots[i].flag, mc_slots[i].data */
}
pad_state = PAD_IDLE;
active_device = DEV_NONE;
@@ -971,6 +1095,99 @@ void sio_get_freeze_diag(int *out_irq_pending, int *out_irq_countdown,
if (out_card_active) *out_card_active = sio_card_protocol_active();
}
/* ---- Bounded SIO IRQ burst drain (active card data phase only) ---------
* Approved as the FIRST step on the path away from "1 byte/VBlank". This
* is NOT the cycle-paced rewrite. It is a transient measure that, while
* a card transfer is in-flight, drains the access-paced countdown so the
* IRQ that would have stalled until the next pad poll instead fires now.
*
* Invariants:
* - Only invoked from sio_write SIO_TX_DATA, after the IRQ-arm decision.
* - Caller guarantees active_device==DEV_MEMCARD and !in_exception.
* - Hard cap on iterations (default 128).
* - Break early if (a) no IRQ pending and countdown idle, OR
* (b) mc_state == MC_IDLE (transaction finished/aborted).
* - Each iteration calls sio_tick() ONCE. sio_tick already handles "fire
* when countdown==0" and updates i_stat / sio_stat / IRQ ring atomically.
* - sio_tick does not enter the BIOS exception. The BIOS exception fires
* later in the dispatch loop when (i_stat & i_mask & !in_exception).
*
* Stats (always-on, exposed via sio_burst_stats TCP cmd) so we can see if
* the bound is being hit, what the typical iter count is, and which break
* reason dominates. */
typedef struct {
uint64_t calls; /* total burst invocations */
uint64_t iters_total; /* total sio_tick iterations across all calls */
uint32_t iter_max_seen; /* max iters in a single call */
uint64_t break_idle; /* broke because pending=0 && countdown=0 */
uint64_t break_mode_clear; /* broke because mc_state==MC_IDLE */
uint64_t break_capped; /* broke at max_iters cap */
uint32_t fires_in_burst; /* IRQ fires that occurred during a burst */
uint32_t last_iters; /* iterations on most recent call */
uint8_t last_break_reason;/* 1=idle, 2=mode_clear, 3=capped, 0=skip */
} SioBurstStats;
static SioBurstStats s_burst_stats;
static uint32_t s_irq_seq_at_burst_start = 0;
extern uint8_t psx_read_byte(uint32_t addr);
extern int psx_get_in_exception(void);
static int sio_card_burst_drain(int max_iters) {
if (max_iters <= 0) max_iters = 128;
if (max_iters > 1024) max_iters = 1024;
s_burst_stats.calls++;
uint32_t fires_before = sio_irq_seq;
int iters = 0;
uint8_t reason = 1; /* default: idle break */
for (; iters < max_iters; iters++) {
/* Idle check (do BEFORE the tick — if there's nothing pending and
* countdown is 0, ticking is a no-op anyway). */
if (!sio_irq_pending && sio_irq_countdown == 0) {
reason = 1;
break;
}
/* Card protocol returned to IDLE — transaction finished or aborted.
* mc_state is the authoritative "transfer in flight" signal; the
* BIOS-RAM word [0x75C0] is only set during the data-byte phase
* (after the address handshake), so checking it here would have
* blocked bursting through the SELECT/CMD/ADDR setup bytes that
* precede the data phase. */
if (mc_state == MC_IDLE) {
reason = 2;
break;
}
sio_tick();
}
if (iters == max_iters) reason = 3;
s_burst_stats.iters_total += (uint64_t)iters;
if ((uint32_t)iters > s_burst_stats.iter_max_seen) s_burst_stats.iter_max_seen = (uint32_t)iters;
if (reason == 1) s_burst_stats.break_idle++;
else if (reason == 2) s_burst_stats.break_mode_clear++;
else if (reason == 3) s_burst_stats.break_capped++;
s_burst_stats.last_iters = (uint32_t)iters;
s_burst_stats.last_break_reason = reason;
s_burst_stats.fires_in_burst += (uint32_t)(sio_irq_seq - fires_before);
return iters;
}
void sio_get_burst_stats(uint64_t out[10]) {
out[0] = s_burst_stats.calls;
out[1] = s_burst_stats.iters_total;
out[2] = (uint64_t)s_burst_stats.iter_max_seen;
out[3] = s_burst_stats.break_idle;
out[4] = s_burst_stats.break_mode_clear;
out[5] = s_burst_stats.break_capped;
out[6] = (uint64_t)s_burst_stats.fires_in_burst;
out[7] = (uint64_t)s_burst_stats.last_iters;
out[8] = (uint64_t)s_burst_stats.last_break_reason;
out[9] = 0;
}
void sio_tick(void) {
if (sio_irq_pending && sio_irq_countdown > 0) {
sio_irq_countdown--;
+37 -3
View File
@@ -90,11 +90,34 @@ def send_cmd(sock, cmd_dict):
line = json.dumps(cmd_dict) + "\n"
sock.sendall(line.encode())
buf = b""
while b"\n" not in buf:
# Server may emit one large JSON object across many TCP chunks, with raw
# newlines inside arrays. Track brace/bracket balance (string-aware) and
# parse once balance returns to zero.
depth_curly = 0
depth_sq = 0
in_str = False
esc = False
started = False
while True:
chunk = sock.recv(65536)
if not chunk:
break
buf += chunk
for b in chunk:
buf += bytes([b])
c = chr(b)
if in_str:
if esc: esc = False
elif c == "\\": esc = True
elif c == '"': in_str = False
continue
if c == '"': in_str = True
elif c == "{": depth_curly += 1; started = True
elif c == "}": depth_curly -= 1
elif c == "[": depth_sq += 1
elif c == "]": depth_sq -= 1
if started and depth_curly == 0 and depth_sq == 0:
# Message complete.
return json.loads(buf.decode().strip())
return json.loads(buf.decode().strip())
@@ -115,12 +138,23 @@ def pretty_regs(resp):
if not resp.get("ok"):
return json.dumps(resp, indent=2)
lines = [f" PC: {resp.get('pc','?')} HI: {resp.get('hi','?')} LO: {resp.get('lo','?')}"]
cop0 = []
for k in ("cop0_sr", "cop0_cause", "cop0_epc", "i_stat", "i_mask"):
if k in resp:
cop0.append(f"{k}={resp[k]}")
if cop0:
lines.append(" " + " ".join(cop0))
# Server returns either a `gpr` array (positional) or a `regs` dict (named).
gpr = resp.get("gpr")
regs = resp.get("regs", {})
for i in range(0, 32, 4):
parts = []
for j in range(4):
name = REG_NAMES[i + j]
val = regs.get(name, "?")
if isinstance(gpr, list) and i + j < len(gpr):
val = gpr[i + j]
else:
val = regs.get(name, "?")
parts.append(f"{name:>4s}: {val}")
lines.append(" " + " ".join(parts))
return "\n".join(lines)
+34
View File
@@ -0,0 +1,34 @@
import json, socket
def send(cmd, **kw):
req = {"id":1,"cmd":cmd, **kw}
s = socket.socket(); s.settimeout(15.0); s.connect(("127.0.0.1", 4370))
s.sendall((json.dumps(req)+"\n").encode())
buf=b""; dc=ds=0; ins=esc=st=False
while True:
c = s.recv(65536)
if not c: break
for b in c:
buf += bytes([b]); ch = chr(b)
if ins:
if esc: esc=False
elif ch == "\\": esc=True
elif ch == '"': ins=False
continue
if ch == '"': ins=True
elif ch == "{": dc+=1; st=True
elif ch == "}": dc-=1
elif ch == "[": ds+=1
elif ch == "]": ds-=1
if st and dc==0 and ds==0:
s.close(); return json.loads(buf.decode().strip())
s.close()
return json.loads(buf.decode().strip())
d = send("dirty_ram_stats")
print(f"blocks_run={d['blocks_run']} insns_run={d['insns_run']} aborts={d['aborts']}")
print("per_pc filtered:")
for e in d.get("per_pc", []):
pc = int(e["pc"], 16)
if pc in (0xCF0, 0x641C, 0x6594, 0x6444, 0x6458, 0x6514, 0x650C, 0x48, 0xA0, 0xB0, 0xC0, 0x80):
print(f" pc={e['pc']} hits={e['hits']} insns={e['insns']}")
+80
View File
@@ -0,0 +1,80 @@
#!/usr/bin/env python3
"""Send a raw JSON command and dump the raw response bytes.
Usage: python tools/raw_tcp.py <port> <cmd> [k=v ...]
Example: python tools/raw_tcp.py 4370 card_txn_dump
python tools/raw_tcp.py 4370 read_ram addr=0x80007568 len=16
"""
import socket
import sys
import json
if len(sys.argv) < 3:
print(__doc__)
sys.exit(1)
port = int(sys.argv[1])
cmd = sys.argv[2]
req = {"id": 1, "cmd": cmd}
for kv in sys.argv[3:]:
k, v = kv.split("=", 1)
# Keep hex strings as strings (server's read_ram etc. expect "addr":"0x..").
# Decimal-looking values become ints.
if v.startswith("0x") or v.startswith("0X"):
pass # leave as string
else:
try:
v = int(v)
except ValueError:
pass
req[k] = v
s = socket.socket()
s.settimeout(5.0)
s.connect(("127.0.0.1", port))
s.sendall((json.dumps(req) + "\n").encode())
data = b""
depth_c = 0
depth_s = 0
in_str = False
esc = False
started = False
done = False
try:
while not done:
chunk = s.recv(65536)
if not chunk:
break
for b in chunk:
data += bytes([b])
ch = chr(b)
if in_str:
if esc: esc = False
elif ch == "\\": esc = True
elif ch == '"': in_str = False
continue
if ch == '"': in_str = True
elif ch == "{": depth_c += 1; started = True
elif ch == "}": depth_c -= 1
elif ch == "[": depth_s += 1
elif ch == "]": depth_s -= 1
if started and depth_c == 0 and depth_s == 0:
done = True
break
except socket.timeout:
pass
s.close()
print(f"=== raw bytes (len={len(data)}) ===")
sys.stdout.write(data.decode("utf-8", errors="replace"))
print()
print("=== json parse attempt ===")
try:
obj = json.loads(data.decode().strip())
print("OK keys:", list(obj.keys()) if isinstance(obj, dict) else type(obj))
except Exception as e:
print(f"FAIL: {e}")
txt = data.decode("utf-8", errors="replace")
if hasattr(e, "pos"):
lo, hi = max(0, e.pos - 30), min(len(txt), e.pos + 30)
print(f"context [{lo}..{hi}]: {txt[lo:hi]!r}")
print(f"byte at pos {e.pos}: {txt[e.pos]!r}")
+11
View File
@@ -0,0 +1,11 @@
import socket, json, sys
s = socket.socket(); s.connect(("127.0.0.1", 4370))
addr_str = sys.argv[1] if len(sys.argv) > 1 else "0x80007568"
req = {"id": 1, "cmd": "read_ram", "addr": addr_str, "len": 16}
line = json.dumps(req) + "\n"
print("SEND:", line.strip())
s.sendall(line.encode())
import time; time.sleep(0.3)
buf = s.recv(8192)
print("RECV:", buf.decode())
+144
View File
@@ -0,0 +1,144 @@
#!/usr/bin/env python3
"""IRQ-chain step audit: per-step probe of the SIO IRQ delivery chain.
Each function probes one step and prints PASS/FAIL with evidence. No
state mutation — pure observation of always-on rings.
"""
import socket, json, sys, time
PORT = 4370
def send(cmd, **kw):
req = {"id": 1, "cmd": cmd, **kw}
s = socket.socket(); s.settimeout(8.0); s.connect(("127.0.0.1", PORT))
s.sendall((json.dumps(req) + "\n").encode())
buf = b""
depth_c = depth_s = 0
in_str = esc = False
started = False
while True:
chunk = s.recv(65536)
if not chunk:
break
for b in chunk:
buf += bytes([b])
ch = chr(b)
if in_str:
if esc: esc = False
elif ch == "\\": esc = True
elif ch == '"': in_str = False
continue
if ch == '"': in_str = True
elif ch == "{": depth_c += 1; started = True
elif ch == "}": depth_c -= 1
elif ch == "[": depth_s += 1
elif ch == "]": depth_s -= 1
if started and depth_c == 0 and depth_s == 0:
s.close()
return json.loads(buf.decode().strip())
s.close()
return json.loads(buf.decode().strip())
def fz():
return send("freeze_check")
def header(label):
print()
print("=" * 70)
print(label)
print("=" * 70)
if __name__ == "__main__":
fz1 = fz()
print(f"frame={fz1.get('total_checks','?')} mc_max_state={fz1.get('mc_max_state')}"
f" sio_irq_total={fz1.get('sio_irq_total')} tx_writes={fz1.get('tx_writes')}"
f" mc_aborts={fz1.get('mc_aborts')} mc_read_done={fz1.get('mc_read_done')}"
f" i_stat={fz1.get('i_stat')} i_mask={fz1.get('i_mask')}")
cmd = sys.argv[1] if len(sys.argv) > 1 else "all"
if cmd in ("step12", "all"):
header("Step 1-2: TX -> sio_process_byte -> DEV_MEMCARD")
# sio_trace dumps recent SIO bytes. Filter for card cmd bytes.
r = send("sio_trace", count=200)
ents = r.get("entries", [])
cards = [e for e in ents if e.get("dev_pre") == "card" or e.get("dev_post") == "card"
or e.get("mc_state_pre", 0) > 0 or e.get("mc_state_post", 0) > 0]
cmds_seen = [e for e in cards if e.get("tx") in ("0x52", "0x57", "0x53") or e.get("tx_byte") in (0x52, 0x57, 0x53)]
print(f"sio_trace returned {len(ents)} entries, {len(cards)} card-related, {len(cmds_seen)} CMD bytes")
if cards:
print("first 3 card-related entries:")
for e in cards[:3]:
print(" ", json.dumps(e))
# sio_state for current device
st = send("sio_state")
print(f"sio_state: mc_max_state={st.get('mc_max_state')} tx_writes={st.get('tx_writes')}"
f" mc_probes={st.get('mc_probes')} mc_cmds={st.get('mc_cmds')} mc_acks={st.get('mc_acks')}")
if cmd in ("step3456", "all"):
header("Step 3-4-5-6: arm + countdown + tick decrement to 0")
# Use sio_irq_dump src=1 (CARD) over wide window
r = send("sio_irq_dump", count=200000, src=1)
cards = r.get("entries", [])
print(f"sio_irq ring: total={r.get('total')} shown={r.get('shown')} card_emitted={r.get('emitted')}")
if cards:
print("first card-IRQ entry:", json.dumps(cards[0]))
# Compare: total card IRQ-arm vs IRQ-fire — would need extra probe.
# Aggregate: any card IRQ ever fired?
if r.get("emitted", 0) == 0:
print("FAIL: zero card-source IRQ fires in entire ring")
# freeze_check exposes current sio_irq_pending and countdown
print(f"freeze_check sio_irq_pending={fz1.get('sio_irq_pending')}"
f" sio_irq_countdown={fz1.get('sio_irq_countdown')}")
if cmd in ("step7", "all"):
header("Step 7: i_stat bit 7 (SIO0) ever raised by sio_tick path")
# i_stat history exists? Check via wtrace target on i_stat MMIO addr.
# Look at sio_irq dump again — when an IRQ fires, i_stat_after has bit 7.
r = send("sio_irq_dump", count=200000, src=1)
cards = r.get("entries", [])
if cards:
with_bit7 = [e for e in cards if int(e.get("i_stat_after","0x0"),16) & 0x80]
print(f"card IRQ entries with i_stat_after bit7 set: {len(with_bit7)} / {len(cards)}")
else:
print("FAIL: no card IRQ entries to inspect")
if cmd in ("step89", "all"):
header("Step 8-9: BIOS exception entry and chain dispatch")
f = fz1
print(f"exception_entries={f.get('exception_entries')}"
f" exception_reentry_blocks={f.get('exception_reentry_blocks')}"
f" dirty_ram_aborts={f.get('dirty_ram_aborts')}"
f" sio_byte_seq={f.get('sio_byte_seq')}"
f" sio_irq_total={f.get('sio_irq_total')}")
# i_mask history (already proven bit 7 toggles)
r = send("imask_trace", count=4)
print(f"imask_trace: bit7_sets={r.get('bit7_sets')} bit7_clears={r.get('bit7_clears')} total={r.get('total')}")
if cmd in ("step1012", "all"):
header("Step 10-11-12: dirty-RAM 0x641C / 0xCF0 + [0x72F0] increment")
r = send("dirty_ram_stats")
per = r.get("per_pc", [])
for entry in per:
pc = entry.get("pc")
if pc in ("0x000000CF0", "0x00000CF0", "0x0000641C", "0x00006594"):
print(f" {pc}: hits={entry.get('hits')} insns={entry.get('insns')}")
print(f"blocks_run={r.get('blocks_run')} insns_run={r.get('insns_run')} aborts={r.get('aborts')}")
# current [0x72F0]
rr = send("read_ram", addr="0x800072F0", len=4)
print(f"[0x72F0] now: hex={rr.get('hex')}")
# wtrace history for [0x72F0]
wt = send("wtrace_dump")
# check what slots exist
print(f"wtrace_dump keys: {list(wt.keys())[:6]}")
# filter for any addr in [0x72F0..0x72F3]
all_entries = wt.get("entries", []) if isinstance(wt.get("entries"), list) else []
if all_entries:
target = [e for e in all_entries if 0x72F0 <= int(e.get("addr","0"),16) & 0xFFFF <= 0x72F3]
print(f"wtrace entries targeting [0x72F0..0x72F3]: {len(target)}")
if target:
print(f"first 5: {target[:5]}")
+61
View File
@@ -0,0 +1,61 @@
#!/usr/bin/env python3
"""Deeper SIO trace mining for card-related entries."""
import socket, json, sys
def send(cmd, **kw):
req = {"id": 1, "cmd": cmd, **kw}
s = socket.socket(); s.settimeout(15.0); s.connect(("127.0.0.1", 4370))
s.sendall((json.dumps(req) + "\n").encode())
buf = b""
depth_c = depth_s = 0
in_str = esc = started = False
while True:
chunk = s.recv(65536)
if not chunk: break
for b in chunk:
buf += bytes([b]); ch = chr(b)
if in_str:
if esc: esc = False
elif ch == "\\": esc = True
elif ch == '"': in_str = False
continue
if ch == '"': in_str = True
elif ch == "{": depth_c += 1; started = True
elif ch == "}": depth_c -= 1
elif ch == "[": depth_s += 1
elif ch == "]": depth_s -= 1
if started and depth_c == 0 and depth_s == 0:
s.close(); return json.loads(buf.decode().strip())
s.close()
return json.loads(buf.decode().strip())
count = int(sys.argv[1]) if len(sys.argv) > 1 else 8000
r = send("sio_trace", count=count)
ents = r.get("entries", [])
print(f"sio_trace total_seq={r.get('total')} returned={len(ents)}")
# Card related: mc_pre or mc_post > 0 OR dev_pre/dev_post == DEV_MEMCARD (=2)
DEV_MEMCARD = 2
DEV_PAD = 1
cards = [e for e in ents if e.get("mc_pre", 0) > 0 or e.get("mc_post", 0) > 0
or e.get("dev_pre") == DEV_MEMCARD or e.get("dev_post") == DEV_MEMCARD]
print(f"card-related: {len(cards)}")
# Of card-related, how many had irq_cd > 0 (IRQ countdown armed)?
armed = [e for e in cards if e.get("irq_cd", 0) > 0]
print(f"card-related with irq_cd>0 at trace time: {len(armed)}")
# Show first few card-related
if cards:
print("\nfirst 5 card-related:")
for e in cards[:5]:
print(f" seq={e['seq']} tx={e['tx']} rx={e['rx']} mc_pre={e['mc_pre']} mc_post={e['mc_post']}"
f" dev_pre={e['dev_pre']} dev_post={e['dev_post']} ctrl={e['ctrl']} irq_cd={e['irq_cd']}"
f" abort={e['abort']} in_exc={e['in_exc']}")
# distribution of irq_cd values for card bytes
if cards:
from collections import Counter
cdist = Counter(e['irq_cd'] for e in cards)
print(f"\nirq_cd distribution among card bytes: {dict(cdist)}")
+18
View File
@@ -0,0 +1,18 @@
"""Audit SIO byte trace: show per-byte mc_state, ctrl, slot states."""
import sys, json, re
txt = sys.stdin.read()
m = re.search(r'\{.*\}', txt, re.S)
if not m:
print('parse fail'); sys.exit(1)
j = json.loads(m.group(0))
ents = j.get('entries', [])
print('seq tx rx mc(pre>post) dev(pre>post) ctrl s0 s1 abrt ctr func')
print('-' * 95)
for e in ents:
print(f"{e['seq']:>6} {e['tx']:>4} {e['rx']:>4} "
f"{e['mc_pre']:>2} > {e['mc_post']:<2} "
f"{e['dev_pre']:>2} > {e['dev_post']:<2} "
f"{e['ctrl']:>6} {e['slot0']:>3} {e['slot1']:>3} {e['abort']:>5} {e['ctr']:>4} "
f"{e['func']}")
+23
View File
@@ -0,0 +1,23 @@
"""Filter SIO trace to entries with seq in [smin, smax]. Args: smin smax."""
import sys, json, re
if len(sys.argv) != 3:
print('usage: trace_range.py SMIN SMAX', file=sys.stderr); sys.exit(1)
smin, smax = int(sys.argv[1]), int(sys.argv[2])
txt = sys.stdin.read()
m = re.search(r'\{.*\}', txt, re.S)
if not m:
print('parse fail'); sys.exit(1)
j = json.loads(m.group(0))
ents = j.get('entries', [])
hits = [e for e in ents if smin <= e['seq'] <= smax]
print(f'(found {len(hits)} of {len(ents)} entries in [{smin},{smax}], total seq up to {j.get("total")})')
print('seq tx rx mc(pre>post) dev(pre>post) ctrl s0 s1 abrt ctr func')
for e in hits:
print(f"{e['seq']:>6} {e['tx']:>4} {e['rx']:>4} "
f"{e['mc_pre']:>2}>{e['mc_post']:<2} "
f"{e['dev_pre']:>2}>{e['dev_post']:<2} "
f"{e['ctrl']:>6} {e['slot0']:>2} {e['slot1']:>2} "
f"{e['abort']:>4} {e['ctr']:>4} {e['func']}")
+21
View File
@@ -0,0 +1,21 @@
"""Dump a single card txn's full TX/RX bytes given txn_seq + nearby SIO trace."""
import sys, json, re
txt = sys.stdin.read()
m = re.search(r'\{.*\}', txt, re.S)
if not m:
print('parse fail'); sys.exit(1)
j = json.loads(m.group(0))
ents = j.get('entries', [])
# Print first txn that has bytes >= 15
for e in ents:
if e.get('bytes', 0) >= 10:
print(f"=== txn {e['txn_seq']}: slot={e['slot']} cmd={e['cmd']} "
f"sect={e['sector']} bytes={e['bytes']} ts={e['terminal_state']} "
f"reason={e['end_reason']} start_byte_seq={e['start_byte_seq']} "
f"end_byte_seq={e['end_byte_seq']} ===")
print(f" start_func={e['start_func']} end_func={e['end_func']}")
for i, (tx, rx) in enumerate(zip(e['tx'], e['rx'])):
print(f" byte[{i:>2}] tx={tx} rx={rx}")
print()
+14
View File
@@ -0,0 +1,14 @@
"""Distribution of (bytes, terminal_state) across all txns."""
import sys, json, re
from collections import Counter
txt = sys.stdin.read()
m = re.search(r'\{.*\}', txt, re.S)
if not m:
print('parse fail'); sys.exit(1)
j = json.loads(m.group(0))
ents = j.get('entries', [])
c = Counter((e['bytes'], e['terminal_state']) for e in ents)
print(f"total_closed={j.get('total_closed')}, returned={len(ents)}")
for (b, t), n in sorted(c.items()):
print(f" bytes={b:>3} ts={t:>2}: {n} txns")
+19
View File
@@ -0,0 +1,19 @@
"""Summarize card txns: per-txn line + max stats."""
import sys, json, re
txt = sys.stdin.read()
m = re.search(r'\{.*\}', txt, re.S)
if not m:
print('parse fail'); sys.exit(1)
j = json.loads(m.group(0))
ents = j.get('entries', [])
for e in ents:
print(f"txn {e.get('txn_seq')}: slot={e.get('slot')} cmd={e.get('cmd')} "
f"sect={e.get('sector')} bytes={e.get('bytes')} "
f"ts={e.get('terminal_state')} reason={e.get('end_reason')}")
if ents:
mb = max(e.get('bytes',0) for e in ents)
mt = max(e.get('terminal_state',0) for e in ents)
print(f"\n[max bytes/txn={mb}, max terminal_state={mt}, total_closed={j.get('total_closed')}]")
+66
View File
@@ -0,0 +1,66 @@
#!/usr/bin/env python3
"""Pull all 128 KiB of cards[slot].data via card_buffer_dump and sha256-compare to disk.
Usage: python tools/verify_card_buffer.py
"""
import socket
import json
import hashlib
import sys
PORT = 4370
HOST = "127.0.0.1"
CHUNK = 0x4000 # 16 KiB per request
SIZE = 0x20000 # 128 KiB
def send_cmd(req):
s = socket.socket(); s.settimeout(5.0); s.connect((HOST, PORT))
s.sendall((json.dumps(req) + "\n").encode())
buf = b""
while True:
chunk = s.recv(65536)
if not chunk: break
buf += chunk
if buf.rstrip().endswith(b"}"):
try:
obj = json.loads(buf.decode().strip())
s.close()
return obj
except json.JSONDecodeError:
pass
s.close()
return json.loads(buf.decode().strip())
def fetch_card(slot):
h = hashlib.sha256()
raw = bytearray()
off = 0
while off < SIZE:
n = min(CHUNK, SIZE - off)
resp = send_cmd({"id": 1, "cmd": "card_buffer_dump",
"slot": slot, "offset": off, "len": n})
if not resp.get("ok"):
print(f"slot {slot} offset {off}: ERROR {resp}")
return None
chunk = bytes.fromhex(resp["hex"])
if len(chunk) != n:
print(f"slot {slot} offset {off}: short read {len(chunk)} != {n}")
raw.extend(chunk); h.update(chunk); off += len(chunk)
if len(chunk) == 0:
break
return bytes(raw), h.hexdigest()
def disk_sha(path):
with open(path, "rb") as f:
return hashlib.sha256(f.read()).hexdigest()
if __name__ == "__main__":
paths = ["card1.mcd", "card2.mcd"]
for slot, path in enumerate(paths):
runtime_data, runtime_sha = fetch_card(slot) or (b"", None)
disk = disk_sha(path)
match = "MATCH" if runtime_sha == disk else "DIFFER"
print(f"slot {slot} ({path}):")
print(f" disk sha256: {disk}")
print(f" runtime sha256: {runtime_sha}")
print(f" -> {match}")
+56
View File
@@ -0,0 +1,56 @@
import json, socket, sys
def send(cmd, **kw):
req = {"id":1,"cmd":cmd, **kw}
s = socket.socket(); s.settimeout(20.0); s.connect(("127.0.0.1", 4370))
s.sendall((json.dumps(req)+"\n").encode())
buf=b""; dc=ds=0; ins=esc=st=False
while True:
c = s.recv(65536)
if not c: break
for b in c:
buf += bytes([b]); ch = chr(b)
if ins:
if esc: esc=False
elif ch == "\\": esc=True
elif ch == '"': ins=False
continue
if ch == '"': ins=True
elif ch == "{": dc+=1; st=True
elif ch == "}": dc-=1
elif ch == "[": ds+=1
elif ch == "]": ds-=1
if st and dc==0 and ds==0:
s.close(); return json.loads(buf.decode().strip())
s.close()
return json.loads(buf.decode().strip())
d = send("wtrace_dump")
print("keys:", list(d.keys())[:10])
ents = d.get("entries", [])
print(f"total wtrace entries: {len(ents)}")
def in_range(e, lo, hi):
a = int(e.get("addr","0"), 16) & 0xFFFFFFFF
p = a & 0xFFFF
return lo <= p <= hi
hits_72F0 = [e for e in ents if in_range(e, 0x72F0, 0x72F3)]
print(f"writes to [0x72F0..0x72F3]: {len(hits_72F0)}")
for h in hits_72F0[:8]:
print(" ", h)
hits_755A = [e for e in ents if in_range(e, 0x755A, 0x755C)]
print(f"writes to [0x755A..0x755C]: {len(hits_755A)}")
for h in hits_755A[:8]:
print(" ", h)
hits_75C0 = [e for e in ents if in_range(e, 0x75C0, 0x75C3)]
print(f"writes to [0x75C0..0x75C3]: {len(hits_75C0)}")
for h in hits_75C0[:8]:
print(" ", h)
hits_7568 = [e for e in ents if in_range(e, 0x7568, 0x7570)]
print(f"writes to [0x7568..0x7570]: {len(hits_7568)}")
for h in hits_7568[:8]:
print(" ", h)