Skip to content

UCI command routine: two handshake races found in c64-test-harness #230

Closed

Description

@JC-000

c64-test-harness found two handshake races in its own UCI command routines and has fixed one of them. The same two shapes appear in this repo's UCI adapter, src/net/uci/uci_cmd.s and src/net/uci/net.s at 1b9b49e.

Evidence grade: source-read in c64-https; not run there. The mechanisms and the measurements come from c64-test-harness on a U64E. Nothing below has been run against this repo's code. No code change is proposed here.


(a) The command is written before the firmware has taken the opening ABORT

Mechanism

Writing ABORT ($04) to $DF1C only sets a pending flag, which reads back as bit 2 of $DF1C. The firmware services it later, from its command task, with HANDSHAKE_RESET. That write also resets the command pointer and forces the state to idle.

So any command byte written before HANDSHAKE_RESET lands is lost, and the firmware parses whatever is left of the command. The harness saw three results of this:

  • target 5 with an unknown command, status "\x04";
  • 21,UNKNOWN COMMAND;
  • no reply and no status at all ("Null command.").

The idle wait does not cover this. The pending abort does not show in STATE or in bit 0, so a $31 idle check can pass while the reset is still pending.

The fix in #476 polls $DF1C until bit 2 clears after the ABORT, instead of running a fixed delay.

Firmware source

software/io/command_interface/command_intf.cc:

  • at bce4535e (U64E v3.15-132): lines 136-143;
  • at 1.1.0 (C64U): lines 121-128, the same code.
136: 		if(status_byte & CMD_ABORT_DATA) {
 ...
142: 			CMD_IF_HANDSHAKE_OUT = HANDSHAKE_RESET;
143: 			CMD_IF_IRQMASK_CLEAR = CMD_ABORT_DATA;

The same shape here

uci_abort follows the ABORT with a fixed spin (src/net/uci/uci_cmd.s):

69: uci_abort:
70:         lda #UCI_CTRL_ABORT
71:         sta UCI_CONTROL
72:         uci_fence
73:         ldx #$20
74: @spin:
75:         dex
76:         bne @spin

The next command starts with uci_wait_idle, which waits on STATE and bit 0 only (uci_cmd.s:178-181):

179:         lda UCI_STATUS
180:         uci_fence                   ; settle read before testing bits
181:         and #(UCI_STAT_STATE | UCI_STAT_CMD_BUSY)   ; $31

uci_regs.inc defines no bit-2 status flag, and nothing in uci_cmd.s or net.s waits for one. Two paths lead from the ABORT to the next command write:

  • Init: net.s:110 jsr uci_abort, then the ID read, then the first DHCP probe at net.s:480 jsr uci_wait_idle / :484 jsr uci_begin_cmd.
  • The @sb_bail recovery: net.s:893-894 jsr uci_abort / jsr uci_wait_idle, with the next command's own uci_wait_idle before its uci_begin_cmd.

The harness routines had the same shape before #476: ABORT, a fixed delay, a $31 idle wait, then the target byte.

Measured in the harness (U64E, fw bce4535e, 2026-09-23, 48 MHz, paired and interleaved, n=10 per arm)

From JC-000/c64-test-harness#419 (comment):

master (with #476) pre-#476
first socket_write reached the host 10/10 4/10
uci_get_ip returned the IP 10/10 3/10
instrument control received 10/10 10/10

An earlier mechanism run (n=20 per arm) failed 8/20 on master against 0/20 with the bit-2 wait, and 0/20 at 1 MHz. $DF1C bit 2 was set just before the target byte in every failure and in none of the passes.


(b) The routine waits on $DF1C bit 0 after the PUSH, which clears before the reply is valid

Mechanism

$DF1C bit 0, which both code bases call CMD_BUSY, is the new-command flag, handshake_in(0) (command_protocol.vhd:85-89 at bce4535e). The firmware clears it with HANDSHAKE_ACCEPT_COMMAND before copy_result copies the reply and status and writes VALIDATE.

In between, STATE reads 01, and both DATA_AV and STAT_AV read low. A drain that checks DATA_AV once in that window stores nothing. The status becomes valid a few instructions later and reads 00,OK. The window is the copy_result memcpy, so a longer reply widens it.

#490 waits instead for STATE bit 5 (reply valid) or the error bit ($28). The error bit is included because a PUSH while not idle sets only the error bit.

Firmware source

software/io/command_interface/command_intf.cc at bce4535e, lines 164-177:

167:                 command_targets[target]->parse_command(&incoming_command, &data, &status);
168: 
169:                 CMD_IF_HANDSHAKE_OUT = HANDSHAKE_ACCEPT_COMMAND; // clears CMD_NEW_COMMAND
170:                 if (no_reply) {
171:                     CMD_IF_HANDSHAKE_OUT = HANDSHAKE_RESET; // forces state to 00
172:                 } else {
173:                     copy_result(data, status); // sets state to 10 or 11
174:                 }

VALIDATE is written inside copy_result, at :202-204. The ordering is the same at 1.1.0: ACCEPT at :154, copy_result at :158, VALIDATE at :187-189.

The same shape here

uci_push_wait runs a fixed settle delay, then waits on bit 0 alone (uci_cmd.s:289-302, :228-231):

289: uci_push_wait:
290:         lda #UCI_CTRL_PUSH_CMD
291:         sta UCI_CONTROL
292:         uci_fence
 ...
298:         ldx #$FF
299: @pw_settle:
300:         dex
301:         bne @pw_settle
302:         jmp uci_wait_not_busy

228: @wnb_loop:
229:         lda UCI_STATUS
230:         uci_fence                   ; settle read before testing bits
231:         and #UCI_STAT_CMD_BUSY

Where it matters most: net_poll's SOCKET_READ. After jsr uci_push_wait at net.s:233 and uci_check_err, the header read checks DATA_AV per byte with one fence before it. If DATA_AV is clear, it takes the "no data" exit, which drains and ACKs (net.s:266-273, :285-290):

266:         uci_fence             ; give firmware time to stage response
267:         ldy #$00
268: @hdr_loop:
269:         lda UCI_STATUS
270:         uci_fence                   ; settle before testing DATA_AV
271:         and #UCI_STAT_DATA_AV
272:         bne @hdr_got                ; branch past trampoline
273:         jmp @hdr_done_short         ; long branch: fence too wide for BEQ
 ...
285: @hdr_done_short:
286:         ; Firmware returned fewer than 2 bytes. Treat as "no data".
287:         jsr uci_drain_resp

In the harness, a read that landed in the window consumed the datagram: a second read found 02,NO DATA.

The other push sites (DHCP probe, TCP connect, socket write) read their reply through uci_read_resp_bytes, which spins up to 16 bits on DATA_AV. That spin probably rides out the window for data. uci_drain_resp and uci_drain_status check their available bit once and return, so they are exposed the same way. None of this is measured here.

Measured in the harness (U64E, fw bce4535e, 2026-09-23, 1 MHz, 253-byte UDP reads, 4 arms interleaved, n=8 each)

From JC-000/c64-test-harness#486:

  • The first read was whole 16/16 with a wait for STATE bit 5 after the push/busy wait, against 5/16 with the stock bit-0 wait.
  • The host delay before the read made no difference (2/8 against 3/8).
  • On all 11 stock failures the first read drained 0, returned status 00,OK, and left $C200 untouched. The second read then got 02,NO DATA: 11.

Not established

  • Whether either race fires in c64-https in practice. Its fences, spin counts and read paths differ from the harness, and nothing here was run against this repo.
  • The C64U (fw 1.1.0) was not measured for either race. Its firmware ordering is source-read only.

Activity

  1. added a commit that references this issue on Sep 24, 2026
  2. JC-000 commented on Sep 24, 2026

    @JC-000
    OwnerAuthor

    Post-flash re-baseline (fw ef9937a7, core 1.50)

    Tree: origin/master 35ea3b9 (includes #232 #233 #238 #241 #244), submodules at their gitlinks (nistcurves c05ead66, x25519 16157a14, ip65 25a9c5aa).
    Device: U64E 10.43.23.81. /v1/info read once inside DeviceLock, 2026-09-24 ~16:43 CDT:
    product=Ultimate 64 Elite, firmware_version=3.15, git_commit_hash=ef9937a7, fpga_version=125, core_version=1.50, unique_id=601A96.

    Every HTTPS run went DeviceLock → prepare_device → preflight_reu. The turbo setting was already 48 MHz Manual, so no turbo write was made on any run. The REU was written Enabled/16 MB for the comb run only. /Temp GC ran in the banner rig and removed 0 files each time; the live rig calls gc_temp itself. Post-run values were read only after the sentinel fired (trampoline rigs) or after the rig saw a complete body (banner rig). Every fetch closed cleanly: the banner rig saw CONNECTION CLOSED after Q, and there was no reset over a live socket.

    # Rig Image (PRG sha256) n Outcome net_last_error Timing (core 1.50 baseline)
    1 boot_check.py uci-onchip, default target 10e614c9…a381baa7 1 PASS: banner, menu, DHCP OK, CIA1 TOD running n/a (rig does not read it) n/a
    2 rig_https_banner.py, menu path, en.wikipedia.org /wiki/Commodore_64, FETCH_TIMEOUT=900 uci-onchip HTTPS_HOST=en.wikipedia.org HTTPS_PATH=/wiki/Commodore_64 c7b24019…ca44a6d42 3 3/3 PASS: 751,154 B consumed == Content-Length (HTTP 200) on every run. Framing check, fetch-settled check and clean close all passed not read by this rig Rig start to lock release: 7m21s (65 s of that queued), 6m18s, 7m53s (95 s queued). The rig prints on a ~16 s cadence with no timestamps, so the next two figures are approximate: G to first body byte ~32-48 s, then ~2.3 KB/s (about 38 KB per print)
    3 rig_https_local.py, back to back, PHASE_TIMING=1 uci-onchip HTTPS_SNI=www.foo.invalid 8f8d5d43…89d04264 3 3/3 PASS: HELLO FROM TLS SERVER, HTTP 200, server-side criteria met. No PASS/$88 alternation: all three consecutive runs passed $00 ×3 CH +6.4 s; GOT2 +19.7 / +20.4 / +20.4 s; CFIN +47.5 / +47.7 / +47.8 s; sentinel 48.6 / 48.2 / 48.3 s
    4a rig_https_live.py github.com uci-onchip default 10e614c9…a381baa7 2 2/2 PASS: HTTP 200 $00 ×2 CH +6.4 s; GOT2 +20.4 s; CFIN +49.0 / +48.9 s; sentinel 108.8 / 68.2 s
    4b rig_https_live.py lwn.net same 1 PASS: HTTP 200 $00 CH +6.5 s; GOT2 +22.1 s; CFIN +48.5 s; sentinel 62.5 s
    5 rig_https_banner.py comb, C64_INIT_WAIT=120, FETCH_TIMEOUT=900 uci-comb (ld65 -C cfg/c64-https-uci-onchip.cfg) wikipedia target 85d0413a…aa340b0102f 1 PASS: boot precompute reached the menu inside 120 s, DHCP OK, 751,154 B == Content-Length, HTTP 200, clean close not read by this rig Rig total 6m50s with no lock wait. G to complete body used 19 poll prints against 23 on onchip, so roughly 60 s less wall time. Approximate only, for the same cadence reason as row 2

    All 11 runs were at 48 MHz. Clock-sensitive figures are labelled as the core 1.50 baseline and deliberately not compared with pre-flash numbers.

    Findings

    🤖 Generated with Claude Code

  3. JC-000 commented on Sep 25, 2026

    @JC-000
    OwnerAuthor

    Resting-image smoke (c47155b7 = ef9937a7 + #835)

    Tree: origin/master 742e0b1, submodules at their gitlinks (nistcurves c05ead66, x25519 16157a14, ip65 25a9c5aa). This is later than the re-baseline's 35ea3b9: it adds #240 (AEAD fail-closed, which touches TLS code) and #236 (tooling only). So every PRG hash below differs from the re-baseline's. That comparison therefore varies both the firmware and the image, not the firmware alone.

    Device: U64E 10.43.23.81. /v1/info read once inside DeviceLock, 2026-09-24 22:01 CDT:
    product=Ultimate 64 Elite, firmware_version=3.15, git_commit_hash=c47155b7, fpga_version=125, core_version=1.50, unique_id=601A96.

    Every run went DeviceLock → prepare_device → preflight_reu. The device came up reset (Turbo Off / 1 MHz, REU Disabled). The first run wrote turbo 48 MHz Manual and every later run found it already set. The REU was written Enabled/16 MB for the comb run only. Post-run values were read only after the sentinel fired (trampoline rigs) or after the rig saw a complete body (banner rig). Every banner fetch closed cleanly (CONNECTION CLOSED after Q), and there was no reset over a live socket.

    # Rig Image (PRG sha256) n Outcome net_last_error Key timings (48 MHz)
    1 rig_https_local.py, back to back, PHASE_TIMING=1 uci-onchip HTTPS_SNI=www.foo.invalid 505f4078…f0dfaabb 3 3/3 PASS: HELLO FROM TLS SERVER, HTTP 200, http_get carry=0. No PASS/$88 alternation $00 ×3 CH +6.5 / +7.1 / +6.5 s; GOT2 +20.2 / +19.9 / +20.0 s; CFIN +47.1 / +47.3 / +46.8 s; sentinel 48.1 / 48.4 / 47.9 s (baseline: CFIN ~47.5-47.8, sentinel ~48.2-48.6)
    2 rig_https_banner.py, menu path, en.wikipedia.org /wiki/Commodore_64, FETCH_TIMEOUT=900 uci-onchip wikipedia target 748c8bdd…b03d1ed9 2 2/2 PASS: 751,154 B consumed == Content-Length, HTTP 200. Framing, fetch-settled, shadow-RAM and clean-close checks all passed not read by this rig Rig start to lock release 6m18s / 6m18s, no lock wait. 23 poll prints each (baseline onchip: 23)
    3 rig_https_live.py github.com uci-onchip default target ea3e8857…13d90983 1 (+2 follow-ups, see findings) 3/3 PASS: HTTP 200, carry=0 $00 ×3 CH +6.4 / +6.4 / +6.6 s; GOT2 +20.4 / +20.3 / +20.8 s; CFIN +48.8 / +49.3 / +48.5 s; sentinel 277.4 / 112.6 / 107.9 s (baseline: 108.8 / 68.2)
    4 rig_https_banner.py comb, C64_INIT_WAIT=120, FETCH_TIMEOUT=900 uci-comb (ld65 -C cfg/c64-https-uci-onchip.cfg) wikipedia target 82c6ecce…3e0aaa06 1 PASS: boot precompute reached the menu inside 120 s, DHCP OK, 751,154 B == Content-Length, HTTP 200, clean close not read by this rig Rig total 6m53s (baseline 6m50s). 23 poll prints (baseline comb: 19). These are cadence-based figures, so they are not a timing measurement

    Full hashes: 505f40788f5e8963968f358d3de50f0c7d236ad74412fdf305f07159f0dfaabb (sni), 748c8bdd6d3419e3d8b59d18aeb00460bc8d1d90b03a3958e30c4b71b03d1ed9 (onchip wiki), ea3e8857d5cfd9aafff278c463a28df26c3abcca2b88b44e229cc5fb13d90983 (onchip default), 82c6ecce38b55cdaf370b7fdb68842991686a5369e60984040704a323e0aaa06 (comb wiki).

    Findings

    • Nothing failed, and nothing failed in a new way. No $86/$88/$89: net_last_error was $00 on all 6 trampoline runs. No stalls and no short bodies: all 3 wikipedia fetches (2 onchip + 1 comb) completed to Content-Length through the menu path.
    • The handshake timings match the ef9937a7 baseline to within a few tenths of a second (CH, GOT2 and CFIN on both the local and github rigs).
    • One github.com outlier: on the first run, CFIN to sentinel took ~229 s against ~19-60 s in the re-baseline. CFIN itself was on time and the result was PASS / carry=0 / $00. net_tcp_state=$00, tls_state=$00 and tls_last_state=$00 at the dump. Two follow-up runs of the same image came in at 112.6 s and 107.9 s, which is inside the re-baseline's spread (68.2-108.8 s). So it is recorded as a run-to-run outlier in the post-handshake GET/drain, n=1. It is not attributed to #835 or to tls: fail closed on AEAD tag failure instead of polling on (#239) #240. The body size is not captured by this rig, so server-side page-size variation cannot be excluded. Snapshots are in /tmp/uci_https_live_debug/20260924_221902/ on the host.
    • Instrument note: rig_https_local.py runs 1 and 2 logged 240 and 611 debug-stream packet gaps (run 3: 2; baseline: 0/3/1). This is host-side capture loss, and the verdicts do not depend on that stream.
    • The device was left with REU Enabled/16 MB and turbo 48 MHz Manual, both runtime-only.

    🤖 Generated with Claude Code

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions