diff --git a/harness/mame/BRINGUP_LOG.md b/harness/mame/BRINGUP_LOG.md index 4f29fda..b6f8ab3 100644 --- a/harness/mame/BRINGUP_LOG.md +++ b/harness/mame/BRINGUP_LOG.md @@ -613,6 +613,16 @@ Captured: `0x0F48`, `0x1008`). So the firmware loops: run a test -> fail -> restart with interrupts off -> run again. +> **CORRECTION (2026-10-16, later).** Point 3 is not where the stub level-1 run +> ends. Breakpoints on `3F208060`/`3F208650` fire **0** times in 20 000 frames, +> and the level-1 runner never returns to the boot loop's `3F204440 jane +> L3F208060`. The DUART failures are reported, the finite `L3F208660` blink runs, +> `TYPE 'GO' TO CONTINUE` is printed (no input is read), and the runner +> **continues** (`CONTINUING THE TESTS`), then wedges in a **DUART1 counter-ready +> interrupt storm** from frame ~2839. See `LEVEL1_CONTINUE_REPORT.md`. The +> "restart" reading above came from a 3000-frame window that ended during the +> LED blink. + **The causal chain is now complete and consistent:** > video memory not modelled -> the level-1 video RAM test fails -> error 22 is reported -> diff --git a/harness/mame/DUART_REPORT.md b/harness/mame/DUART_REPORT.md index 61dbfac..c3f7650 100644 --- a/harness/mame/DUART_REPORT.md +++ b/harness/mame/DUART_REPORT.md @@ -1,5 +1,13 @@ # DUART — wiring MAME's SCN2681 at the host-port window +> **CORRECTION (2026-10-16, later).** The line 356 note — "an earlier note in +> this project records that INTENB never enables, because the level-0 restart +> enters at `3F208060` with `DINT`" — is wrong on both halves: `3F208060` is +> never entered on the stub level-1 path (measured), and the run does enable +> interrupts. The level-1 DUART failures are reported and the runner continues, +> then dies in a **DUART1 counter-ready interrupt storm** (ISR reg 5 = `0x08`) +> from frame ~2839; see `harness/mame/LEVEL1_CONTINUE_REPORT.md`. + Bounded task, 2026-10-16. Goal: make the firmware's level-1 **HOST PORT** test pass (DUART1 channel A) by modelling the DUART with MAME's `SCN2681`, so that `'LEVEL1/2 ERROR -> HOST PORT - 15 '` stops appearing in the console capture. diff --git a/harness/mame/GATE_CLEANUP_REPORT.md b/harness/mame/GATE_CLEANUP_REPORT.md index b3f270d..07ca148 100644 --- a/harness/mame/GATE_CLEANUP_REPORT.md +++ b/harness/mame/GATE_CLEANUP_REPORT.md @@ -1,5 +1,15 @@ # `VT1200_*` env-gate cleanup — outcome +> **CORRECTION (2026-10-16, later).** This report's `no-env` section says the run +> goes "up to the HOST PORT test (then the LED loop)" and calls +> `3F2088B0/3F208B20/3F208A80/3F208950` "the LED loop". Measured over 20 000 +> frames (`harness/mame/LEVEL1_CONTINUE_REPORT.md`), those PCs are inside the +> **finite** one-shot blink `L3F208660`; `3F208060`/`3F208650` are never executed +> and the run does not end there. The DUART failures are followed by +> `CONTINUING THE TESTS` and then a **DUART1 counter-ready interrupt storm** from +> frame ~2839. The baseline values below are unchanged; only the "LED loop" +> reading is corrected. + Executes `docs/superpowers/plans/2026-10-16-env-gate-cleanup.md`. The working configuration is now the **default**: a bare `vt1200 vt1200` (no env at all) behaves exactly like the old incantation diff --git a/harness/mame/LEVEL1_CONTINUE_REPORT.md b/harness/mame/LEVEL1_CONTINUE_REPORT.md new file mode 100644 index 0000000..29320e5 --- /dev/null +++ b/harness/mame/LEVEL1_CONTINUE_REPORT.md @@ -0,0 +1,151 @@ +# The stub run does NOT park at HOST PORT — it continues, then dies in a DUART1 counter storm + +Date: 2026-10-16. Configuration: `./run.sh stub` (`VT1200_IO_PATH_STUB=1`), no other +env. ROM `vt1200_v22.bin` md5 `b46a3e442ccb86134d2356bd70d22fd2` (unmodified). + +This report corrects a claim that stood as fact in +`reference/level1-bypass-analysis.md` Q4 and shaped the wording of +`harness/mame/README.md`: **"a level-1 failure is fatal: the runner returns +nonzero → `3F204440 jane L3F208060` → an infinite board-LED loop at +`3F208650 jruc L3F208060`."** Measured, that is wrong for the DUART failures. (The file +`reference/level1-bypass-analysis.md` is outside this task's owned paths, so its +Q4 text is **not** edited here; this report is the correction of record and the +owner should annotate it in place.) + +All timings are **screen frames** (the firmware's own refresh), sampled once per +emulated frame. Instrumentation: `harness/mame/console_frames.lua`, +`harness/mame/wall_hist.lua`, and breakpoints on the sites named below; frames +and VRAM/RAM dumped via the driver's `VT1200_DUMP_*` knobs. Console output is the +firmware's own printer (`0x3FDE00C0`), captured to MAME `debug.log` with +`-debuglog`; the on-screen text is from the frame dumps. + +## Timeline (across time, not one snapshot) + +| frame | what happens | +|---|---| +| 0–1 | level 0 passes (stub); level-1 runner entered (`3FDF72D0`, called from `3F204400`); `LEVEL1/2 TESTING **` printed | +| 470–481 | HOST PORT test runs; it enables DUART1 interrupts (IMR = `0x07`→`0x01`→`0x07`, channel A) | +| 484 | HOST PORT fails: dispatcher `3FDF0630` code `0x400` → handler `3FDE9D70` prints `LEVEL1/2 ERROR -> HOST PORT - 15`, dumps `BAUD ERROR 00900040` / `FRAME & OVERRUN ERROR 00030000` / `INTERRUPT REG BIT 00000002`, prints `BLINKING SYSTEM BOARD LED`, calls `L3F208660` (one **finite** two-digit blink, error code `0x15`) | +| 484–1534 | the blink's `dsjs` delay loops dominate the CPU (hottest PC `3F2088B0`, etc.) | +| 1534 | handler prints `TYPE 'GO' TO CONTINUE`, then `jauc L3FDF1010` | +| 1534→1627 | `L3FDF1010` takes the **return** branch (status word `*A13(0xFFA0)` is zero) → the runner continues to the next test | +| 1613–1624 | PRINTER PORT test runs; enables DUART1 channel-B interrupts (IMR = `0x70`→`0x10`→`0x70`) | +| 1627 | PRINTER PORT fails: code `0x800` → `LEVEL1/2 ERROR -> PRINTER PORT - 16`, same three diagnostics, `BLINKING SYSTEM BOARD LED`, `L3F208660` blink (code `0x16`); **on-screen text reads `CONTINUING THE TESTS`** | +| 2759 | `TYPE 'GO' TO CONTINUE` again; returns via `L3FDF1010`; runner continues and draws the weave | +| **2839** | the next level-1 test enables **only** the DUART1 counter-ready interrupt: `L3FA78A10` writes IMR = `0x08` (last IMR write of the run) | +| 2839→end | **DUART1 counter-ready interrupt storm.** Frame samples are 100 % inside the DUART1 interrupt path (`00000F60` INT1 trampoline → `3FA92F40` → dispatcher `L3FA78D90`); the DUART1 IRQ re-asserts every ~229 CPU cycles | +| 3500, 6000, 12000 | frame dumps are **byte-identical**; RAM at 3500 vs 12000 differs in **one byte** (offset `0x4E105`). Still storming at frame 20000 | + +So the owner's two observations are exact: (1) after each DUART failure, after a +finite delay (~1050 frames ≈ 15 s of the blink), it **continues**; (2) then it +gets **stuck** — at frame 2839. + +## The "continues" is not a timeout and not the prompt + +The error handler `L3FDE9D70` ends + +``` +3fdea470: move a11, *a14+, 1 +3fdea490: calla L3F208660 ; ONE finite blink of the LED error code +3fdea4e0: movi 0x3fdcd2a8, a9 ; "TYPE 'GO' TO CONTINUE" +3fdea520: calla L3FDE00C0 ; print it +3fdea550: jauc L3FDF1010 +``` + +and the shared exit is + +``` +L3FDF1010: +3fdf1010: move *a13(0xffa0), a11, 1 +3fdf1030: jreq L3FDF10A0 ; status == 0 -> skip the blink, return +3fdf1040: move a14, -*sp, 1 +3fdf1070: calla L3FDF1270 ; status != 0 -> the INFINITE LED blink +L3FDF10A0: +3fdf10a0: ... rets 2 +``` + +Facts: + +* `3F208060` / `3F208650` are **never executed** in this run. Breakpoints on + both fired **0** times over 20 000 frames; so did `3F204440` (the boot loop's + `jane L3F208060`) and `3FDF1070` (the call into the truly infinite blink + `L3FDF1270`). +* The blink that *is* seen (`3F2088B0/3F208950/3F208A80/3F208B20`) is inside + **`L3F208660`**, a *finite* one-shot blink. The earlier "LED loop" conclusion + came from sampling a 900–3000 frame window that ended during the second blink + and reading its dominant PC as a wedge. +* `L3FDF1270` **is** an infinite loop (`3fdf1a80: jruc L3FDF13B0`), but it is + only entered when the status word is nonzero. In the observed DUART path the + status word is zero, so `L3FDF1010` returns and the runner proceeds. +* `TYPE 'GO' TO CONTINUE` is **printed, not waited on**: nothing reads DUART2, + the keyboard, or any input after it, and no input is faked. The runner + continues on its own. There is no keypress and no timeout. + +**What is actually true:** a level-1 failure is **reported and the runner +continues**; it is not by itself fatal. A level-1 failure becomes an infinite +blink only via `L3FDF1010 → L3FDF1270`, i.e. when the status word +`*A13(0xFFA0)` is nonzero, which did not happen for these two DUART failures. +The runner also **never returns** to the boot loop (`3F204440` never fires), so +`3F208060` plays no part in this path at all. + +## The wall, named + +In the steady state (frames 2839 → 20 000) the only DUART accesses are a +repeating pair, ~229 CPU cycles apart: + +| logged PC | instruction | access | value | +|---|---|---|---| +| `3FA78E30` | `3FA78E10 move *a11(0x50), a7, 0` | DUART1 **ISR**, reg 5, firmware bit address **`0x06400050`** | **`0x0008`** (bit 3 = counter/timer ready) | +| `3FA7B5E0` | `3FA7B5C0 move *a7(0xf0), a7, 0` | DUART1 reg **0xF**, firmware bit address **`0x064000F0`** (write-only; reads `0xFF`) | `0x00FF` | + +(The logged PC trails the memory instruction by one word — TMS34010 prefetch — +so the reading instruction is the one quoted.) + +* `L3FA78D90` (the DUART1 ISR dispatcher) computes `pending = ISR & IMR` into RAM + `0x270820`, tests bit 2, then 6, then 1, later **bit 3** at `3FA7B4D0`, clears + the software bit, and reads reg `0xF`. But the hardware ISR bit 3 is set again + before the read even retires, and `reti` re-enters immediately. +* Cause: the counter is in **timer mode** — `L3FA71CB0` writes `ACR = 0x60` + (reg 4) once — and **CTUR/CTLR (regs 6/7) are never written**, so the reload + value is `0`. MAME's `mc68681` re-arms with `std::max(CTR, 1)` = **1 tick** at + the 3.6864 MHz DUART clock (271 ns), so the counter-ready interrupt is + re-asserted far faster than the ~229-cycle ISR can clear it. The interrupt is + therefore permanently pending and the CPU never runs mainline code again. +* **What it waits for:** ISR bit 3 (`0x08`) to be clear, i.e. `ISR & IMR == 0`. + It never is. +* **What is missing:** a sane counter/timer period. With the reload left at `0`, + the model produces the fastest possible tick rather than a long one; the + firmware's counter interrupt becomes a storm. This lives in the MAME + `mc68681` model (`devices/machine/mc68681.cpp`), which is out of scope here + (MAME tree is not owned by this task) — reported, not changed. The local MAME + edits (`harness/mame/mame_edits/`) are unrelated (Rx overrun latch, TxRDY + timing); this is upstream `max(CTR,1)` behaviour. + +## Next wall + +**DUART1 counter-ready interrupt storm.** CPU is 100 % inside the DUART1 INT1 +ISR; it polls DUART1 ISR (reg 5, bit `0x06400050`) and always reads `0x08` +(counter ready); the counter runs in timer mode (`ACR = 0x60`) with an +unprogrammed reload (`CTUR/CTLR = 0`), so the interrupt re-arms every ~229 CPU +cycles and can never be cleared. Nothing else executes; the screen has been +frozen since frame 2839. + +Reproduce: + +```sh +M=/home/arti/code/k-space/mame0289/vt1200 +# transcript + milestones (writes debug.log) +VT1200_IO_PATH_STUB=1 CF_FRAMES=20000 $M vt1200 -rompath harness/mame/roms \ + -video none -sound none -nothrottle -debug -debugger none -debuglog \ + -autoboot_script harness/mame/console_frames.lua -autoboot_delay 0 +# final-state histogram, plus DUART access log +VT1200_IO_PATH_STUB=1 W_START=5000 W_END=12000 \ + VT1200_DUARTLOG=/tmp/duart.log $M vt1200 -rompath harness/mame/roms \ + -video none -sound none -nothrottle -debug -debugger none \ + -autoboot_script harness/mame/wall_hist.lua -autoboot_delay 0 +# frames at increasing times +VT1200_IO_PATH_STUB=1 VT1200_DUMP_FRAMES=500,1627,2800,3500,12000 \ + VT1200_DUMP_DIR=/tmp VT1200_DUMP_VRAM_FRAMES=500,2800,12000 \ + $M vt1200 -rompath harness/mame/roms -video none -sound none -nothrottle \ + -seconds_to_run 200 +``` diff --git a/harness/mame/README.md b/harness/mame/README.md index 0972fc4..5835793 100644 --- a/harness/mame/README.md +++ b/harness/mame/README.md @@ -111,10 +111,21 @@ is carefully, because it is easy to misread: * It is **off by default**. A bare run still fails level 0 exactly as before and says so. This is deliberate: the faithful configuration stays the default. -With the stub on the boot clears level 0 and reaches **level 1's `HOST PORT - 15`** -(and `PRINTER PORT - 16`), which is the faithful ceiling. It does **not** produce a -booted OS: level 1 still fails on the DUART fidelity ceiling, so -`VT1200_SKIP_LEVEL1=1` remains the only route to X11. +With the stub on the boot clears level 0 and reaches level 1, where the DUART +tests fail: `HOST PORT - 15`, then `PRINTER PORT - 16`. **It does not park at +`HOST PORT - 15`.** Each failure is reported, the board LED blinks once (finite), +the firmware prints `TYPE 'GO' TO CONTINUE` (which nothing answers and which does +not wait), and the runner **continues**. It then enables DUART1's counter-ready +interrupt and **wedges in a DUART1 interrupt storm** — that is the faithful +ceiling, not `HOST PORT - 15`. It does **not** produce a booted OS. See +`LEVEL1_CONTINUE_REPORT.md`. + +There is **no infinite board-LED loop** on this path. `3F208060`/`3F208650` are +never executed here, and the boot loop's `3F204440 jane L3F208060` is never +reached (the level-1 runner never returns). The blink that is seen is the finite +`L3F208660` called by the error handler. A level-1 failure is fatal only through +`L3FDF1010 → L3FDF1270`, the genuinely infinite blink, which is entered when the +status word `*A13(0xFFA0)` is nonzero; the DUART failures leave it zero. ### How far the OS gets @@ -187,10 +198,14 @@ PC=3FDCE400 samples=53 (75 distinct PCs) ``` That is a genuine move, not a false pass: with the count-only level-0 test -satisfied, the run leaves the level-0 wait and executes level-0/level-1 work, then -parks at **level 1's `HOST PORT - 15`** (verified from the console transcript: -`LEVEL1/2 TESTING **`, then `LEVEL1/2 ERROR -> HOST PORT - 15`). It is recorded as a -*different* baseline because it is opt-in; the default must stay `samples=198`. +satisfied, the run leaves the level-0 wait and executes level-0/level-1 work. It +is **not** parked at `HOST PORT - 15`: the console transcript continues +(`LEVEL1/2 TESTING **`, `LEVEL1/2 ERROR -> HOST PORT - 15`, +`LEVEL1/2 ERROR -> PRINTER PORT - 16`, `TYPE 'GO' TO CONTINUE`), and the run ends +in a DUART1 counter-ready **interrupt storm** (from frame ~2839; PC in the DUART1 +INT1 ISR, polling ISR reg 5 = `0x08`). See `LEVEL1_CONTINUE_REPORT.md`. It is +recorded as a *different* baseline because it is opt-in; the default must stay +`samples=198`. It is a change detector, not a specification. If it moves without you meaning it to, find out why. diff --git a/harness/mame/console_frames.lua b/harness/mame/console_frames.lua new file mode 100644 index 0000000..6cbf00a --- /dev/null +++ b/harness/mame/console_frames.lua @@ -0,0 +1,48 @@ +-- console_frames.lua -- the firmware console transcript WITH frame numbers. +-- +-- Break on the printer entry 0x3FDE00C0 (a9 = message bit pointer) and on the +-- error-report dispatcher and the level-1 runner, so the transcript is +-- interleaved with the control-flow milestones. Output goes to MAME's +-- debug.log (run with -debuglog); stdout only carries frame summaries. +-- +-- CF_FRAMES= budget (default 20000) +-- +-- vt1200 ... -debug -debugger none -debuglog \ +-- -autoboot_script harness/mame/console_frames.lua -autoboot_delay 0 + +local machine = manager.machine +local dbg = machine.debugger +local cpu = machine.devices[':maincpu'] + +if not dbg then + print("ERROR: debugger not enabled; pass -debug") + machine:exit() + return +end + +FRAME = 0 + +dbg:command('bpset 3fde00c0,,{ printf "P fr=%d a9=%08X\\n", FRAME, a9 ; g }') +dbg:command('bpset 3fdf72d0,,{ printf "RUNNER-ENTRY fr=%d a3=%08X\\n", FRAME, a3 ; g }') +dbg:command('bpset 3f204400,,{ printf "L1-CALL fr=%d\\n", FRAME ; g }') +dbg:command('bpset 3f204440,,{ printf "L1-GATE fr=%d a8=%08X\\n", FRAME, a8 ; g }') +dbg:command('bpset 3f204460,,{ printf "L1-ZERO-LOOPBACK fr=%d\\n", FRAME ; g }') +dbg:command('bpset 3f208060,,{ printf "LED-RESTART fr=%d a10=%08X\\n", FRAME, a10 ; g }') +dbg:command('bpset 3f208660,,{ printf "LED-BLINK fr=%d a10=%08X\\n", FRAME, a10 ; g }') +dbg:command('bpset 3fde9d70,,{ printf "ERR-HOSTPORT fr=%d\\n", FRAME ; g }') +dbg:command('bpset 3fdf0630,,{ printf "ERR-DISPATCH fr=%d a8=%08X a10=%08X\\n", FRAME, a8, a10 ; g }') + +local maxframes = tonumber(os.getenv("CF_FRAMES") or "20000") +emu.register_frame_done(function() + FRAME = FRAME + 1 + if FRAME % 2000 == 0 then + print(string.format("frame %d PC=%08X", FRAME, cpu.state['PC'].value)) + end + if FRAME >= maxframes then + print("done (" .. FRAME .. " frames)") + machine:exit() + end +end, "vt1200-cf") + +dbg.visible_cpu = cpu +dbg.execution_state = 'run' diff --git a/harness/mame/console_frames_20k.log b/harness/mame/console_frames_20k.log new file mode 100644 index 0000000..6cb8876 --- /dev/null +++ b/harness/mame/console_frames_20k.log @@ -0,0 +1,57 @@ +MAME debugger version 0.289 (mame0289-dirty) +Currently targeting vt1200 (VT1200 X terminal (v2.2 firmware)) +Breakpoint 1 set +Breakpoint 2 set +Breakpoint 3 set +Breakpoint 4 set +Breakpoint 5 set +Breakpoint 6 set +Breakpoint 7 set +Breakpoint 8 set +Breakpoint 9 set +L1-CALL fr=0 + +RUNNER-ENTRY fr=0 a3=00000000 + +ERR-DISPATCH fr=1 a8=00000001 a10=00000000 + +P fr=1 a9=3FDCA8E8 + +ERR-DISPATCH fr=484 a8=00000400 a10=00000000 + +ERR-HOSTPORT fr=484 + +P fr=484 a9=3FDC9C68 + +P fr=484 a9=0080000C + +P fr=484 a9=00C0000C + +P fr=484 a9=0100000C + +P fr=484 a9=0200000C + +LED-BLINK fr=484 a10=00000000 + +P fr=1534 a9=3FDCD2A8 + +P fr=1538 a9=0200000C + +ERR-DISPATCH fr=1627 a8=00000800 a10=00000000 + +P fr=1627 a9=3FDC9D78 + +P fr=1627 a9=0080000C + +P fr=1627 a9=00C0000C + +P fr=1627 a9=0100000C + +P fr=1627 a9=0200000C + +LED-BLINK fr=1627 a10=00000000 + +P fr=2759 a9=3FDCD2A8 + +P fr=2764 a9=0200000C + diff --git a/harness/mame/wall_hist.lua b/harness/mame/wall_hist.lua new file mode 100644 index 0000000..7770ad6 --- /dev/null +++ b/harness/mame/wall_hist.lua @@ -0,0 +1,62 @@ +-- wall_hist.lua -- where does the run END UP, and does it keep changing? +-- +-- Samples the PC once per emulated frame but only counts the window +-- [W_START, W_END], so the early boot/test phases do not pollute the histogram +-- of the final state. Prints a few timestamped PC snapshots so "stuck" is +-- supported by an across-time comparison, not one sample. +-- +-- W_START= default 5000 +-- W_END= default 20000 +-- W_SNAP= snapshot stride (default 2000) +-- W_OUT= printable summary copy +-- +-- vt1200 ... -debug -debugger none -debuglog \ +-- VT1200_LOG_UNMAPPED=... VT1200_BOARD_LOG=... VT1200_DUARTLOG=... \ +-- -autoboot_script harness/mame/wall_hist.lua -autoboot_delay 0 + +local machine = manager.machine +local dbg = machine.debugger +local cpu = machine.devices[':maincpu'] + +if not dbg then + print("ERROR: debugger not enabled; pass -debug") + machine:exit() + return +end + +local wstart = tonumber(os.getenv("W_START") or "5000") +local wend = tonumber(os.getenv("W_END") or "20000") +local snap = tonumber(os.getenv("W_SNAP") or "2000") + +local frames = 0 +local hist, first, last = {}, {}, {} + +emu.register_frame_done(function() + frames = frames + 1 + local v = cpu.state['PC'].value + if frames >= wstart then + hist[v] = (hist[v] or 0) + 1 + if not first[v] then first[v] = frames end + last[v] = frames + end + if frames % snap == 0 then + print(string.format("frame %6d PC=%08X", frames, v)) + end + if frames >= wend then + local n = 0 + for _ in pairs(hist) do n = n + 1 end + print(string.format("--- window [%d,%d]: distinct PCs=%d", wstart, wend, n)) + print("--- hottest PCs ---") + local list = {} + for k, c in pairs(hist) do list[#list + 1] = {k, c} end + table.sort(list, function(a, b) return a[2] > b[2] end) + for i = 1, math.min(25, #list) do + print(string.format(" PC=%08X samples=%d first=%d last=%d", + list[i][1], list[i][2], first[list[i][1]], last[list[i][1]])) + end + machine:exit() + end +end, "vt1200-wall") + +dbg.visible_cpu = cpu +dbg.execution_state = 'run'