flaky (io_uring): tls_segmented_recv_reassembles_and_eofs hangs — server stops echoing mid 100 KiB TLS message

[brayniac]

Summary

tls_segmented_recv_reassembles_and_eofs hangs a large fraction of runs on
io_uring. The server stops echoing part-way through a 100 KiB TLS message and
never resumes; the test then waits forever.

It is long-standing — reproduced on every sha tested, including before
#415 — and it is not a recent regression. It was invisible until now because
the test could not fail, only hang (see "Why this went unnoticed").

Repro

cargo test -p ringline --test tls_echo -- --test-threads=1

--test-threads=1 is the amplifier: ~40% there against ~6% in the default
parallel mode. Serialising increases the rate, so this is not
TEST_SERIALIZE contention.

Measured on an anvil guest (debian-13-ci, io_uring, 24 vCPU), 25 reps per sha:

sha		hangs
0a8aabf	#422	7/25
5afa2aa	#421	15/25
b0e0605	#420	7/25
a91bde8	pre-#415	4/25

Rates vary run to run; presence does not.

What hangs

Single-threaded, the trailing test NAME ... line with no result names it
every time:

test tls_echo_with_external_client ... ok
test tls_info_accessors ... ok
test tls_outbound_connect_and_echo ... ok
test tls_segmented_recv_reassembles_and_eofs ...     <-- never completes

The test writes 100 KiB over TLS and reads the echo back. The read stalls
part-way: the client keeps getting WouldBlock, i.e. the server has stopped
sending. The EOF wait later in the same test is already bounded (300 x 10 ms),
so the hang is in the echo read, not the close path.

100 KiB is deliberately larger than rustls' internal plaintext buffer, so the
server's drain loop produces several owned segments across several TLS records
— that is what the test is for. Possibly related to the recorded pre-existing
">16 KiB TLS echo" hang, though that one was mio and this is io_uring.

Why this went unnoticed

TcpStream::set_read_timeout surfaces a timed-out read as
ErrorKind::WouldBlock, which is indistinguishable from "no data yet". The
test's WouldBlock arm retried unconditionally, making the 5-second timeout
inert — so a stall became an unbounded hang rather than a failure, and CI saw
a 1200-second job timeout with no failing test name.

The same pattern is suite-wide: 46 WouldBlock arms across 8 test files,
many under a set_read_timeout. tls_echo.rs alone has 9 set_read_timeout
calls and 10 such arms; echo.rs has 59 and 27.

• Fixed for the two named tests in the PR that files this issue.
• The remaining sites are worth converting to a shared deadline-aware helper,
  so no test in this suite can convert a stall into a hang again.

This issue tracks the underlying stall, not the test-harness defect.

Next steps

• Capture thread stacks from a stuck run (gdb -p <tls_echo pid> -batch -ex "thread apply all bt"); gdb is not in the debian-13-ci guest image, so
  install it in the job or use a different image.
• Determine whether the worker is parked on a CQE that never arrives, or
  whether rustls has buffered plaintext that the drain loop is not re-polling
  for.

[brayniac]

The stall point is deterministic: exactly 16 KiB outstanding

With the bounded reads from #424 the hang becomes a named failure carrying a
byte count, and the count is the same every time:

test tls_segmented_recv_reassembles_and_eofs ... FAILED
segmented TLS echo: no progress for 30s at 86016/102400 bytes

102400 - 86016 = 16384 — exactly 16 KiB left undelivered, on every
observed failure. The echo returns 84 KiB of the 100 KiB and then stops for
good.

16384 is both the default provided-recv-buffer size and rustls' maximum
plaintext record, so the shape is "the final record/buffer is never drained"
rather than a general slowdown. Worth checking:

• whether the server's segmented drain loop leaves a final partial chunk in
  rustls' plaintext buffer without re-arming a read, and
• whether this is the io_uring sibling of the recorded pre-existing mio
  busy-spin on >16 KiB TLS echo.

Measured on an anvil guest, --test-threads=1, 30 reps per arm:

	ok	fast failure	hang
before #424	19	0	11 (150 s each)
after #424	14	16 (~31 s each)	0

(The ok-count difference is within binomial noise at this n; the 30 s
no-progress budget matches the watchdog already used by this file's big-send
reader.)

[brayniac]

Correction: the stall point is not deterministic

My earlier comment called it deterministic at 86016/102400. That was
generalised from two samples inside a single build, and it is wrong. Across
builds the stall lands in different places:

config	first observed stall
send_pool(64, 16384)	36864/102400
send_pool(64, 16448)	36864/102400
send_pool(64, 32768)	0/102400
(earlier run, same code as row 1)	86016/102400

It is consistent within a build and varies across them, which is a different
and more useful fact: there is no fixed boundary being hit.

Send-pool slot size is not the cause

Tested directly, 25 reps each, --test-threads=1:

slot size	ok	bad
16384 (test's value)	18	7
16448 (the default)	17	8
32768	3	22

The hypothesis was that 16384 is 64 bytes too small for a 16384-byte plaintext
record plus TLS header+MAC — which is exactly why the default is 16448. It is
wrong: the default performs identically, and a larger slot is dramatically
worse, stalling before a single byte is echoed.

Where that points instead

Sensitivity to unrelated send-side sizing, a variable stall point, and a ~30%
rate fit a provided-buffer-ring exhaustion / re-arm race rather than any
sizing error. Under segmented recv a held buffer is not replenished until the
segment is consumed, and ENOBUFS re-arm is event-driven on replenish
(Domain Invariant 6) — a missed re-arm there parks the connection for good.

The test runs a deliberately small ring for a large burst:

.recv_buffer(64, 4096)   // 256 KiB total, for a 100 KiB message

This is plausibly the same family as #378 / #349
(buffer_ring_exhaustion_recovers). A ring-depth sweep is running; if depth
moves the rate, that localises it.

Still unexplained and worth keeping in view: why a bigger send slot makes it
strictly worse.