# Why 38400 wedges

> Folded into `testReport.md` as **section 10**, which carries the headline numbers; this file is the
> full record.  It was written against the build that still had the fault, so its addresses and its
> present tense are that build's; `portCompatReport.md` and `testReport.md` section 11 measure the
> build with the re-entrancy guard, in which the failure below does not occur.

`highRateReport.md` characterised the 38400-baud wedge and said plainly that it had not been
explained: four boots, four wedges, one ending in `*** Main CPU: JAM at $0007`, and no path traced
from any measured byte to any of it.  This document explains it, from measurements taken for that
purpose.

**The cause is NMI re-entrancy, and it is established, not inferred.**  A machine was stopped by a
checkpoint at the instant it entered `commNmiHandler` with `SP = $12`, and thirty-four complete
nested handler frames were decoded off page 1.  The descent from a healthy stack to an exhausted one
was recorded three separate times, with the emulator's own cycle counter, and takes **8 to 13
milliseconds**.  The arithmetic behind it was measured too: one pass of the handler costs 175 to 266
cycles, and at 38400 baud a character time is 266.3 cycles with **two** interrupts inside it.  The
handler cannot finish before the next one arrives, so it never finishes at all.

Everything below is VICE 3.7.1 (`x64sc`), NTSC, `-acia1mode 1 -acia1base 0xDE00 -acia1irq 1`, on
**2026-08-22**, against a disk built from the current source with `./build.sh`
(`checkAbi.py` prints `ABI CHECK PASSED`).  **No driver source was changed.**  The only write either
script makes to a machine is `baudIndex $E055` before the link is opened - 38400's hot key was
removed from `baudEntryTable`, so the rate is selected by setting the index and letting the driver's
own `loadBaudParameters $E353` program the control register.  `$DE03` read `$1F` on every machine in
every run.

---

## 1. The answer

1. The 6502 does not mask NMI.  Entering an NMI sets `I`, which stops IRQs, and nothing at all stops
   another NMI.
2. `commNmiHandler $E685` reaches `jsr aciaGetStatus` at `$E68F` eight instructions in, and that
   routine's `lda $DE01` is the ninth.  On a 6551 that read *is* the acknowledge: it clears the IRQ
   flag and releases `/IRQ`.
3. From that read to the end of the pass - up to about 220 more cycles - the chip is free to raise
   a fresh event.  `/IRQ` falls again, the 6502 latches the edge, and the handler is re-entered
   at the very next instruction boundary.  Each re-entry costs **6 bytes of stack** (the CPU's
   `PCH`/`PCL`/`P` plus the handler's `A`, `X` and saved `$01`), or **8** when the edge lands while
   the interrupted pass was inside one of its own `JSR`s.
4. At 38400 baud with traffic in both directions there are **two** interrupt-raising events per
   character time - one `RDRF`, one `TDRE` - so an edge arrives roughly every 133 cycles, while one
   pass of the handler costs 175 to 266.  **Service time exceeds inter-arrival time.**  The queue is
   not a queue: it is a stack, and it grows without bound.
5. About thirty frames is the whole of the 170-odd bytes of page 1 the game leaves free.  Measured:
   **8.4 ms, 12.5 ms and 11.5 ms** in three independent bursts.
6. Once `SP` wraps past `$00` the frames overwrite one another.  Every `RTI` from then on pops a `P`
   and a `PC` that belong to a different frame, and the `PLA` / `STA $01` at `$E6E3`/`$E6E4` writes a
   foreign byte into the CPU port register.  The machine leaves the handler with a corrupted program
   counter, a corrupted flag byte, or a corrupted memory map - and that is the wedge.

The driver's own comment at `commNmiHandler` names this race and prices it at "a checksum failure and
one retransmit, which the ARQ layer above already deals with".  That price is right for one re-entry.
What the comment does not say is that above about 19200 baud it stops being one re-entry.

---

## 2. What one pass of the handler costs - measured

`testCost.py` traces six addresses inside the handler - the entry `$E685`, `sta aciaRxByte $E699`,
`dec uartPendingCount $E6C9`, `jsr aciaPutData $E6D6`, and both exits (`rti $E6E9`, `jmp
(nmiChainVector) $E67F`) - and pairs every entry with its exit, so each pass can be priced *and*
classified by what it actually did.  It was run at **19200**, where the link is healthy and busy, and
where nothing nests: the handler's cost is the same code at any rate.

Four windows, two machines, 34.8 emulated seconds, 5694 complete passes:

| what the pass did | passes | trace-to-trace, median | whole interrupt |
|---|---:|---:|---:|
| received a character | 2983 | 165 cycles | **178 cycles** |
| transmitted a character | 1835 | 165 | **178** |
| transmit interrupt found the ring dry, disarmed it | 677 | 162 | 175 |
| **received and transmitted in the same pass** | 188 | 243-253 | **256-266** |
| neither half had work (a DCD/DSR change) | 11 | 151 | 164 |

"Whole interrupt" adds the 7 cycles the CPU spends taking the NMI and the 6 the `RTI` costs, neither
of which lies between the two tracepoints.  A hand count of the same paths off the source agrees to
within a cycle, which is worth saying because it means the figure is a property of the code and not
of the emulator.

Now put that against the line.  An NTSC C64 runs at 1,022,727 Hz and 8N1 is ten bits per character:

| rate | characters/s | one character time | one pass | two passes | share of the CPU |
|---|---:|---:|---:|---:|---|
| 300 | 30 | 34090.9 cycles | 178 | 356 | 1% |
| 1200 | 120 | 8522.7 | 178 | 356 | 4% |
| 2400 | 240 | 4261.4 | 178 | 356 | 8% |
| 4800 | 480 | 2130.7 | 178 | 356 | 17% |
| 9600 | 960 | 1065.3 | 178 | 356 | 33% |
| 19200 | 1920 | 532.7 | 178 | 356 | **67%** |
| 38400 | 3840 | **266.3** | 178 | 356 | **134% - cannot keep up** |

The "one pass" column is a single-half pass; a pass that services both halves costs 256-266.

Two numbers in that table decide everything.

* **A full-duplex pass costs 266 cycles and a character time at 38400 is 266.3 cycles.**  One
  interrupt that services both halves consumes an entire character time on its own, leaving the game
  nothing.
* When the receive and transmit events land in *separate* passes - which is the normal case, because
  they are separate events at separate instants - the cost is **356 cycles of work offered every 266
  cycles**.  That is the whole failure in one line.

This is also the ladder every earlier report measured without knowing why: healthy at 4800 (17%),
degrading at 9600 and 19200 (33% and 67%), gone at 38400.

---

## 3. The re-entrancy itself - measured three times

`testStack.py` arms one tracepoint before the link is ever opened:

```
trace exec e685 if sp < $b4
```

A tracepoint prints and lets the machine run on, so this does not disturb anything, and it prints
**nothing at all** while nesting is shallow: the main line runs with `SP` between `$BD` and `$EB`, so
an entry below `$B4` is already one frame deeper than the deepest healthy entry seen on any
machine in any run.  Every VICE trace
line carries `SP` and the free-running cycle counter, so the output is a timestamped staircase.

Three runaways were caught, on freely running machines, with no breakpoint involved:

| run | machine | entries | duration | `SP` fell | frames | rate of descent |
|---|---|---:|---:|---|---:|---:|
| `st384d` | B | 44 | 8611 cycles = **8.42 ms** | `$B0` -> `$02` | 174 bytes = 29 | 20666 stack bytes/s |
| `st384d` | B | 91 | 12807 cycles = **12.52 ms** | `$B3` -> `$08` | 171 bytes = 28.5 | 13656 bytes/s |
| `st384c` | B | 84 | 11780 cycles = **11.52 ms** | `$B3` -> `$00` | 179 bytes = 30 | 15541 bytes/s |

The first twenty-four entries `st384d`'s machine B recorded below `$B4`, as `(SP, cycle)`:

```
($B3,153671517) ($B0,+264) ($B2,+152) ($AA,+115) ($AF,+147) ($A7,+117) ($A9,+152) ($A1,+115)
($A9,+153)      ($A1,+115) ($A1,+148) ($99,+115) ($A1,+153) ($99,+115) ($99,+147) ($91,+117)
($99,+151)      ($91,+115) ($93,+153) ($8B,+115) ($90,+147) ($88,+163) ($8A,+107) ($84,+113)
```

Read the gaps: they alternate **115 and about 150 cycles, and 115 + 150 = 265** - one character time
at 38400, with two interrupts inside it.  That is the "two events per character" claim measured
directly rather than argued.  Read the stack pointer: it saws up and down as inner passes complete,
and every saw tooth is lower than the last.  In `st384d` the in-burst gaps were min 55, 25th percentile 117,
median 158, 75th percentile 265 cycles; in `st384c`, min 55, 25th percentile 60, median 171, max 269
- against a handler that needs 175 to 266.

**Control.**  The same script, the same instrumentation, 200 seconds at **19200** with two machines
carrying 16729 and 16856 bytes - six times the traffic the 38400 runs managed - produced **no entry
below `SP $B4` at all, on either machine**, and neither stack was ever pushed below `$01C9`.  At
19200 the handler fits inside the character time, so it never nests.

---

## 4. The stack, decoded

`st384b` carried a second checkpoint, `break exec e685 if sp < $20`, which stops the emulator once
the stack is nearly gone.  It fired.  Machine A was stopped **at `$E685`, the first instruction of
`commNmiHandler`, with `SP = $12`, `X = $14` and `I` set** - about to push three more bytes onto a
stack with room for two more nested passes.  This is the one machine whose stack can still be
*walked*: it was stopped part-way down, before the pointer wrapped and the frames began overwriting
one another.

Its page 1, walked upward from `$0113` (the newest pushed byte) to `$01FF`, decodes without a gap or
an ambiguity into **34 complete nested handler frames plus 16 `JSR` return addresses**:

| what | value | count |
|---|---|---:|
| interrupted PC | `$E6C4` | 10 |
| | `$E6C7` | 9 |
| | `$E551` | 8 |
| | `$E6C2` | 7 |
| saved `X` | `$14` | 33 of 33 |
| saved `$01` | `$35` | 33 of 33 |
| saved `P` | `$25` / `$27` | 25 / 9 - `I` set in every one |
| saved `A` | `$10` / `$09` / `$00` | 17 / 8 / 8 |
| `JSR` return addresses under the frames | `$E40A`, `$E6E2` | 8 each |

Every one of those addresses is inside the handler's **transmit half**, in the window between the
status read at `$E68F` and the two writes that would remove the interrupt source:

* `$E6C2` - `beq L_E6EA`, the `TDRE` test
* `$E6C4` - `lda txCharActive`
* `$E6C7` - `beq L_E6D1`
* `$E551` - `sta aciaCommandShadow` inside `aciaSetCommand`, reached from `aciaSetCommandIdle $E408`
  at `$E6E0`; the two `JSR` return addresses `$E6E2` and `$E40A` sitting under those frames are that
  call chain

The saved `$01` is `$35` in all 33 frames, which by itself proves nesting: `$35` is the value the
handler *forces* at `$E68D`, so a frame that saved `$35` was interrupted by a handler that had
already run.  The saved `X` is `$14` = 20 in all 33: `pushUartRxRing` leaves `X` at `uartRxCount`,
and the receive ring was pinned at its 20-byte limit because the game had stopped draining it.

Three things fall out of that table that earlier reports could not explain.

* **`$E6C4` and `$E6C7` straddle `dec uartPendingCount $E6C9`.**  A pass interrupted at `$E6C7` has
  already read `txCharActive` and decided to count a byte off; the inner pass then does its own
  `dec`, clears `txCharActive`, pops the ring and writes the data register; when the outer pass
  resumes it decrements *again* for the same byte and writes the data register *again*.  That is
  where `highRateReport.md` section 4's lost transmit characters come from - VICE's "data register
  written although data has not been sent yet", 0.8% at 4800 climbing to 2.2% at 19200, the same
  curve as the duty cycle in section 2 - and it is how `uartPendingCount` gets below zero to the
  `$FF` that section 6.1 found.  *The double decrement is shown here as a frame stopped one
  instruction short of the `DEC`; a `DEC`/`INC` imbalance was not separately counted during a storm.*
* **`$E551` explains boot 4's impossible command register.**  `aciaSetCommand` writes the shadow at
  `$E551` and the chip at `$E554`.  A machine thrown off the rails between those two instructions
  ends up exactly as `highRateReport.md` section 6.2 found it: `$DE02` = `$05`, transmit interrupt
  still armed, while `aciaCommandShadow` says `$09`.
* **The two stacks that finished the job cannot be walked, and that is the point.**  `st384c`'s
  and `st384d`'s machine B both
  finished with page 1 covered end to end in the same material - `$35`/`$14` pairs, `P` bytes of
  `$65`/`$67` with `I` set, and the return addresses `$E6B5` (`jsr reportLinkError`), `$E6E2` (`jsr
  aciaSetCommandIdle`), `$E40A` (`jsr aciaSetCommand`), `$E551`/`$E554`, `$E6B9`/`$E6BB` and
  `$E6E7`/`$E6E8`, the last two being `tax` and `pla` in the handler's own exit sequence.  Those two
  stacks cannot be walked frame by frame the way `st384b`'s can, because the pointer had wrapped and
  the frames had overwritten each other - which is itself the point.

---

## 5. The aftermath, and why the four boots looked different

Once `SP` has wrapped, an `RTI` pops three bytes that were written by three different interrupts.
What the machine does next depends on which bytes.  Five 38400 boots were run in this session and
four machines died; with the one `highRateReport.md` caught, they are the *same* failure photographed
at different moments:

| machine | where it ended up |
|---|---|
| `st384b` A | caught mid-runaway: `PC $E685`, `SP $12`, 34 frames still on the stack |
| `wg384a` A | running game code at `$44EB-$4502` with `I` **set**, `SP` frozen at `$BD` |
| `st384d` B | `PC $C631`, `SP $67`, `I` set, page 1 covered in handler frames |
| `st384c` B | `PC $A34E`, `SP $B2`, `I` **and `B`** set, and **`$01 = $31`** - `CHAREN` clear, so `$D000-$DFFF` is the character ROM and the ACIA is not in the address space at all |
| `highRateReport.md` boot 4 | `JAM at $0007`, `$00`/`$01` = `$5E`/`$15` - the same corrupt `PC` and the same smashed CPU port, landing on an illegal opcode instead of on live code |

`st384c`'s `$01 = $31` is the mechanism caught in the open: `$E6E3` is `pla` and `$E6E4` is `sta
$01`, so a wrecked stack hands the memory-map register whatever byte happens to be there.  Boot 4's
`$01 = $15` is the same instruction with different rubbish.

### Why it never recovers

`wg384a`'s machine A was measured for 154 seconds after it died, and three readings say why nothing
comes back:

* **`pollCarrierState $E3CB` - the `$E00C` entry the raster IRQ calls once a frame - executed ZERO
  times** in a 12.15-second traced window and **zero** again in an 8.19-second one.  Its healthy peer
  executed it 479 times in 8.51 seconds, 56.3/s.  Across the whole run the monitor read machine A's
  registers **124 times, and the interrupt flag was set in all 124, with `SP` at `$BD` in all 124**;
  the same 124 reads on its healthy peer found `I` set in only 15 - the ones that caught it inside
  its raster IRQ - and `SP` ranging over `$DF`-`$E5`.  A 6502 with `I` set takes no IRQ, so there is
  no `$E000`/X=0 and no `$E00C`, and **nothing in the driver runs except the NMI**.
* **`sta uartPendingCount $E611`, `startNextTxChar`'s once-a-frame repair of exactly the byte
  `highRateReport.md` section 6.1 found stuck at `$FF`, also executed zero times.**  Its peer ran it
  478 times in the same 8.51 seconds.  The self-heal cannot heal anything, because the self-heal is
  on the frame tick and the frame tick is gone.
* **`serviceLock $E0A7` read `$00`.**  It rests at 1; `serviceCommTick` decrements it on entry and
  restores it at `$E149`.  The runaway threw the CPU out of the middle of a service tick, so the
  lock is held for ever - a second latch that would refuse to run the driver even if the raster IRQ
  came back.

Its remaining state, for the record: `connectionPhase $E040` = 2, `isLinkActive $E03B` = 1,
`uartRxCount $E42D` = `$14` with both indices frozen at `$02`, `uartTxCount $E414` = 0,
`uartPendingCount $E0A5` = `$00`, `txCharActive $E5BB` = `$00`, `aciaCommandShadow $E5BE` = `$09`,
`$DE01`/`$DE02`/`$DE03` = `$10`/`$09`/`$1F`.  The NMI itself was still working perfectly - 18 to 21
interrupts a second, 0.3% duty cycle, every one of them 164 to 207 cycles - and it had nobody left to
deliver to.  **That is why the 2400-baud repair probe could never have worked: by the time a wedged
machine can be examined, the driver is fine and the machine above it is dead.**

---

## 6. What was ruled out

| hypothesis | verdict | on what evidence |
|---|---|---|
| NMI re-entrancy | **ESTABLISHED** | 34 nested frames decoded off a live stack; three timed descents; the cost/character-time budget |
| Steady-state CPU starvation by the NMI | **ruled out as the wedge** | after the wedge the NMI duty cycle is 0.3% and the game gets essentially the whole CPU - it just has `I` set.  Overload is the *trigger*, not the resting state |
| The 20-byte receive ring being too small | **not the cause** | it overflows at 9600 and 19200 too, and those recover.  In the wedges the ring is full because the game stopped draining it - a consequence, and `X = $14` in every stack frame is that consequence in the act |
| `uartPendingCount` reaching `$FF` (`spec_uart.md` hazard 1) | **a consequence, not the cause** | `wg384a`'s machine A wedged with `uartPendingCount` = `$00`.  The `$FF` shape needs both the double decrement (section 4) and a dead frame tick (section 5) |
| The control byte `$1F` itself, or the rate table | **ruled out** | `$DE03` read `$1F` on every machine in every run and characters crossed the wire correctly; `highRateReport.md` section 7 ran a machine at `$1F` against a 300-baud peer for 245 s with no wedge, no overflow and no bad character.  The chip setting is innocent; the *traffic* is what kills |
| A spurious interrupt storm from the chip (a VICE artefact) | **ruled out** | in normal operation the median gap between handler entries is 267-268 cycles, exactly one character time, and the interrupt rate tracks the character rate.  The chip raises one interrupt per event, as it should |
| A protocol deadlock above the driver | **ruled out** | the wedged machines' CPUs were thrown out of their own control flow with a corrupt `P`, `PC` or `$01`; a healthy peer's page 1 in the same run is untouched below `$01C9` |
| The 2400-baud transmitter deadlock | **not this** | `txCharActive`/`aciaCommandShadow` were the self-consistent pair `$00`/`$09` on every wedged machine, as `highRateReport.md` section 6 already found |
| Word length / parity / stop bits | **irrelevant here** | every run was 8N1 throughout.  Nothing in this failure depends on the framing |

**38400 does not always kill inside a minute.**  Run `st384a` reached phase 3 on both machines and
neither wedged in 200 seconds, on the same build, with the same instrumentation armed.  The failure
needs both directions bursting at once - `sendPacket $E909` queues a whole 20-odd byte frame into the
22-byte ring in one loop and the NMI shifts it out back to back - so it is a race that a quiet link
can lose for a while.  Five 38400 boots in this session, four machines dead.

---

## 7. What this does not show

* **VICE, not hardware.**  No physical SwiftLink and no C64 Ultimate.  Two things carry to hardware
  regardless, because they are properties of the driver and of the 6502: the handler's cost in cycles
  (measured here, and confirmed by a hand count off the source) and the fact that reading the status
  register releases `/IRQ` while the handler still has 100 to 240 cycles of work left.  What VICE
  cannot settle is the precise instant a real 6551 re-asserts `/IRQ`, so the *speed* of the collapse
  on a real cartridge may differ from 8-13 ms.  The direction cannot: 356 cycles of work per 266
  cycles of line time is arithmetic.
* **VICE's ACIA is byte level**, so no framing or parity error can be produced on this rig.  On a
  real line those errors add `reportLinkError $E3BC` -> `countLinkError $E73F` to the receive path,
  which makes the pass *longer*, not shorter.
* **The double decrement of `uartPendingCount` is shown structurally, not counted.**  Section 4 has a
  stack frame stopped one instruction before the `DEC`; it does not have a `DEC`/`INC` imbalance
  counted during a storm.  Instrumenting `$E6C9` and `$E71E` unconditionally at 38400 prints
  thousands of lines a second, and the storm lasts eight milliseconds.
* **Nothing was fixed and nothing was changed.**  No driver source file was touched;
  `checkAbi.py` passes on the image every run above was made against.

---

## 8. What any fix has to satisfy (not implemented)

Stated here only because the measurements pin the constraints, and because two of them rule out
repairs that look obvious:

1. **The handler must be safe to re-enter, or must not be re-enterable.**  Re-entry is not rare at
   high rates and it is not free: it costs 6 to 8 bytes of stack and it corrupts `uartPendingCount`,
   `txCharActive` and the byte in the transmitter.  A re-entrancy counter alone is not enough - the
   source's own comment is right that naively refusing a nested pass can lose the interrupt that
   would have restarted the transmitter, and a lost `TDRE` stalls the transmitter for ever.
2. **Total interrupt work per character time must stay below one character time at the rate the user
   has configured.**  At 38400 that means the two halves must be serviced by *one* interrupt of well
   under 266 cycles - i.e. the handler has to get materially cheaper, or the transmitter has to stop
   asking for an interrupt per character.
3. **Whatever is done must hold when the user's hardware is set to a rate the driver did not choose**,
   which is the point of the current work: the rate is not the driver's to pick.
4. **Eight data bits are mandatory** - the frame layer sends `$55` length codes, sequence bytes and
   rotate-and-add checksums, so it is not 7-bit clean.  Parity and stop bits are free.  Nothing in
   this diagnosis depends on framing either way.

---

## 9. Files

| File | What it is |
|---|---|
| `testWedge.py` | pairs the handler's entry with its exits, counts re-entries, measures the duty cycle, counts the `$E00C` frame service, and profiles PC/SP with monitor pauses |
| `testStack.py` | the deep-nesting tracepoint and the stack-page checkpoints; `traceonly` mode records the staircase without ever stopping the machine |
| `testCost.py` | classifies and prices every pass of the handler, and prints the per-character-time budget |
| `testLogs/wedge.wg384a.txt` | the 38400 boot whose machine A died with `I` set and its raster IRQ gone |
| `testLogs/wedge.wg384a.A.nmi.trace.txt`, `.A.after.trace.txt`, `.B.after.trace.txt` | the traces behind the "`$E3CB` executed zero times" measurement |
| `testLogs/stack.st384a.txt` | a 38400 boot in which neither machine wedged in 200 s |
| `testLogs/stack.st384b.txt` | the boot stopped at `SP = $12`; the stack page decoded in section 4 |
| `testLogs/stack.st384c.txt`, `stack.st384d.txt` | the trace-only boots; the three timed descents |
| `testLogs/stack.st384c.B.deep.txt`, `stack.st384d.B.deep.txt` | the raw staircases, with `SP` and cycle counter per line |
| `testLogs/stack.st192a.txt` | the 19200 control: heavier traffic, no nesting, no wedge |
| `testLogs/cost.c192a.txt`, `testLogs/cost.c192a.[AB].[01].trace.txt` | the pass-cost measurement of section 2 |
| `shots/wgwg384a*.png`, `shots/stst384*.png`, `shots/stst192a*.png` | both machines at the end of each run |