Repository navigation
Intermittent UCI handshake stall after a good connect: tls_state=3, read_seq=0, ~707 B consumed, ring empty, net_last_error=$00 #242
Description
Seen twice while measuring PR #238 and PR #241 on the U64E at 48 MHz. Cause not established.
Signature (identical in both runs)
- TCP_CONNECT succeeds (e.g. socket 6), and the plaintext ServerHello is processed.
- The run stalls with `tls_state=3` (waiting for EncryptedExtensions), `tls_read_seq=0`, about 706–707 B consumed, the TCP ring empty, and `net_last_error=$00`.
- The screen shows `…KEYS ENC1 RX`, with no GOT2.
- In the fix(uci): wait for the reply to be valid, not for CMD_BUSY to clear (#230 b, #211) #238 run (B3) the ring dump was intact and contiguous through SH, CCS, EE and the Certificate header. That is consistent with the first encrypted record failing AEAD, not with a missing read. On master that is a silent hang, because an AEAD failure is retried as "incomplete"; tls: fail closed on AEAD tag failure instead of polling on (#239) #240 makes it fail closed.
Runs
| Lane | Image | Run |
|---|---|---|
| #238 A/B, B arm | `97f1aa98…` (#238, before CLR_ERR) | B3, port 4433, trampoline ABORT before connect |
| #241 A/B, B arm | `587b068a…` (#241 on #238) | run 3, port 443 |
That is 2 of 27 runs on images carrying #238's change, against 0 of 21 control runs. One-sided Fisher p ≈ 0.31, so not evidence that #238 causes it.
Not the known REU trap
Both images are onchip (no REU row-fetch DMA), so CLAUDE.md's "REU-profile build on a REU-less device" cause of the same screen does not apply. `net_last_error=$00` rules out a `$86` wedge.
Next steps
- Once tls: fail closed on AEAD tag failure instead of polling on (#239) #240 lands, a repeat should fail closed with sub-progress `$0B` (AEAD) or `$0C` (framing) instead of hanging, which says which one it is.
- Capture `tls_rec_buf`, the handshake keys, and the transcript hash at the stall, and check them against a host-side decrypt of the captured ring bytes.
- Candidates, none measured: a transcript mismatch (wrong bytes folded into the hash, e.g. a CCS or a duplicate), a corrupted key derivation, or one byte flipped in the ring.
🤖 Generated with Claude Code
Activity
JC-000 commentedon Sep 24, 2026
Update from the PR #241 adversarial review (ring dump parsed, not re-run). In the #241 B run, the ring holds the entire server flight, and all of it was consumed: SH 95 + CCS 6 + EE 55 + Cert 392 + CV 101 + Finished 58 (header
17 03 03 00 35) = 707 B, with head == tail. The client stalled right after consuming the Finished record's header, withsub_progress=$02where passing runs reach$0A. #238's B3 shows the same state, with a certificate 1 B shorter (706 B). So this is a client-side stall in the deframer/TLS path after the whole flight arrived, not network loss and not a connect/abort problem. That points away fromnet_polland towardtls_deframe.sand the handshake state machine.JC-000 commentedon Sep 24, 2026
Another occurrence, on the shipped menu path (
do_https_get), capturedA third hit, on a different image and a different path from the two in the issue body. Hardware-runner lane, 2026-09-24 07:40 CDT, U64E 48 MHz.
3677c4a,make BACKEND=uci USE_NISTCURVES_ONCHIP=1 HTTPS_HOST=en.wikipedia.org HTTPS_PATH=/wiki/Commodore_64, PRG sha2562596bd347380d56d3f976ace96c0f26d6a983e2461de2f01e6bb8d00053aa2d4. This is onchip, with no REU used (LIB_NISTCURVES_REU_BANKS_USED=0, device REU Disabled).tools/uci/rig_https_banner.py(menu 'I', then 'G'). It went through the realdo_https_get, not the trampoline, against the real en.wikipedia.org:443. That was run 1 of 5; runs 2-5 on the same image completed 751,225 B bodies.HTTPS GET EN.WIKIPEDIA.ORG... / DNS OK / TCP CONNECTED / CH / SH / HK1 / KEYS / ENC1 / RX / TLS HANDSHAKE FAILED.Timeline (from
net_tcp_statereads, an observation wrapper around the unmodified rig)net_tcp_state=$01CONNECTED from about t=9 s through at least t=455 s after 'G'.body_total=0andparse_state=0throughout.net_tcp_state=$00CLOSED. The handshake then failed out and returned to the menu ("TLS HANDSHAKE FAILED"). So on fix(uci): wait for ABORT's reset; abort on every connect/close timeout (#230 a, #221) [stacked on #238] #241 this is not a permanent hang: the connection ended roughly 470 s in. Most likely the server gave up; the fix(uci): wait for ABORT's reset; abort on every connect/close timeout (#230 a, #221) [stacked on #238] #241 close path then ran.Captured state (read-only DMA reads at 07:49, after the failure;
$A000proven RAM:5a5a6d84…, not ROM)tls_state$A24D$FFtls_last_state$A24E$03(waiting for EncryptedExtensions)tls_read_seq$A40B00 00 00 00 00 00 00 00tls_recv_progress/_sub_progress$A24F/$A250$05/$02tcp_recv_head/tail$A244/$A246$0233/$0233(ring empty)tcp_recv_overflow$A248$00net_last_error$B3BE$00net_tcp_state$B3BF$00CLOSEDtls_rec_header$A41317 03 03 00 35tls_recv_state/count$174C/$174D$00/$0000df_last_err$3B79$00df_mode,df_hdr,df_hdr_have,df_msg_rem,df_rec_off$3B66…00,00000000,00,0000,005a(LE$5A00)uci_socket_id$6852$07How this differs from the issue body: here the client consumed the whole server flight, well past 707 B. The 4 KB ring at
$C000has wrapped: the head is at$0233, so at least 4,096 + 563 B arrived. Walking record headers backwards from the head gives a clean chain ending exactly at the head:53 B is the size of a Finished record (32 + 1 + 4 + 16). The SH/CCS/EE bytes at the start of the flight were overwritten when the ring wrapped. So
tls_read_seqstayed at 0 while every encrypted record of the flight was read out of the ring. No record ever decrypted, and the state machine never left WAIT_EE. That fits "the first encrypted record fails AEAD, and on a pre-#240 image the failure is retried as incomplete", with the retry walking on through the rest of the flight. It does not fit a missing read. #241 does not include #240, so this image still has the silent-retry behaviour.Full buffers follow (hex, 32 B per line). The ring file's sha256 is
528969de8fbd4a9485331b912113ab2fe0d79f5a60fc97b1824ce7636cf63dfa. No handshake keys or transcript hash were captured, because I did not have their labels in this pass.tcp_recv_buf $C000-$CFFF (4,096 B)
tls_rec_buf $A000 (548 B)
$A200-$A4FF (ring pointers, tls_state, tls_read_seq, tls_rec_header ...)
deframer state $3B66 (64 B)
🤖 Generated with Claude Code
JC-000 commentedon Sep 24, 2026
Root cause found offline: an X25519 field-arithmetic carry bug that sends the wrong key_share
The handshake keys are fine and the deframer is fine. The ClientHello's X25519 public key does not match the private key. The cause is a dropped carry in
fe_reduce_wide(src/crypto/fe25519.s, grep@prop2:). It has been in that file since the first handshake commit, so it is on master and in all three shipped products. #238 and #241 do not cause it. The fix is in PR #244.From hw-runner's capture (PRG
2596bd34…, which I rebuilt byte-identically from #241 head3677c4a)tls_ecdhe_pubkey=eca6f47c…, but X25519(tls_ecdhe_privkey, 9) =c689799c…. Mismatch.tls_shared_secret= X25519(priv,tls_server_pubkey). Correct.tls_transcript) reproduces the captured early secret, handshake secret, and all four handshake key/IV buffers. The key schedule is correct.tls_transcriptonly when the ClientHello carrieseca6f47c…. That is the key that went on the wire.$C15063,$C19496,$C1F953, 7× 529) decrypts under the captured server handshake key at any sequence number from 0 to 63.So the server derived its keys from a public key the client holds no private key for. EncryptedExtensions fails its tag. On this pre-#240 image, the failure is retried as "incomplete", and
tls_recv_recordhas already reset its state. The client walks the rest of the flight, every record failing withread_seqstuck at 0. That is exactly thetls_state=3/sub_progress=$02/ empty-ring signature.Reproduced on the real PRG in VICE
tls_ecdh_generate_keypairon the captured private key, in image2596bd34…, outputs exactlyeca6f47c…. The failure is deterministic and depends on the scalar. There is no timing, network or hardware component.fe_mulat ladder bit 110 (CB = C*B), with got…225259000064against expected…22525a000064. The carry was lost past byte 2.@prop2ripples withlda / adc #0 / sta / bcc / inx / cpx #32 / bcc.cpxrewrites C, so from byte 3 on the loop adds 0.@prop3has the same defect. c64-x25519 found and fixed this pattern after its v0.1.0; the in-tree copy never received the fix.fe25519.swith the bug reproduceseca6f47c…bit-exactly. Across 2,000 random keygens it gives 1.3% wrong, so about 2.6% per handshake, since keygen and the shared secret are both exposed. The field shows ~3 in 51 runs; these are compatible, but n is small. I checked the model against the hardware code: 6 scalars it flags, plus the captured one, are 0/7 correct on unfixed master uci-onchip (fcbd8d19…) and 7/7 with the fix (8bb53057…).What this settles
net_poll, and fix(uci): wait for the reply to be valid, not for CMD_BUSY to clear (#230 b, #211) #238's read timing are all excluded for this capture. The bytes are good and the parse is good; the keys disagree with the server's. I did not run the chunk-split sweep, because this reproduction left nothing for it to explain.Reproducer
tools/test_x25519.py(on the fix branch) has two new groups that run by default:fe_reduce_wide carry (#242)andx25519 #242 captured keygen. On master they fail 4 of 77, and the keygen prints "= the key the U64E sent in #242". With the fix they pass 77/77, on ip65 and on uci-onchip.#240 is still worth landing. Any future key mismatch from another cause would otherwise be another ~470 s stall.
🤖 Generated with Claude Code
test(crypto): cover the byte-32 fe_mul_a24 fold entry; scope the CLAU…
Merge pull request #244 from JC-000/fix/242-fe-reduce-wide-carry
Link the libs/x25519 sibling on every profile; retire in-tree X25519 (#…