Skip to content

uci-m3 stage 2: READ 1472 B over a Data More continuation (measured: no gain; draft) - #297

Closed
JC-000 wants to merge 4 commits into
perf/uci-m3-read-pacingfrom
perf/uci-m3-read-1472
Closed

JC-000 wants to merge 4 commits into
perf/uci-m3-read-pacingfrom
perf/uci-m3-read-1472

Conversation

@JC-000

@JC-000 JC-000 commented Oct 14, 2026

Copy link
Copy Markdown
Owner

Stacked on #296 (base perf/uci-m3-read-pacing). It is stage 2 of the uci-m3 speed work. Measured result: no gain. Recommendation: do not merge unless the firmware's per-READ cost changes. The evidence and the code are here so that decision can be reviewed.

What

net_poll asks for min(ring free - 1, 1472) instead of 893. A reply over 893 B arrives as the first block plus one Data More continuation. The client does this:

  1. Reads the first block until DATA_AV is 0.
  2. Data-accepts it (write fence kept).
  3. Waits up to 12 s from that accept for REPLY_VALID.
  4. Copies on, then reads the status line and does the final accept.

The ER-5 protection still applies. Each of these is still treated as a hole:

  • Data More after a short first block (anything other than exactly 893 B).
  • A short continuation.
  • An over-long continuation.
  • A second Data More.
  • A continuation that never arrives: ABORT, $89, ERROR, then CLOSE.

M3_READ_ONE_BLOCK=1 keeps one-block READs and assembles #296's image byte for byte: 44648860 default target, 3b3685c9 for the REU-sink wiki build. M3_READ_FENCE=1 still assembles the pre-#296 client (f5d9278b / a3c67976).

Spec and firmware: verified before building

  • M3-SPEC v1 (c265fdfc), S:2012-2013: READ len is 1..1472, and "A READ reply longer than one block (the 2-byte header + 893 bytes) continues over Data More, exactly as for TCP".
  • Errata v1.1 (f9a39ff3):
    • ER-1 N-1: B bounds only the first block; each continuation is timed for 12 s from the data-accept of the block before it.
    • ER-5: read each block until bit 7 = 0 before you accept it.
  • Errata v1.2 (a6802f40) adds nothing on this.
  • Firmware 3a1ff9ff:
    • NET_MAX_SOCKET_READ 1472 (network_target.h:48).
    • start_read_reply (network_target.cc:483) sends the header plus up to NET_FIRST_BLOCK_PAYLOAD = 893 B. The status queue stays empty on intermediate blocks.
    • get_more_data (:756) sends payload only, up to 895 B, with the status only on the last block.
    • command_intf.cc:145-153: DATA_ACC on a Data More block calls get_more_data.
    • command_protocol.vhd: an accept on "11" drops the state to "01" until the Nios validates the next block.
  • Why it cannot help much: tls_read returns at most one engine step's plaintext. A step is at most 1024 B (NET_TLS_PT_MAX = TLS_STEP_OUT_MAX). On hardware, a 1472 B request returns 960 B, not 1472. The win is limited to removing the ~67 B tail READs, which cost about 1.2 ms each.

Model + mutation

Model changes in check_m3_client.py:

  • READ replies are now split into blocks the way the firmware splits them.
  • The status line rides only on the last block.
  • A continuation can be delayed.

Six new tests:

  • test_read_continues_over_data_more
  • test_continuation_after_short_block_is_a_hole
  • test_short_continuation_is_a_hole
  • test_long_continuation_is_a_hole
  • test_unowed_continuation_is_a_hole (also covers a second Data More after a short continuation)
  • test_continuation_timeout_aborts (taken at accept + 11 s; $89 + ABORT + CLOSE when it never comes)

On one-block images the continuation tests return early with no assertions. Those cases are not applicable there.

Results:

  • Default image 477e1f04: 58/58 passed.
  • M3_READ_ONE_BLOCK=1 (44648860): 58/58 passed.
  • M3_READ_FENCE=1 (f5d9278b): 58/58 passed.
  • REU-sink image: 59/59 passed.

mutate_m3_client.py: 77/77 killed. The new mutants and what they produced:

KILLED  more-never-taken       S:2013 a READ continues over Data More   the READ ended the connection (net_last_error $8F)
KILLED  more-after-short-block ER-5 a continuation only after a FULL block short first block: net_tcp_state $01, expected ERROR (ER-5)
KILLED  more-no-wait           wait for the continuation to be validated the READ ended the connection (net_last_error $8F)
KILLED  more-bound-short       ER-1 N-1: 12 s from the accept           a continuation at accept + 11 s was not taken (net_last_error $89)
KILLED  more-lost-not-89       a lost continuation is $89 + CLOSE       a continuation that never came: net_last_error $8F, expected $89
KILLED  request-893            READs ask for 1472 B (S:2012)            the READ asked for 893 B, expected 1472

I also wrote a "no second continuation" guard. It turned out to be equivalent: m3_blk_end stays 893, so a second Data More can never match it. I deleted it and gave the case a test instead of keeping dead code.

Other profiles are unchanged:

  • ip65-onchip e1ad289d
  • uci-onchip 375f9480
  • uci-comb 74a7d358
  • uci b4e4e6fb

Hardware: three arms

Setup:

page arm PRG n median (min-max) s
/robots.txt F: fenced, 893 (pre-#296) a3c67976 6 12.89 (12.38-13.31)
/robots.txt 1: unfenced, 893 (#296) 3b3685c9 6 5.50 (5.15-5.78)
/robots.txt 2: unfenced, 1472 (this) 0fa82383 3 5.06 (4.96-5.26)
/wiki/Commodore_64 F a3c67976 7 210.13 (208.73-218.37)
/wiki/Commodore_64 1 3b3685c9 8 18.97 (18.20-24.22)
/wiki/Commodore_64 2 0fa82383 5 18.98 (17.83-20.00)

Stage 2 makes no measurable difference on the large page (18.98 vs 18.97 s). The small page shows −0.4 s at n=3, inside the session-to-session spread.

Body oracles:

  • Every complete run is HTTP 200 with net_last_error $00.
  • robots.txt: every body is byte-equal to a host curl taken just before the run.
  • wiki: every complete body has CRC 9C298DA4 and differs from the fresh host render only inside the parser report.
  • The latest six attempts also logged the client's own verdict: "751,823 B consumed == Content-Length", with m3_eof_code 0.

Demo disk at this branch (PRG df0b1b9a, rig_https_m3_demo.py), n=1:

  • wiki: 18 s, complete.
  • github robots: 5 s.
  • The name-mismatch negative is still refused with 94.

Per-READ round trip (M3_TRACE, build 313412b4, wiki page, 879 READs, all recorded)

READ n RTT ms min / p10 / median / p90 / max whole net_poll, median
data (median 960 B, sum 758,254) 832 2.09 / 5.18 / 5.22 / 5.75 / 23.0 8.32 ms
of those, < 893 B 47 2.09 / 3.39 / 3.41 / 4.34 / 8.02 4.48 ms
idle 47 25.3 / 25.9 / 27.4 / 30.6 / 53.6 28.4 ms

READs per page fell from 1,666 to 879, but each 960 B READ costs the same ~5.2 ms to its first block that an 893 B READ did. Per-READ firmware time follows the engine step, not the command count. That is why removing about half the commands saved nothing: the time per command scaled with the payload.

$DF1C bit 3 after every PUSH: 900 pushes on the large page, 57 on robots.txt. Never set.

Open finding (pre-existing, not caused by either PR)

1 of 7 fenced-arm (a3c67976, i.e. master's client code) large fetches entered the REU viewer at 360,448 of 751,823 B, with HTTP 200 and net_last_error $00 (22:04:55).

  • That body was a different render: it contains wgTestKitchenUserExperiments, so it was probably a cache miss.
  • It is byte-identical to the good renders for the first 1,876 B and ends mid-tag.
  • 360,448 = 0x58000.
  • That run did not record the framing, so I cannot say whether the server ended the response with a legitimate terminator (chunked 0 or a short Content-Length) or the client misjudged it. The rig now records the client's framing verdict and m3_eof_code on every attempt.
  • A model fuzz of chunk-size lines split across READs (12 split points) found nothing.
  • Unattributed. The shared http.s verdict is the same code in all three arms.

🤖 Generated with Claude Code

JC-000 and others added 4 commits October 14, 2026 00:24
M3-SPEC v1 S:2012-2013 allows READ len 1..1472, with a reply over 893 B
continuing over Data More "exactly as for TCP"; errata v1.1 ER-1 (N-1)
bounds each continuation by 12 s from its data-accept, and ER-5 requires
each block read to its end first. Firmware 3a1ff9ff: NET_MAX_SOCKET_READ
1472; start_read_reply sends the header + 893, get_more_data the rest
(payload only, <= 895), the status line only with the last block.

net_poll now asks for min(ring free - 1, 1472). When the first block is
read to its end, the header still owes bytes, the state is "11", and
exactly 893 bytes have arrived, it data-accepts (m3_next_block: write
fence kept, then waits for REPLY_VALID up to 12 s from the accept) and
copies on. Anything else is still a hole: Data More after a short block,
a short or over-long continuation, a second Data More, a continuation
that never comes ($89, ABORT, CLOSE).

M3_READ_ONE_BLOCK=1 (and M3_READ_FENCE=1) keep one-block READs and
assemble the previous images byte for byte (44648860 / f5d9278b).

Model: READ replies are blocked as the firmware blocks them, the status
rides the last block, and a continuation can be delayed. Six new tests;
seven new mutants, all killed (77/77).

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
…de per attempt

A pre-change (M3_READ_FENCE=1) large fetch entered the viewer at 360,448
of 751,823 B with net_last_error $00; the run did not keep the framing
facts that would say whether the client or the server ended it.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
…D image

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
…y set-up

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
@JC-000
JC-000 force-pushed the perf/uci-m3-read-1472 branch from 5f5fd03 to b23d405 Compare October 14, 2026 05:28
@JC-000

JC-000 commented Oct 14, 2026

Copy link
Copy Markdown
Owner Author

Closing without merging. #296 has landed.

Result. Asking for 1472 B per SOCKET_READ (the firmware's NET_MAX_SOCKET_READ) instead of our 893 B cap made no measurable difference on the U64E at 48 MHz. The Wikipedia demo took 18.98 s here, against 19.19 s for #296 in the same session.

Why. The ESP32 side hands over at most one TLS engine step per read. NET_TLS_PT_MAX = TLS_STEP_OUT_MAX = 1024, which is about 960 B of plaintext. The cap underneath that is the UART RPC CMD_BUF_SIZE. A larger client request therefore never receives more than one step's worth.

Worth revisiting if the firmware changes. A change in 1541ultimate could lift this ceiling. Two options were discussed with the firmware side:

  • larger TLS steps (a bigger RPC buffer);
  • multi-step prefetch on the Nios side, so that one SOCKET_READ can return several steps.

If either lands, this branch (perf/uci-m3-read-1472, head b23d405) is the client half to re-measure. Until then, the per-read round trip sets the floor, and the client cannot move it.

@JC-000 JC-000 closed this Oct 14, 2026
@JC-000
JC-000 deleted the perf/uci-m3-read-1472 branch October 15, 2026 14:39
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant