modemwars/swiftlink/realtimeReport.md
2026-08-23 02:09:40 -05:00

40 KiB

Real-time behaviour of the SwiftLink module at a given line rate

Note on addresses. This report records a run made before the probe-hardening pass, which relocated six internal helpers. Addresses quoted below are the ones those routines had at the time of the run. See ADDRESS_CHANGES.md for the mapping onto the current source.

Every earlier test in this directory ran in warp, so none of them said anything about how the link behaves in real time or whether the traffic matches the rate the 6551 is programmed for. This report closes that gap. Both emulators are cross-connected through the socket null modem and both run at true C64 speed; everything here is VICE 3.7.1 (x64sc). The report covers two campaigns on that same rig:

  • 2026-08-21, before the transmitter-deadlock fix - sections 1 to 7, kept as the record of the fault and of how it was measured.
  • 2026-08-22, after the fix - section 8, which re-ran the same rig against the fixed driver.

Script: swiftlink/testRealtime.py. Logs: testLogs/realtimeRun300first.txt, testLogs/realtimeRun2400first.txt (before), testLogs/fixRun1.300then2400.txt, testLogs/fixRun2.2400first.txt, testLogs/fixRun3.2400first.txt (after), the per-second byte counts in testLogs/realtime.*.samples.txt, and the screenshots shots/rt*.png.

Short answer:

  • At 300 baud the link is healthy at true C64 speed and the throughput is exactly the line rate. While the two games had something to say to each other the link ran at 30.0 bytes/s in each direction, second after second - 300 bit/s of 8N1 line time, which is 100% of what 300 baud can carry. No framing, parity or overrun error was reported at either end. Still true after the fix: section 8's 300-baud window held 29.8 bytes/s each way for all 75 seconds, with no second below 27.
  • Before the fix, at 2400 baud it was not healthy. The link came up - both ends reached connection phase 3 - and then fell apart within about twenty seconds, every time, in three separate 75-second windows over two boots. One machine stopped transmitting for good and the other poured out $00 byte-sync characters at exactly one per video frame. The stalled machine was left with txCharActive ($E5BB) set while its command shadow said the transmit interrupt was off, which is a state its own code cannot leave; writing a single $00 over $E5BB from the monitor brought it straight back to life. No character-level error was counted at either end while this happened.
  • After the fix, 2400 baud holds. Nine 75-second windows over three boots, both ways of reaching the rate, 675 seconds of measured link time: the deadlock did not recur once, every window carried traffic in both directions in every single second, and txCharActive was never once found set with the transmit interrupt disarmed - in any of the 66 state readings taken at the window edges of three runs. Section 8.

1. Method

Running at true speed

viceHarness.ViceSession(..., warp=False) starts x64sc with +warp. VICE 3.7.1 has no WarpMode resource - three spellings were tried in an earlier session and all were rejected - but its monitor does have a warp command (warp [on|off|toggle]), and that is what makes this measurement possible. The script turns warp on by hand before the loader, breaks at $0800 as every earlier test does, then turns warp off and confirms with warp, which answers Warp mode is off. From that point nothing is warped: the options menu, the module load, the modem prompts, the Hayes dialogue, the byte sync and both measurement windows all run at 1 MHz.

Measuring the traffic

The null modem is testTwoMachines.NullModemRelay: one TCP listener, both emulators connect out to it, every byte is forwarded and counted per direction. conn0 is the machine that opened its ACIA first, which is always machine A (the answer side, driven first by the script); conn1 is machine B (originate). The 2400-baud runs confirm that mapping independently: the direction that carried nothing is conn0, and it is machine A whose state readback shows the stalled transmitter while machine B's command shadow shows a transmitter that is still armed.

A measurement window is 75 seconds of wall clock during which nothing is sent to either monitor, because any input stops that emulator and would corrupt the number being measured. The relay's counters are read from the test script's own thread, which costs the emulators nothing, once a second during the window and at both edges.

Proving the emulators really ran at 1 MHz

The monitor's stopwatch command prints the CPU cycle counter, free running since the emulator started. It is read at both ends of every window, so the emulated time the window covers is known independently of the host's load: cycles / 1022727 (VICE's C64 NTSC clock) against wall seconds. Every window in this report came out between 100.5% and 100.9% of real time. The systematic +0.5 to +0.9% is the test rig, not the emulator: the cycle counter is read while the emulator is stopped and the window's wall clock starts after it is resumed, so roughly half a second of stopping and starting is inside the cycle count and outside the wall time. A machine that could not keep up would read well under 100%, which is what this check exists to catch.

Counting errors

The NMI receiver tests the ACIA status against #$07 at $E69F (overrun, framing error, parity error) and pushes every bad character - and every receive-ring overflow - through reportLinkError $E3BC into countLinkError $E403, which bumps linkErrorCount $E047. A VICE tracepoint (trace exec $e403) prints on every hit and does not stop the emulator, so it counts those events for the whole window at no cost to timing. linkErrorCount itself is also read at both window edges, but it is only half an instrument: restartByteSync clears it at $E814, so it only ever shows errors since the last resync.

The tracepoint was validated separately, because an instrument that never fires proves nothing: a trace exec $ea31 on the KERNAL raster IRQ of an idle machine produced 146 #1 (Trace exec ea31) lines in three seconds through the same drain path the real runs use.

Selecting the line rate

The driver's speed hot keys work. VICE's default symbolic keymap puts the Commodore key on Tab (/usr/share/vice/C64/gtk3_sym.vkm: Tab 7 5), not on Control_L - Control_L is C64 CTRL, and the game's own matrix scanner at $0DB7 deliberately reports CTRL as "no key". That is why the earlier session's ctrl+c attempt at the C=+C hot key did nothing. Holding Tab and pressing 2 gives C= + 2, and the driver takes it: baudIndex $E055 (written by the hot key and by nothing else) went to 6 and $DE03 to $18 on both machines, on a live link and again at the "PRESS A OR O" prompt. No monitor write to $DE03 was needed in either run.

One timing rule worth recording: at the A/O prompt the hot key only lands after initCommModule has patched the module's keyboard vector. $E013/$E014 reads $E3B2 (returnNoKey) until then and every key is answered with $FF, so the script waits for that vector to become $0DB7 before pressing.


2. What was measured

Two boots, four 75-second windows (plus retries), both machines at true speed throughout.

Run window first rate reached how conn0 (A -> B) conn1 (B -> A) A speed B speed
A 1 300, the disk default 1796 B = 23.91 B/s 1813 B = 24.13 B/s 100.9% 100.5%
A 2 2400, C=+2 on a live link 0 B = 0.00 B/s 4497 B = 59.83 B/s 100.9% 100.5%
B 1 2400, C=+2 before the link opened 0 B = 0.00 B/s 4495 B = 59.81 B/s 100.9% 100.5%
B 2 300, C=+3 on a live link 0 B 0 B 100.9% 100.5%

Run A window 2 and run B window 1 are each the last of three attempts; the script throws a window away and measures again when either machine ran under 90% of real time or when a direction carried nothing, and all three attempts in each case were identical.

Those four windows are the pre-fix driver. Section 8 has the eleven windows measured against the fixed one.


Run A, window 1, 75.13 s wall, both games in the middle of the side-0/side-1 negotiation (machine A showing "OPPONENT PICKING GAME/MAP.", machine B on the GAME TYPE menu - shots/rt02aLinked.png, shots/rt02bLinked.png).

conn0  A -> B   1796 bytes / 75.13 s = 23.91 bytes/s = 239 bit/s   0.400 bytes per video frame
conn1  B -> A   1813 bytes / 75.13 s = 24.13 bytes/s = 241 bit/s   0.403 bytes per video frame

The per-second samples (testLogs/realtime.a.run300.samples.txt) show that average is two different regimes, not a steady stream:

  t= 2..55 s   A = 30.0  B = 30.0   bytes/s, second after second
  t=56..75 s   A =  6-12 B =  7-11  bytes/s

Over the first 54.09 seconds: A sent 1576 bytes = 29.14 bytes/s (291 bit/s), B sent 1592 bytes = 29.43 bytes/s (294 bit/s), and almost every individual one-second bucket is exactly 30 bytes.

30.00 bytes/s is exactly 300 baud. 8N1 costs 10 bits per byte - one start bit, eight data bits, one stop bit - so 300 baud carries at most 30 bytes a second, and 30 bytes a second is what was measured, to the resolution of a one-second bucket, in both directions at once. So while the packet layer had traffic to send it saturated the line, and VICE really is pacing the emulated line from the control register rather than from -rsdev1baud. (The command line said -rsdev1baud 2400 throughout; the measured rate was 30 bytes/s. That setting only matters for a real serial device.)

The drop after t=56 s is the link falling out of the packet phase into a byte-sync round: machine A's side of the wire contains one run of 46 consecutive $00 in the window, and the end-of-window snapshot caught A in phase 3 and B in phase 2.

What the bytes themselves look like: 697 $55 frame lead bytes from A and 626 from B in the window - this is the real ARQ frame layer at work, not a sync flood.

Register and state readback at the end of that window:

machine A machine B
$DE03 control $15 $15
decoded 8N1, internal baud generator, rate bits $5 = 300 baud on a SwiftLink same
$E056 bitPeriodLo (the driver's copy of the control byte) $15 $15
$E055 baudIndex 0 0
$DE02 command $05 (transmitter armed) $05
$DE01 status $00 $00
$E03B isLinkActive $01 $01
$E03C linkStatus $F8 (carrier + data flowing) $F8
$E040 connectionPhase 3 2
$E047 linkErrorCount $00 $00
$E403 countLinkError tracepoint hits in the window 0 0

So at 300 baud, at true C64 speed: no framing, parity or overrun character at either end for 75 seconds, throughput equal to the configured rate whenever there was anything to send, and the ACIA programmed exactly as the module's table says it should be.


This section describes the driver as it was on 2026-08-21. The deadlock it documents has since been fixed and the fixed driver was re-measured on the same rig - see section 8.

The rate itself is programmed correctly. $DE03 read $18 on both machines - 8N1, internal baud generator, rate bits $8, which is 2400 baud with the SwiftLink's doubled crystal - and $E055 read 6, the table index for 2400.

It was reached two different ways, with the same result both times:

  • Run A: healthy 300-baud link, then C= + 2 on both machines while the link was live.
  • Run B: C= + 2 on both machines at the "PRESS A OR O" prompt, before the link was ever opened - the order README.md section 3 tells the player to use. Both machines then reached connection phase 3 at 2400 baud, so the link does come up at that rate.

In both runs the link had already collapsed by the time the first 2400-baud window began - within the half minute the script spends photographing both screens, arming the tracepoint and taking a state snapshot - and it stayed collapsed for three consecutive 75-second windows (225 seconds) in run A and again in run B:

conn0  A -> B      0 bytes in 75.15 s
conn1  B -> A   4495 bytes in 75.15 s = 59.81 bytes/s = 1.000 bytes per video frame, every byte $00

Two things are worth reading off those numbers.

59.8 bytes/s is the frame rate, not the line rate. NTSC VICE runs 59.826 frames a second, and the byte-sync sender queues one character per link-service tick when the transmitter is idle (continueByteSync $E828: uartPendingCount zero -> queueSyncByte), and the link is serviced once per raster IRQ. At 300 baud the line is slower than that and caps the flood at 30.0 bytes/s; at 2400 baud the line can carry 240 bytes/s and the pacing becomes the game's own once-per-frame tick. This is the measured form of what README.md section 3 says in prose - "past a few thousand baud what improves is latency and the cost of a retransmit, not throughput" - and it puts a number on it: one byte per frame, 59.8 bytes/s, is the ceiling this driver's link layer can offer no matter how fast the line is.

The silent machine is not idle, it is stuck. Its state, identical in both runs:

stalled machine (A) flooding machine (B)
$E040 connectionPhase 2 2
$E03B isLinkActive $01 $01
$E047 linkErrorCount $00 $00
$E403 tracepoint hits 0 0
$E5BB txCharActive $01 $01
$E5BE aciaCommandShadow $09 $05
$E0A5 uartPendingCount $03, frozen $01
$DE01 status $10 (TDRE, no IRQ pending) $10
$DE03 control $18 $18

txCharActive set with command bit 2 clear is a state the driver cannot leave on its own:

  • startNextTxChar $E607 returns immediately while txCharActive is non-zero, so nothing new is ever handed to the ACIA;
  • the NMI's transmit half $E6B6 tests aciaCommandShadow & $04 first and ignores TDRE when the transmit interrupt was not armed, so txCharActive is never cleared.

This was tested directly, not inferred. With run B's machine A in that state, the script wrote a single $00 over $E5BB through the monitor and touched nothing else. In the next 15 seconds the machine that had sent 0 bytes in the preceding 225 seconds sent 37, and its peer answered with 98. So the diagnosis is confirmed: one byte of driver state is the whole difference between a dead transmitter and a live one.

When it happened, in each run. In run A the deadlock state was already there in the snapshot taken about a second after the C= + 2 keystroke: the previous snapshot had machine A in phase 3 with cmdShadow $05 (transmit armed), txCharActive $01 and uartPendingCount $03, and the one after the keystroke has the same txCharActive and the same uartPendingCount with cmdShadow now $09 - and uartPendingCount then read $03 in every later snapshot, so those three bytes never left the machine. There, the trigger looks like the control-register write landing on a transmitter with a byte in flight. In run B no such write happened on a live link at all - the rate was set before the link was ever opened - and the same state appeared anyway a few seconds into a 2400-baud session, so the write is not the only way in.

How the driver gets there was not determined, and this report does not claim it. The two candidates both come from the interrupt path, and both are consistent with the fact that the failure appears at 2400 baud and not at 300, where characters are eight times further apart:

  • the re-entrancy race the source documents at commNmiHandler - reading the status register releases /IRQ, so an event arising between that read and the data-register read re-enters the handler. If the inner pass primes a byte (aciaPutData, inc txCharActive) and the outer pass then finds the transmit ring empty, the outer pass writes command $09 at $E6DE and disarms the transmit interrupt while the inner pass's byte is still in flight - which is exactly the observed state. DESIGN_NOTES.md and README.md both describe this race as costing "one checksum failure and one retransmit"; if this is the mechanism, it can also cost the whole link.
  • any path that writes command $09/$0B without clearing txCharActive. restartUart $E586 clears it first (through aciaResumeReceiver -> clearUartState) and is safe by itself, but an NMI arriving between that clear and the command write at $E5A9 would leave the same state.

Worth noting either way: loadBaudParameters $E353 writes the new control byte and nothing else. It does not clear txCharActive, does not re-arm the transmitter, and does not care whether a character is half way out of the chip. What a real 6551 does with a byte in its shift register when the control register is rewritten under it is not something a data sheet promises, and what VICE's ACIA does with the pending TDRE was not investigated, so run A's trigger cannot be blamed on either the driver or the emulation from what was measured here. A driver that cleared txCharActive and called startNextTxChar after a rate change would be immune to that particular ordering whatever the hardware does.

Neither could be pinned down without instrumenting the NMI itself, which stops the emulator and would have destroyed the timing this test exists to measure.

After the collapse the far end behaves exactly as the protocol says it should: B counts ten sync rounds without an answer, restarts the sync, and pours $00 down a line nobody is reading. The silent machine is still receiving all of it: at the start of run B's first 2400-baud window machine A was in phase 3 with carrierSampleTimer $E045 = $07, i.e. a character had arrived seven frames earlier. It never resynchronised from that phase, and the reason is visible in the source - the NMI zeroes the protocol stall counter $EB00 on every character received, so a flood of $00 keeps that counter from ever reaching the sixteen ticks that force a resync. A machine that has stopped transmitting is therefore held in the packet phase by the very flood its peer sends to re-establish sync.

Finally, dropping back to 300 baud with C= + 3 on the live link did bring both ends back to connection phase 3 with linkErrorCount 0 - but by then the game layer above had given up: both screens read "PICK UP PHONE THEN PRESS SPACE." (shots/rtb04aAfterSecond.png, shots/rtb04bAfterSecond.png), and 0 bytes moved in either direction for 75 seconds, because at that prompt neither side has anything to send. A synchronised link with nothing on it is not the same thing as a working game, and this is the case where the two look alike from the wire.


5. connectionPhase and isLinkActive at the end of every window

As asked, read from $E040 and $E03B through the monitor at the close of each window:

run window A phase A isLinkActive B phase B isLinkActive
A 300 baud 3 $01 2 $01
A 2400 baud 2 $01 2 $01
B 2400 baud 2 $01 2 $01
B 300 baud after the switch 3 $01 3 $01

isLinkActive never dropped: the driver considers the link open in every case, including the ones where nothing can get out. Post-fix, the same two bytes at the edges of eleven more windows are in section 8; isLinkActive was $01 at every one of them too, and the phases move between 3 and 2 without any machine being stuck.


6. Errors

linkErrorCount $E047 read $00 in every snapshot taken in both runs, on both machines, and the countLinkError $E403 tracepoint recorded zero hits in every window at both rates. So no character was ever rejected for a framing, parity or overrun error, and no receive-ring overflow happened, at 300 or at 2400.

Two honest qualifications:

  • linkErrorCount is cleared by restartByteSync $E814, so on its own it only reports errors since the last resync. The tracepoint does not have that limitation, and it agrees.
  • VICE's ACIA is byte-level. Bytes cross the emulated line whole; the emulation paces them at the rate the control register asks for but does not shift them bit by bit, so a rate mismatch between two emulated ends does not produce framing errors the way real hardware would. That means this rig cannot exercise the error path by mis-setting a rate, and it also means the brief mismatch while the two machines are switched one after the other is harmless here in a way it would not be on a cable. The zero error count is therefore a real result about this driver on this emulation, and says nothing about a noisy real line.

Unchanged after the fix: linkErrorCount $E047 read $00 at all 66 post-fix state readings, and the $E403 tracepoint recorded zero hits in each of the seven post-fix windows where it was tallied. The one new thing the emulator did have to say is a handful of ACIA: data register written although data has not been sent yet. lines in its own log - section 8's last-but-one heading.


7. Limits of this measurement

  • VICE 3.7.1 only. No real SwiftLink, no real C64, no real cable.
  • The 2400-baud collapse is reproducible here but its cause is not proven. Three windows in run A and three in run B, two different ways of reaching the rate, same outcome; the stalled state and its cure are both directly observed; the event that creates the state is not. Since fixed: one of the two candidates was closed at its source and the state itself was made self-healing, and nine more windows at 2400 over three boots did not reproduce it - section 8.
  • Only 300 and 2400 were exercised. 1200, 4800, 9600, 19200 and 38400 remain untested at any speed, in warp or otherwise.
  • The measured throughput is the traffic this particular game state produced. At 300 baud that happened to be more than the line could carry, which is what makes "the throughput equals the line rate" a meaningful statement; a quieter game state (the reconnect prompt, section 4's last paragraph) puts zero bytes on the wire at any rate.
  • The relay can in principle drop data. The forwarding sockets are non-blocking, and a chunk that cannot be written because the destination's buffer is full is discarded rather than queued. At 30 to 240 bytes/s against a kernel socket buffer of tens of kilobytes this should never happen, and the clean 55-second saturated run at 300 baud is evidence that it did not, but it was not instrumented.
  • The cycle-count check has a known +0.5 to +0.9% bias, explained in section 1; it is a floor test ("did this machine keep up"), not a precision clock.
  • The stopped-emulator hazard is real and had to be engineered around. An early version of this script left one emulator sitting at the monitor prompt for a whole 75-second window (17099 emulated cycles against 75 seconds of wall clock). viceHarness.mon() returns as soon as it sees a prompt, which is often the previous command's, so a command can be sent into a monitor that has not finished the last one. testRealtime.py therefore reads to quiescence instead, verifies every resume, and discards any window in which either machine ran at under 90% of real time. Anything else built on this harness should do the same.

8. After the fix: the same rig, the same rate, no deadlock

Measured 2026-08-22, same script, same socket null modem, same true-speed method as sections 1 to 3, against a disk rebuilt from the current source with ./build.sh. checkAbi.py on that image prints ABI CHECK PASSED with 452 of 4096 bytes changed in 24 regions. Against the pre-fix build the only addresses that changed are $E04C-$E054 and $E057-$E05E - seventeen bytes of dead stock-UART constants (dtrToggleMask, userPortDdrbValue, userPortDtrDropped, userPortIdleTable, serialShiftPatternTable and its 1200-baud answer entry, bitPeriodHi, txPaceReload and the old baudParameterTable, none of them read since the software UART was replaced; the two live bytes between them, baudIndex $E055 and bitPeriodLo $E056, are why it is two ranges and not one) - plus $E607, the first instruction of startNextTxChar, and two call sites inside ranges the SwiftLink build had already replaced. Nothing in the packet layer, the ring buffers, the modem state machine or the frame/ARQ layer moved.

Logs: testLogs/fixRun1.300then2400.txt, testLogs/fixRun2.2400first.txt, testLogs/fixRun3.2400first.txt; per-second byte counts in testLogs/realtime.f1.*.samples.txt and testLogs/realtime.f3.*.samples.txt; screenshots shots/rtf1*.png, shots/rtf2*.png, shots/rtf3*.png; the two emulator logs of run 3 in testLogs/fixRun3.[ab].vice.log.

The deadlock did not recur. Nine 75-second windows at 2400 baud over three boots - 675 seconds of measured link time - both ways of reaching the rate, and in every one of them both directions carried traffic in every single second. The state that defined the fault, txCharActive $E5BB non-zero while aciaCommandShadow $E5BE has bit 2 clear, was not seen once in 66 state readings. No $00 flood, no silent machine, and the script's deadlock probe - which writes $00 over $E5BB when it detects the state - never fired, so nothing in these numbers is the test rig repairing the driver.

What changed in the driver

Three sites, one idea: txCharActive $E5BB means "a byte of ours is sitting in the ACIA's transmit holding register" and nothing else, so it must never outlive the transmit interrupt that clears it.

Site What it does In the built image
aciaSetCommandIdle $E72A, called from the NMI's disarm at $E6E0 writes the command register and then clears txCharActive - closing the known path, where an inner NMI pass primes a byte and does INC txCharActive at $E6D9 while the outer pass finds the ring empty and writes command $09 $E6DE: A9 09 20 2A E7, $E72A: 20 51 E5 4C 4F E0
healStuckTransmitter $E057, now the first thing startNextTxChar $E607 does once a frame, whatever caused it: if the command shadow says the transmit interrupt is disarmed, clear txCharActive. Returns the same A the old LDA txCharActive did, so the caller is unchanged $E607: 20 57 E0 D0 56, $E057: AD BE E5 29 04 F0 F1 60
aciaSetControlIdle $E04C, called from loadBaudParameters $E35C a rate change forgets any byte the driver believed was in the chip, so a speed hot key that lands on a character in flight cannot strand the flag $E35C: 20 4C E0, $E04C: 20 67 E5 A9 00 8D BB E5 60

The first closes the one path that was traced; the second makes the whole class of paths recoverable, including any that were never identified; the third removes the rate change as a way in.

The three runs

testRealtime.py grew a window-count argument for this: a rate now gets several consecutive windows measured back to back, with a full state readback of both machines at every edge, and nothing is retried or discarded - a window that carried nothing would be reported as a result, not thrown away.

Run How 2400 was reached Windows
1 one 75 s window at the disk default 300 baud, then C= + 2 on both machines on the live link 1 x 300, then 3 x 2400
2 C= + 2 at the "PRESS A OR O" prompt, before the link was ever opened 3 x 2400 (the 300-baud window that was to follow was lost, see below)
3 the same as run 2, a second boot, then C= + 3 back to 300 on the live link 3 x 2400, then 1 x 300

Both machines were in the same game state throughout every window: machine A showing "OPPONENT PICKING GAME/MAP.", machine B sitting on the GAME TYPE menu with nobody pressing a key (shots/rtf103aAfterFirst.png, shots/rtf103bAfterFirst.png, shots/rtf303*.png). That is the state the side-0/side-1 negotiation ends in, and it is also the state the pre-fix runs died in.

Bytes each way, per window

conn0 is machine A (answer), conn1 is machine B (originate). "speed" is the emulator's own cycle counter over the window against the wall clock - the check that the measurement was made at true C64 speed.

Run Rate Window A -> B B -> A A speed B speed $E403 hits
1 300 1/1 2240 B = 29.81 B/s 2241 B = 29.82 B/s 101.0% 100.6% 0
1 2400 1/3 672 B = 8.94 B/s 672 B = 8.94 B/s 100.9% 100.5% 0
1 2400 2/3 672 B = 8.94 B/s 672 B = 8.94 B/s 101.0% 100.6% 0
1 2400 3/3 672 B = 8.94 B/s 672 B = 8.94 B/s 100.9% 100.5% 0
2 2400 1/3 675 B = 8.98 B/s 675 B = 8.98 B/s 101.0% 100.6% not tallied
2 2400 2/3 674 B = 8.97 B/s 675 B = 8.98 B/s 101.0% 100.5% not tallied
2 2400 3/3 675 B = 8.98 B/s 675 B = 8.98 B/s 100.9% 100.5% not tallied
3 2400 1/3 674 B = 8.97 B/s 675 B = 8.98 B/s 100.9% 100.5% 0
3 2400 2/3 675 B = 8.98 B/s 675 B = 8.98 B/s 100.9% 100.5% 0
3 2400 3/3 672 B = 8.94 B/s 672 B = 8.94 B/s 100.9% 100.5% 0
3 300 1/1 2211 B = 29.42 B/s 2150 B = 28.61 B/s 100.9% 100.5% 0

Compare the row the fault used to produce: conn0 0 bytes, conn1 4495 bytes = 59.81 B/s, every byte $00. Nothing resembling it appears above; the two directions differ by at most one byte per window at 2400.

Per-second sampling (testLogs/realtime.f*.samples.txt, one line per second per window):

  2400, all six windows that were sampled:   6 to 12 bytes/s each way, no second at zero
  300, run 1:                               27 to 31 bytes/s each way, no second at zero
  300, run 3 after C= + 3:                  27 to 31 bytes/s, one single second at zero on conn1

That one zero second is inside the byte-sync round the rate change costs; it is the only second in 825 seconds of measured link time where a direction carried nothing.

The state at every window edge

Read through the monitor with both emulators stopped, at the open of each series and at the close of each window: connectionPhase $E040, linkErrorCount $E047, uartPendingCount $E0A5, txCharActive $E5BB, aciaCommandShadow $E5BE, plus baudIndex $E055 and the ACIA control register $DE03.

Run 1 - 300 baud, then C= + 2 on the live link:

Edge A phase / err / pend / tx / cmd B phase / err / pend / tx / cmd $E055 / $DE03
open of the 300 series 2 / $00 / $01 / $01 / $05 2 / $00 / $01 / $01 / $05 0 / $15
close of 300 w1 2 / $00 / $01 / $01 / $05 2 / $00 / $03 / $01 / $05 0 / $15
open of the 2400 series 3 / $00 / $00 / $00 / $09 3 / $00 / $00 / $00 / $09 6 / $18
close of 2400 w1 3 / $00 / $00 / $00 / $09 3 / $00 / $00 / $00 / $09 6 / $18
close of 2400 w2 3 / $00 / $00 / $00 / $09 3 / $00 / $00 / $00 / $09 6 / $18
close of 2400 w3 3 / $00 / $00 / $00 / $09 2 / $00 / $00 / $00 / $09 6 / $18

Run 2 - 2400 selected at the A/O prompt:

Edge A phase / err / pend / tx / cmd B phase / err / pend / tx / cmd $E055 / $DE03
open of the 2400 series 2 / $00 / $00 / $00 / $09 2 / $00 / $00 / $00 / $09 6 / $18
close of 2400 w1 3 / $00 / $00 / $00 / $09 3 / $00 / $03 / $01 / $05 6 / $18
close of 2400 w2 3 / $00 / $00 / $00 / $09 3 / $00 / $03 / $01 / $05 6 / $18
close of 2400 w3 3 / $00 / $00 / $00 / $09 2 / $00 / $00 / $00 / $09 6 / $18

Run 3 - 2400 selected at the A/O prompt, then C= + 3 back to 300:

Edge A phase / err / pend / tx / cmd B phase / err / pend / tx / cmd $E055 / $DE03
open of the 2400 series 3 / $00 / $00 / $00 / $09 3 / $00 / $00 / $00 / $09 6 / $18
close of 2400 w1 3 / $00 / $00 / $00 / $09 3 / $00 / $00 / $00 / $09 6 / $18
close of 2400 w2 3 / $00 / $00 / $00 / $09 3 / $00 / $00 / $00 / $09 6 / $18
close of 2400 w3 3 / $00 / $00 / $00 / $09 2 / $00 / $02 / $01 / $05 6 / $18
open of the 300 series 3 / $00 / $03 / $01 / $05 2 / $00 / $01 / $01 / $05 0 / $15
close of 300 w1 2 / $00 / $01 / $01 / $05 2 / $00 / $02 / $01 / $05 0 / $15

linkErrorCount $E047 read $00 at every edge of every window on both machines, and the countLinkError $E403 tracepoint recorded zero hits in each of the seven windows where it was tallied. isLinkActive $E03B was $01 at every edge. connectionPhase moves between 3 and 2 as the link drops in and out of a byte-sync round, exactly as it did in the healthy 300-baud run of section 3; what never happened again is a machine stuck in one phase with a dead transmitter.

The pair that defines the fault never occurred. Across all 66 state readings in the three runs:

txCharActive aciaCommandShadow Readings Meaning
$00 $00 4 before the ACIA was ever programmed (phase 0, at the A/O prompt)
$00 $09 42 idle: transmit interrupt disarmed and nothing believed to be in the chip
$01 $05 20 busy: transmit interrupt armed and a byte of ours in the chip
$01 $09 0 the deadlock - never seen

Only the two self-consistent pairs ever appear, which is precisely the invariant the three fix sites were put in to hold.

Throughput, honestly

2400 baud is not throughput limited by the driver here, and it never reached the byte-sync ceiling. 8.9-9.0 bytes/s is what these two games had to say to each other in that game state: the wire carried about 250 $55 frame lead bytes per direction per window (roughly 3.4 ARQ frames a second each way) and no run of eight or more $00 at all, so this is the real frame layer ticking over, not a resync flood. The line could carry 240 bytes/s and the link layer would cap a flood at one byte per video frame, 59.8 bytes/s - section 4's measurement of that ceiling still stands, and nothing in these runs approached either limit. Neither machine had a backlog: uartPendingCount $E0A5 read $00 at most edges and never above $04.

300 baud still saturates. Run 1's 300-baud window ran at 29.81 and 29.82 bytes/s for the whole 75 seconds, with no one-second bucket below 27 or above 31. 8N1 costs ten bits a byte, so 30.0 bytes/s is exactly 300 baud, and this is a better result than the pre-fix run in section 3, which averaged 23.9 and 24.1 because the traffic ran out at t=56 s. Run 3's 300-baud window, reached by pressing C= + 3 on a live 2400-baud link, came back at 29.42 and 28.61 bytes/s after one resync round (a 57-byte and an 18-byte run of $00 in the two directions). That is also a change from the pre-fix run B, where dropping back to 300 left both games at "PICK UP PHONE THEN PRESS SPACE." with nothing to send; here the game survived the rate change in both directions and kept playing.

What went wrong in the rig, and what it cost

  • Run 2 ended in a BrokenPipeError on machine B's monitor socket, during the state readback that follows the switch back to 300 baud - after all three 2400-baud windows had completed and been reported. The three windows and their edge states are in the log and are used above; what was lost is run 2's 300-baud window and its per-window tracepoint tallies, which that version of the script only counted in the closing summary. testRealtime.py now writes each window's samples and trace as the window closes, and run 3 - a second boot of exactly the same 2400-first sequence - was run to replace what run 2 could not report. Nothing in the emulator log explains the socket closing.
  • VICE logged a handful of Acia1: ACIA: data register written although data has not been sent yet. - 1 on A and 2 on B in run 2, 1 on A and 6 on B in run 3, in runs lasting a quarter of an hour each. VICE raises that when the data register is written before the previous byte has been handed to the line, i.e. one transmitted character is overwritten and lost; the ARQ layer above recovers such a byte with a checksum failure and a retransmit. It is plausible they cluster on the control-register writes (each link open and each speed hot key calls loadBaudParameters, which now clears txCharActive deliberately, and run 3's machine B saw about that many such writes), but the correlation was not measured - pinning it down needs a tracepoint on the writes, which stops the emulator. It cannot be compared with the pre-fix driver either, because those runs' emulator logs were overwritten by these. What can be said: no receiver at either end counted a single framing, parity or overrun error in any window, and no window lost the link.

What these runs do not show

  • They are still VICE 3.7.1, byte-level ACIA, no real SwiftLink and no real cable.
  • The 2400-baud windows were quiet ones. Nine bytes a second exercises the transmitter's arm/disarm path a few thousand times per machine - the disarm at $E6DE runs once per frame sent, so roughly 250 times per window per machine - but it does not load the line. The pre-fix fault did appear in exactly this game state, in windows measured the same way, which is what makes the comparison fair; it has not been retested under a saturated 2400-baud link, because nothing in this game state produces one.
  • Only 300 and 2400. 1200, 4800, 9600, 19200 and 38400 are still untested at any speed.
  • No complete game. Same as before: the machines reach the GAME TYPE menu and stay there.
  • The fix is proven by absence over 675 seconds at the rate that used to fail within twenty, not by a proof that no path into the state remains. healStuckTransmitter makes any such path self-healing within one video frame rather than fatal, which is the stronger of the two claims that can be made from a test like this.

9. Files

File What it is
testRealtime.py the test: two machines at true speed, windowed byte counting, cycle-counter check, error tracepoint, hot-key rate selection, deadlock probe. Takes <disk> [windowSeconds] [firstRate] [tag] [firstWindows] [secondWindows]; a series of consecutive windows retries nothing and reads both machines' state at every edge
testLogs/realtimeRun300first.txt before the fix, run A - 300 baud first, then C=+2 to 2400 on a live link
testLogs/realtimeRun2400first.txt before the fix, run B - 2400 selected at the A/O prompt, then C=+3 back to 300
testLogs/realtime.a.run300.samples.txt per-second byte counts, both directions, run A at 300 baud
testLogs/realtime.a.run2400.samples.txt the same for run A at 2400 baud
testLogs/realtime.b.run2400.samples.txt run B at 2400 baud
testLogs/realtime.b.run300.samples.txt run B back at 300 baud
testLogs/fixRun1.300then2400.txt after the fix, run 1 - one 300-baud window, then C=+2 on the live link and three 2400-baud windows
testLogs/fixRun2.2400first.txt after the fix, run 2 - C=+2 at the A/O prompt, three 2400-baud windows, then a broken monitor socket
testLogs/fixRun3.2400first.txt after the fix, run 3 - the same as run 2 on a second boot, then C=+3 back to 300 for one more window
testLogs/realtime.f1.*.samples.txt, testLogs/realtime.f3.*.samples.txt per-second byte counts for every post-fix window
testLogs/fixRun3.[ab].vice.log the two emulators' own logs from run 3, with VICE's Sync reset chatter stripped
shots/rt0*.png, shots/rtb0*.png before the fix: the menu, the linked pair, and the end of each window
shots/rtf1*.png, shots/rtf2*.png, shots/rtf3*.png after the fix: the same points in runs 1, 2 and 3 - run 2 has no 04 pair because it never reached the end of its second series