aioquic interop multiplexing 2026-05-06 qlog post-mortem:
- 2898 packets sent in 60s, each carrying ONE STREAM frame
- server log: streams created/discarded strictly serially, ~30-40ms apart
- 1421/2000 files completed before the runner's 60s timeout
- shape ≈ 1 RTT per stream — wire was emitting one stream per datagram
Cause: Http3GetClient.prepareRequests + HqInteropGetClient.prepareRequests
both did `conn.lock.withLock { ... openBidiStreamLocked() }`. Post the
lock-split refactor `conn.lock` is the deprecated alias for lifecycleLock.
The writer's drainOutbound takes streamsLock — not lifecycleLock — so the
send loop interleaved between every two openBidiStreamLocked calls,
draining one stream's data per pass.
Fix:
1. Both prepareRequests impls now use conn.streamsLock.withLock.
2. openBidiStreamLocked now `check`s streamsLock.isLocked at entry
so this can never silently regress again — calling it without the
lock (or with the wrong lock) throws IllegalStateException with
a message naming streamsLock as the lock to acquire.
3. New BatchedOpenLockContractTest pins the contract:
- calling openBidiStreamLocked WITHOUT any lock throws
- calling openBidiStreamLocked while holding lifecycleLock throws
(the exact regression shape)
- calling openBidiStreamLocked while holding streamsLock works
(happy path)
The runtime check is the regression-proof part: future callers physically
cannot hold the wrong lock without the test (and prod) blowing up at the
first call site.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
Runner persists:
<case>/output.txt — runner stdout/stderr (+ client logs)
<case>/client/qlog/*.sqlog — qlog under client/qlog/, not client/
<case>/server/stderr.log — server stderr (CONNECTION_CLOSE reason)
Plus targeted grep for the events we actually need to localize a
multiplexing failure:
- last 5 packet_received / packet_sent (where did the flow stall)
- connection_closed (peer error code + reason)
- packet_dropped (sign of decrypt fails / unknown CID / etc.)
Layout varies by runner version; print the tree so we can see what
the runner actually wrote (qlog/pcap/log filenames, sizes) before
guessing at paths.
Pulls the diagnostics needed to localize a multiplexing failure:
- tail client/log.txt (per-stream errors, final outcome)
- tail server/log.txt (peer's CONNECTION_CLOSE reason)
- tail client qlog (frame-level event sequence)
- count downloaded files (how many of N actually finished)
- qlog event-type histogram (e.g. "lots of packet_dropped",
"no stream_state_updated past t=30s", etc.)
Resolves the most recent run-* dir under ../quic-interop-runner/logs
automatically — no need to copy-paste paths after every run.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
The runner's `multiplexing` testcase opens N parallel bidi streams,
each downloading one file, and asserts every file's content lands
on the right stream. Existing tests cover pieces of that:
- MultiplexingThroughputTest: opens 1000 streams in <2s — measures
lock contention but never moves bytes server-side.
- MultiplexingCoalescingTest: pins that 64 streams coalesce into ≤6
packets — encoder contract, no end-to-end.
- MultiStreamFinDeliveryTest: server pushes responses to 50 streams,
client surfaces every FIN — but the CLIENT never sends a STREAM
frame in that test, so any regression in the writer's request-
side multiplex path is invisible.
This test runs the full request → response loop:
1. Open 64 parallel bidi streams
2. Each enqueues a tiny request + FIN
3. Drain client outbound → decrypt → assert all 64 STREAM frames
made it across, with their request bytes intact
4. Server sends one response per stream + FIN
5. Per-stream incoming.toList() must yield the expected response
Failures call out the specific stream id, so a regression points
at "stream X dropped its FIN" instead of a generic timeout.
64 streams keeps wall-clock under a second; the bug class the test
guards against (per-stream loss / mis-routing) fires identically at
64 and 1999.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
The existing PtoCryptoRetransmitTest simulated the driver inline:
it set pendingPing=true and called requeueAllInflightCrypto by hand,
then asserted the next drain emitted CRYPTO. That checked the helpers
worked but never noticed when the DRIVER stopped calling
requeueAllInflightCrypto — which is exactly the regression that bit
us in commits c0d7b6031 (qlog merge) and again in cf2303a38
(lock-split refactor).
Extract the PTO-fired logic from QuicConnectionDriver.sendLoop into
a top-level internal helper handlePtoFired(conn). Driver and test now
both call the same function — if anyone unwires the requeue from
that helper or rewrites sendLoop to do volatile-only updates, the
test breaks.
Verified the regression-catch by stripping the requeue from
handlePtoFired and re-running the test: it fails with an
AssertionError on the PTO retransmit packet check, as expected.
Restored the helper, test green again.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
aioquic interop multiplexing qlog (the smoking gun):
packet_sent PN=0 Initial frames=[crypto] (ClientHello)
packet_sent PN=1 Initial frames=[ping] (PTO probe — bare PING)
packet_received connection_close 0x0
"Packet contains no CRYPTO frame"
This is the SAME bug commit c0d7b6031 fixed; the lock-split refactor
(ef4bb9998) re-wrote the driver's PTO branch to use streamsLock and
inlined the @Volatile pendingPing/consecutivePtoCount writes — but
dropped the requeueAllInflightCrypto call that c0d7b6031 had wired
under the (now-renamed) connection.lock.
Restored under levelLock for the appropriate level. SendBuffer's
internal synchronized covers correctness, but the level lock keeps
us from racing the writer's takeChunk mid-build.
The writer's comment at QuicConnectionWriter.kt:421-431 already
documented this contract — it was just unwired on the driver side.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
Tier 1 lock-split agent's worktree was based on main and didn't carry
the Retry-handling work (fields retryToken / retryConsumed, applyRetry
method's references to them). Merge with -X theirs nuked those.
Restored:
- retryToken + retryConsumed @Volatile fields on QuicConnection,
re-attached to applyRetry in the lock-split-merged file.
- LevelState.resetForVersionNegotiation now uses pnSpace.resetForRetry()
to reset the PN counter in place — pnSpace is `val` post-refactor,
direct re-assignment doesn't compile. The naming is historical;
the underlying semantics (zero PN counter + clear received side)
are correct for both VN and Retry-with-fresh-PN cases.
- openBidiStream split into the public suspend wrapper +
openBidiStreamLocked() (caller holds streamsLock). Restores the
batched prepareRequests path's ability to open N streams under one
lock hold.
- close() — local var firedQlog hoisted out of withLock block.
Test suite runs clean. Three deprecation warnings remain on
PtoCryptoRetransmitTest + QlogObserverTest still using the
backward-compat conn.lock alias; left for follow-up cleanup.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
The single connection-wide `QuicConnection.lock` mutex serialised every
critical path: the read loop's `feedDatagram`, the send loop's
`drainOutbound`, and every public mutator (`openBidiStream`,
`streamById`, `flowControlSnapshot`, ...). The multiplexing testcase
opens hundreds of bidi streams in parallel and was capped at ~25
streams/sec by lock contention against the I/O loops.
Phase 1 of the lock split (see
`quic/plans/2026-05-08-lock-split-design.md`) introduces three
domain-specific mutexes:
- `streamsLock` — streams registry, datagram queues, stream-id
counters, connection-level flow-control bookkeeping, pending-
retransmit maps for control frames
- `LevelState.levelLock` (one per encryption level) — per-level
pnSpace / sentPackets / ackTracker / CRYPTO buffers
- `lifecycleLock` — status transitions, close reason/error code
Acquisition order: `lifecycleLock < streamsLock < levelLock`.
Per-stream `synchronized(this)` blocks inside SendBuffer/ReceiveBuffer
remain at the leaf — never acquire any QuicConnection mutex while
holding a per-stream lock.
The legacy `lock: Mutex` field is preserved as a deprecated alias of
`lifecycleLock` for source-compatibility with external test harnesses;
new code MUST use the appropriate domain lock.
Highlights:
- `feedDatagram` / `drainOutbound` now require the caller to hold
`streamsLock`; the driver wraps each call. Phase 1 keeps the whole
feed/drain inside `streamsLock` for safety; phase 2 (deferred) will
split frame-collection from encrypt + sentPackets-record so app
coroutines can intersperse during the encrypt window.
- `pendingPing`, `peerTransportParameters`, `status`,
`handshakeComplete` are now @Volatile so observers read them
without a lock.
- `markClosedExternally` no longer needs any lock (status is
@Volatile, signals are channel-thread-safe).
- Driver's PTO bookkeeping uses the volatile fields directly — no
lock needed.
- Tests that manually acquired `conn.lock` to call
`getOrCreatePeerStreamLocked` / `onTokensAcked` / `onTokensLost`
now acquire `streamsLock` (the domain those routines mutate).
- New `MultiplexingThroughputTest` locks in the contract: 1000
parallel `openBidiStream` calls must complete in <2 s.
Test plan:
- `:quic:jvmTest` — 294 tests pass (293 prior + 1 new throughput).
- `MultiplexingThroughputTest`: 1000 bidi streams in 52 ms
(~19,000 streams/sec on the in-memory pipe), well above the
250+/sec target.
- `:nestsClient:compileKotlinJvm` — clean, no API breaks.
- `./gradlew :quic:spotlessApply` — clean.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
Diagnosis from yet another qlog round: streams/packet still ~1 even
with the prepareRequest/awaitResponse split. Root cause: openBidiStream
is suspend due to lock.withLock, and each call releases the lock between
iterations. The send loop is queued on the lock; it grabs it the moment
we release, drains the one stream of data we just enqueued, and the
next prepareRequest call has to re-acquire after the send loop releases.
Net: one stream per drain per packet, same useless coalescing as before.
Fix is structural:
- QuicConnection.openBidiStreamLocked() — public, lock-not-acquired
version of openBidiStream. Caller MUST hold conn.lock.
- GetClient.prepareRequests(authority, paths) — batch API that
holds conn.lock once, opens + enqueues all N streams in a single
critical section, releases. Send loop can't interject; when it
next drains it sees ALL N streams' data ready and packs them
into coalesced packets.
- Http3GetClient + HqInteropGetClient: implement prepareRequests
using openBidiStreamLocked under conn.lock.withLock { ... }.
- InteropClient's chunked-multiplex loop: uses prepareRequests
(batch) instead of N x prepareRequest.
Single-stream paths still use prepareRequest / get(); behavior unchanged.
The fundamental architectural improvement (per-stream / per-level lock
split, or actor-model dispatch) is a follow-up; this commit gets us
the throughput we need from the existing single-mutex shape by holding
the lock for the full chunk's worth of work.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
Two unit tests for the multiplexing throughput problem we just fixed
in the InteropClient (commit bc19e90c1):
1. `64 streams enqueued before drain coalesce into a small fixed
number of packets` — opens 64 bidi streams, enqueues 50 bytes +
FIN on each (no drain between), drains everything, asserts
≤6 packets and ≥10 streams/packet. Pre-fix shape (each enqueue
followed by an immediate single-stream drain) would emit 64 packets.
2. `1000 streams enqueued in batches of 64 produce a tractable packet
count` — stress version mirroring the runner's 1999-file
multiplexing test. Asserts ≤150 packets total for 1000 streams.
Both tests run in <300ms on the in-memory pipe — fast iteration for
debugging the multiplexing-throughput regression cycle without
spinning up Docker.
These pin the contract that ZERO drains between enqueues = packets
batch many streams' frames. The runner-side fix (split GetClient.get
into prepareRequest + awaitResponse, batch prepareRequests serially,
wake once) ensures we hit this shape in real interop.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
Diagnosis from qlog timeline pattern: send packets clustered ~37ms
apart (sim RTT) but each cluster contained only ONE stream's data
(80-byte packets despite 1452-byte capacity). 1457 GETs in 58s, ~25
streams/sec.
Root cause: race between client.get()'s per-call driver.wakeup() and
the dispatcher scheduling the OTHER 63 coroutines. Sequence:
1. c1 acquires conn lock, enqueues request, wakes send loop, releases
2. Send loop wakes, queues for lock — other 63 coroutines haven't
started yet (dispatcher hasn't picked them up)
3. Send loop acquires lock alone, drains c1's data into one tiny
packet, releases
4. c2 finally starts, acquires, enqueues, wakes...
→ one stream per packet, no coalescing
Fix: split GetClient.get() into prepareRequest (open + enqueue + FIN,
synchronous, no wake) and awaitResponse (collect, async). Multiplex
chunk loop now:
Phase 1: serial prepareRequest for every URL in the chunk (64 in
sequence, each adding to send buffers)
Phase 2: SINGLE driver.wakeup() — by now all 64 streams have data
queued; send loop drains them all in coalesced packets
Phase 3: parallel awaitResponse with per-stream timeout
Predicted throughput jump: 25 streams/sec → ~1000+/sec (sim RTT-bound
at ~30ms per round trip = 64 streams per RTT = 2100/sec ceiling).
Single-request paths (transfer / chacha20 / etc) keep using the
default GetClient.get() which still wraps prepare+await; no behavioral
change there.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
Multiplexing-throughput investigation (qlog against aioquic):
~25 streams/sec with 1453 GETs in 58s. The bottleneck under high
stream count was drainOutbound's per-call O(N log N) sort over the
ENTIRE stream list (including streams that have already FIN'd both
ways and have nothing to send).
Two cheap optimizations to drainOutbound's stream iteration:
1. Filter to !isClosed streams BEFORE sort. Most streams under
bursty multiplexing loads are done; iterating them is wasted.
2. Skip sortedByDescending entirely when every stream is at
default priority (priority == 0). The pre-priority round-robin
shape (insertion order) is preserved, satisfying the moq-lite
newer-sequence-stream priority contract by happenstance for
uniform-priority loads.
Drops drainOutbound's per-call cost from O(N log N) where N = total
streams to roughly O(active) under realistic loads. Multiplexing's
~2000 streams accumulated over a run drop down to maybe 64 active at
any moment (the chunk in flight).
Doesn't affect the moq-lite audio path's behavior (small N, default
priorities → both paths reduce to the same round-robin walk).
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
Diagnosis (qlog): 1361 GETs in 58s = 23/sec, but only 2618 packets sent
in that window — 0.5 GETs per packet. We were sending nearly empty
packets one at a time, not coalescing requests.
Root cause: stream.send.enqueue + stream.send.finish() don't wake the
send loop. The send loop suspends on sendWakeup until either an
inbound packet arrives or the PTO timer fires (~1s). For our chunked
parallel multiplexing path:
1. enqueue 64 GETs into 64 streams
2. send loop is asleep (last drain happened on previous chunk)
3. wait ~1s for PTO before any of them go on the wire
4. server processes, replies, our read loop wakes the send loop
5. send loop drains ACKs (no new requests yet)
Each chunk wasted ~1s of PTO wait. With ~21 chunks at 1s each plus
RTTs and server processing, throughput floored at ~23 streams/sec.
Fix: pass QuicConnectionDriver to Http3GetClient + HqInteropGetClient
constructors. After stream.send.finish(), call driver.wakeup() to
nudge the send loop. The first request of each chunk now leaves
within microseconds instead of waiting for PTO.
Predicted throughput: 600+ streams/sec (RTT-bound at 30ms per chunk
of 64 = 2100/sec ceiling; CPU and lock contention drop it to ~600).
1999 streams in 3-5s instead of timing out at 60s.
The architectural fix would be having stream.send.enqueue auto-wake
via a callback set during stream creation. That's the cleaner shape;
this commit takes the minimal path: explicit driver-passed wakeup
from interop client code where the throughput matters.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
Multiplexing matters — MoQ audio rooms run hundreds of concurrent streams
(one per Opus frame). Earlier diagnosis showed our endpoint was
hard-capped at ~23 streams/sec because spawning 1999 simultaneous
coroutines all racing :quic's single conn.lock cratered throughput.
Diagnosis from the qlog/output.txt: 1359 GETs processed in 58s. Lock
contention scales superlinearly with suspended coroutines:
- every drainOutbound walks streamsList O(N)
- every openBidiStream queues behind every other waiter
- the dispatcher thrashes context-switching across 1999 channels
Fix: process the multiplexing testcase's URLs in chunks of 64. Each
chunk is fully parallel on the wire (what the runner's tshark
multiplexing check verifies — streams overlap in time WITHIN a chunk),
and conn.lock only ever has ~64 live waiters instead of ~1999.
Predicted throughput jump from 23 to ~600+ streams/sec. 1999 files in
~3 seconds instead of timing out at 60.
Per-stream timeout still wraps each get() — a single hung stream
surfaces as status=0 instead of stalling its chunk's await.
This is the right answer for the throughput angle. The conn-lock split
remains a follow-up for genuinely-stratospheric stream counts (10k+),
but 64-wide concurrency comfortably handles the runner's 1999 and
real MoQ audio-room load shapes (hundreds of concurrent streams).
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
The QPACK_MAX_TABLE_CAPACITY=0 advertisement worsened the result
(1 file → 0 files written). Empirical: empty SETTINGS = spec defaults
(both 0) and aioquic was already sending literal-encoded responses
under that condition.
Real bug isn't QPACK — diagnostic showed 1359 GETs processed in 58s
(~23 streams/sec). Throughput is hard-bottlenecked by :quic's single
conn.lock serializing send loop + read loop + openBidiStream across
1999 waiting coroutines. Even at maximum throughput we'd only complete
~1400 of 1999 in 60s. The 1 file we managed previously was just the
first response landing before lock contention spiked.
Filed multiplexing as a known-throughput-limit follow-up. Possible
fixes (per-level lock split / Semaphore-bounded concurrency / QPACK
dynamic-table support) are all non-trivial and the testcase is a
stress test, not a real-world load shape.
For now: revert to empty SETTINGS, accept multiplexing as the lone
deferred testcase. Aioquic + picoquic stay at 6/7.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
aioquic multiplexing diagnosis: runner asked for 1999 files, aioquic
processed 1371 GET requests, our endpoint wrote ONLY 1 file to
/downloads. The connection stayed healthy throughout (qlog shows
STREAM frames flowing both ways at t=58s). Server response volume
indicates each request got a 200 response.
The bug: our QpackDecoder is literal-only (no dynamic table). When
aioquic primes its dynamic table after a few requests and switches
to dynamic-table references in subsequent response HEADERS, our
decoder silently mis-parses — status comes back 0, file not written.
Empty-SETTINGS gives aioquic the spec default (also 0) but it apparently
doesn't strictly enforce: it still emits dynamic-refs anyway.
Fix: explicitly advertise QPACK_MAX_TABLE_CAPACITY=0 +
QPACK_BLOCKED_STREAMS=0 in our SETTINGS. Forces aioquic onto the
literal-only QPACK path that our decoder handles correctly.
A proper fix would be to implement QPACK dynamic-table support in our
decoder + read the server's encoder stream; that's its own project.
For now this gets multiplexing past the QPACK barrier so we can see
whether anything else is broken downstream.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
The previous coroutineScope { urls.map { async { ... } }.map { it.await() } }
pattern was vulnerable to a single hung stream blocking the whole await
chain — even though the others completed, sequential .await() iteration
would hang on the slowest forever. With multiplexing's hundreds of
streams, the probability of at least one having an issue (lost FIN,
slow consumer hitting channel-saturation thresholds, etc.) is high.
Wrap each get() in withTimeoutOrNull(PER_STREAM_TIMEOUT_SEC). A timed-out
stream surfaces as GetResponse(status=0); the caller's status != 200
check counts it as a failure but doesn't block the loop.
Doesn't fix throughput — that needs separate work on per-stream
backpressure and parser fairness. Just makes the failure mode visible
(status=0 → "failed file") rather than hidden (whole test times out
because of one bad stream).
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
aioquic multiplexing qlog showed:
t=31424: still receiving STREAM frames
t=31493: PTO timer expired
t=31507: connection_closed (owner: local)
We were still actively transferring when our 30s timeout fired. The
multiplexing testcase generates many small files (3431 sim packets
captured for the run) and download throughput on Mac+Rosetta is
dominated by per-write filesystem overhead in the Docker volume mount.
60s gives enough headroom without making fast-completing tests slower.
Doesn't fix any real protocol issue — just lets the test budget match
the workload.
If multiplexing still fails after this, the next investigation is the
sequential `.map { it.await() }` pattern in runTransferTest: a single
hung stream blocks the await chain even though others completed.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
aioquic's retry test result, surfaced via qlog:
Check of downloaded files succeeded.
Client reset the packet number. Check failed for PN 0
Our applyRetry called LevelState.resetForVersionNegotiation, which
creates a fresh PacketNumberSpaceState() — resetting PN to 0. The
qlog confirmed: PN=0 sent at t=388 (pre-Retry ClientHello), then PN=0
again at t=1468 (post-Retry retried ClientHello). Same PN reused
across the boundary.
RFC 9001 §5.7 + RFC 9000 §17.2.5: the Initial PN namespace CONTINUES
across the Retry boundary. The new Initial keys are derived from the
new DCID, but PN doesn't reset. Reusing a PN under different keys
makes the runner's pcap-decryption check fail (it's also a security
concern in the general case, hence the strict spec rule).
Fix: new LevelState.resetForRetry that's identical to
resetForVersionNegotiation EXCEPT it preserves pnSpace. applyRetry
calls resetForRetry. Two regression tests updated to assert the
post-Retry Initial uses PN=1 (continues from PN=0 of the pre-Retry
attempt) rather than PN=0 (the buggy reset behavior).
For Version Negotiation the original semantics still apply (RFC 9000
§6.2: client treats VN as if the original Initial was never sent;
PN reset to 0 is correct).
This should bring the retry testcase from ✕(S) to ✓(S) against
servers that exercise the Retry path. The handshake / transfer
already succeeded over the Retry per the qlog (the server's check
"Check of downloaded files succeeded." passed); only the PN-reuse
flag was failing the test.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
Direct evidence from aioquic interop qlog:
packet_sent PN=0 frames=[crypto] (ClientHello)
packet_sent PN=1 frames=[ping] (PTO probe — bare PING)
packet_received frames=[connection_close]
reason="Packet contains no CRYPTO frame"
aioquic strictly rejects pre-handshake Initials that contain no
CRYPTO frame. Our PTO probe was a bare PING, not a CRYPTO retransmit.
Agent 2's c9e036f72 implemented the right behavior: on PTO, the
driver requeues all inflight CRYPTO at the highest pre-application
level, so the next drain emits a fresh CRYPTO frame at the original
offset. The pendingPing flag stays as a fallback only used when no
CRYPTO is available to retransmit. That logic was wiped during the
qlog observer merge — driver's PTO branch only set pendingPing,
nothing requeued anything, probe was always bare PING.
Restored. Should fix the post-flush-fix regression where aioquic
went 1/7 (only transfer green) — once a packet was dropped or PTO
fired, the next probe was bare PING, aioquic closed with
"no CRYPTO frame", the test failed. Sequential tests on the same
matrix invocation likely intermittently passed/failed depending on
whether PTO fired before the response arrived.
The :quic helpers requeueAllInflightCrypto + highestPreApplicationLevel
already exist on the branch — just the driver call wasn't wired.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
aioquic still 0/7 after the close-race fix because there's a deeper
issue. QlogWriter.writeLineLocked() called writer.flush() on every
event. On macOS Docker Desktop the filesystem is virtualized and
per-event flush is multi-millisecond. The qlog hooks fire from
QuicConnectionWriter.drainOutbound() which runs INSIDE
conn.lock.withLock { ... } on the send loop. Every flush stalls
that lock; the receive loop blocks indefinitely trying to acquire
it for feedDatagram().
Symptom matched: client.sqlog showed our ClientHello packet_sent
at t=400ms, then NOTHING for the rest of the test — no
packet_received (server's response never decoded), no PTO probe
(send loop stuck behind disk IO).
Fix: remove per-event flush. close() flushes once at the end of
the run, which gives us the trace for everything except a hard
JVM kill mid-test (acceptable trade). BufferedWriter still buffers
in-memory; we don't lose events, just don't sync them to disk
synchronously.
Should restore aioquic to 5/7. picoquic was already 5/7 because
its server-response timing apparently let our send loop drain
between flushes; aioquic's faster turnaround tripped the lock more
reliably.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
aioquic full-matrix run came back 0/7 with stack traces:
java.io.IOException: Stream closed
at QlogWriter.writeLineLocked(QlogWriter.kt:289)
at QlogWriter.onPacketSent(QlogWriter.kt:126)
at QuicConnectionWriter.emitQlogSent(...)
The send loop runs concurrently with InteropClient's teardown sequence:
1. driver.close() — launches CLOSING → CLOSED async
2. qlogWriter?.close() — closes the file
3. delay(50)
4. scope.cancel() — kills coroutines
Between (2) and (4), the send loop is still alive and emits
packet_sent for the CONNECTION_CLOSE Initial. QlogWriter.writeLineLocked
threw IOException into the send loop, propagated up, took down the
connection — including connections that had completed transfer
successfully.
Fix: QlogWriter swallows post-close IOExceptions silently. An observer
must NOT break the connection it's observing — that's the whole NoOp
contract. Adds @Volatile closed flag, latches it both on explicit
close() and on the first IOException; subsequent emits short-circuit.
picoquic was 5/7 (predictable: M + S still open) so the regression was
specifically aioquic-timing-sensitive. With this fix aioquic should
return to 5/7 too.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
Documents:
- Three overnight agents merged (VN defense in :quic, qlog observer
+ JSON-NDJSON writer wired into the prod endpoint, peer-uni-stream
drainer fixing the multiplexing tear-down).
- The agent-A versionnegotiation testcase mismatch — runner doesn't
have that name; v2 is the closest, tests QUIC v2 which we don't
speak. VN code stays as defensive support.
- Open issues for tomorrow: retry test failure (qlog now available
for diagnosis), v2 (deferred), re-runs against all three peers
with the new fixes.
- Documented run-matrix.sh's concurrency limit.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
Agent B's QlogWriter previously lived only in :quic's jvmTest scope,
hooked into the standalone InteropRunner. Brings it into :quic-interop
proper:
- QlogWriter.kt + QlogWriterTest.kt copied into :quic-interop with
package com.vitorpamplona.quic.interop.runner.
- Jackson dep added to :quic-interop's build.gradle.kts.
- InteropClient reads $QLOGDIR (the runner sets it inside the
container per docker-compose.yml). When set, opens a QlogWriter
at <QLOGDIR>/client.sqlog, passes as QuicConnection.qlogObserver,
closes on every exit path (handshake_failed / udp_failed /
transfer_timeout / ok).
- QUIC_INTEROP_DEBUG=1 now prints qlogdir alongside the other env
fields.
Net effect: any future runner-driven test failure dumps a structured
qlog file the user can drag straight into qvis (qvis.quictools.info)
to see frame-by-frame what the client decided to do. The retry test
failure on aioquic + picoquic that we still need to debug now produces
a usable artifact.
NOTE: the QlogWriter copy in :quic's jvmTest stays in place as the
helper for the standalone InteropRunner main(). Slight duplication;
acceptable while :quic-interop is its own module.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
Two corrections from the user's just-completed run:
1. The runner does not have a 'versionnegotiation' testcase. Available
list output: handshake, transfer, longrtt, chacha20, multiplexing,
retry, resumption, zerortt, http3, blackhole, keyupdate, ecn,
amplificationlimit, handshakeloss, transferloss, handshakecorruption,
transfercorruption, ipv6, v2, rebind-port, rebind-addr,
connectionmigration. (`v2` exists but tests QUIC v2 protocol
support — we're v1-only, so it would correctly fail.)
The :quic-side VN code from agent A stays as defensive support for
any future server that throws a VN at us; just no testcase wires
it up.
2. run-matrix.sh is NOT safe to run concurrently. The runner's
docker-compose.yml hardcodes container_name: sim/server/client —
Docker enforces those globally regardless of COMPOSE_PROJECT_NAME.
Documented the limitation + the recommended sequential loop in
the script's comments.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
Same merge-from-main shape as the prior agent A integration: the qlog
agent's worktree didn't carry the version-negotiation work (QuicVersion
import, currentVersion / vnConsumed fields, applyVersionNegotiation),
the Retry work (extraSecretsListener / cipherSuites / applyRetry), or
the version-negotiation testcase wiring. Merge with -X theirs took the
qlog version of QuicConnection.kt + QuicConnectionWriter.kt + the
existing InteropRunner.kt wholesale, dropping those.
Restored:
- QuicVersion import in QuicConnection.kt + QuicConnectionWriter.kt +
the test-side InteropRunner.kt (also touched by agent B's qlog
hooks).
- extraSecretsListener / cipherSuites / initialVersion ctor params
on QuicConnection (qlogObserver kept; new qlog work landed).
Net result: all three overnight agents (A versionnegotiation, B qlog
observer, C peer-uni-stream drainer) now coexist on the branch with no
references missing. Full :quic:jvmTest green; :quic-interop:test +
installDist green.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
Two integrations from overnight agents:
1. agent C — peer-uni-stream drainer for the H3 multiplexing fix.
Http3GetClient.init() now takes a CoroutineScope and calls
conn.drainPeerInitiatedUniStreamsIntoBlackHole(scope) to consume +
discard the server's three uni streams (control, qpack-encoder,
qpack-decoder). RFC 9114 §6.2 mandates the client read these;
pre-fix their bytes accumulated in 64-chunk per-stream channels
until parser overflow tore down the connection with INTERNAL_ERROR
~4.5s into a multiplexing run.
2. agent A — versionnegotiation testcase wired into dispatch.
Adds the testcase to the runTransferTest route and threads
QuicVersion.FORCE_VERSION_NEGOTIATION as the initial version when
testcase=='versionnegotiation'. The QuicConnection's RFC 9000 §6
VN flow (applyVersionNegotiation) takes over from there, retrying
with v1 once the server replies with its supported list.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
The agent A worktree was based on main, so its QuicConnection.kt
didn't carry the Retry handling from d03e17981. Merging with
-X theirs replaced the file wholesale, dropping applyRetry +
extraSecretsListener / cipherSuites constructor params + the
RetryPacket import in the parser.
Restored:
- extraSecretsListener + cipherSuites ctor params (used in tlsListener
+ the TlsClient construction site).
- applyRetry method, now using the version-negotiation-introduced
LevelState.resetForVersionNegotiation helper (functionally
equivalent to the prior restoreFromRetry it replaced).
- RetryPacket import in QuicConnectionParser.
Also dedupes a duplicate `originalClientHello` field that the merge
left both copies of (one from agent 3's Retry work, one from agent A's
VN work). Single field now serves both reset paths.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
Variant (B) from the three-way fix menu in the multiplexing-interop
investigation: keep `:quic` strict about per-stream backpressure (the
audit-4 #3 "INTERNAL_ERROR: stream … consumer overflowed" tear-down
stays the contract for app-data overflow on bidi streams) but expose
an explicit, opt-in helper for peer-initiated UNI streams that the
application has decided it does not need to interpret.
Root cause confirmed in QuicConnectionParser.kt:290: when the server
opens its three RFC 9114 §6.2.1 peer-uni streams (CONTROL +
QPACK_ENCODER + QPACK_DECODER) and the H3 client does not consume
them, the parser routes their bytes into each stream's bounded
incomingChannel (capacity 64). Once the QPACK encoder issues
dynamic-table inserts beyond 64 chunks the next chunk overflows
trySend, sets QuicStream.overflowed, and the parser maps that to
markClosedExternally — the entire connection dies.
Notes on scope:
- The `Http3GetClient` and `:quic-interop` runner mentioned in the
investigation prompt do NOT exist on the `main` worktree this
branch starts from. The fix here is therefore `:quic`-only: the
public `awaitIncomingPeerStream` API was already sufficient for
an integrator to write the accept loop themselves; this commit
wraps the common case in `drainPeerInitiatedUniStreamsIntoBlackHole`
and updates the doc on `awaitIncomingPeerStream` so the next
integrator landing the H3 GET client doesn't hit the same trap.
- Variant (C) — silent default drain in `:quic` itself — was
deliberately rejected: defaults that swallow application bytes
are the misconfiguration we want type-system-or-API-explicit.
The new helper requires the caller to pass a CoroutineScope, so
opt-in is unmistakable in any callsite.
Regression test coverage in PeerUniStreamDrainTest:
- pre_fix_no_consumer_overflows_and_tears_down_connection — pushes
65 chunks (capacity + 1) on a SERVER_UNI stream with no consumer;
asserts the connection transitions to CLOSED. Pins the existing
backpressure contract.
- drainPeerInitiatedUniStreamsIntoBlackHole_keeps_connection_alive
— same setup but with the new helper running on a side scope;
pushes 256 chunks (4× capacity) and asserts the connection stays
CONNECTED. With the helper sabotaged, this test fails at
line 119 with status=CLOSED, confirming it actually exercises
the fix.
Full quic test suite: 295 tests, 0 failures, 0 errors.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
Adds the client-side VN flow needed for the interop runner's
`versionnegotiation` testcase:
- `QuicConnection` accepts an `initialVersion` constructor parameter
(default `QuicVersion.V1`) and exposes a mutable `currentVersion`
the writer stamps into outbound long-headers. `start()` now caches
the ClientHello bytes for VN-driven re-emission.
- `applyVersionNegotiation(supportedVersions)` validates per §6.2
(anti-downgrade: reject if list contains the offered version),
picks v1 from the offered set, regenerates DCID, re-derives
Initial keys against the new DCID, resets the Initial level via
`LevelState.resetForVersionNegotiation`, re-enqueues the cached
ClientHello, and latches `vnConsumed` so a second VN is dropped.
Failure to find a mutually supported version closes the connection
with `QuicVersionNegotiationException`.
- `QuicConnectionParser.feedDatagram` detects `version == 0` long
headers BEFORE peekHeader (whose layout assumes v1) and dispatches
to a new `feedVersionNegotiationPacket` that parses the §17.2.1
shape and validates the echoed DCID.
- `QuicConnectionWriter` reads `conn.currentVersion` instead of the
hardcoded `QuicVersion.V1`.
- `QuicVersion.FORCE_VERSION_NEGOTIATION = 0x1a2a3a4a` for the
interop runner.
- `InteropRunner` honors `TESTCASE=versionnegotiation` (or
`-DinteropTestcase=`) and offers the force-VN version.
Regression coverage in `VersionNegotiationTest`:
- happy path: VN switches `currentVersion` to v1, regenerates DCID,
resets PN, and the next drain emits a v1 Initial on the wire.
- downgrade defense: VN listing the offered version is dropped.
- unsupported list: VN whose versions we can't speak fails the
handshake and closes the connection.
- second VN: post-consumption VN is ignored.
- DCID mismatch: spoofed VN with wrong echoed DCID is dropped.
- backward compatibility: default `initialVersion` keeps v1 behavior
for existing callers.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
Three agents in flight in worktrees:
A — versionnegotiation testcase + configurable initial-version writer
B — qlog observer infrastructure (QlogObserver interface in :quic,
JSON-NDJSON writer in :quic-interop, hooks at packet/key/recovery
sites, reads $QLOGDIR the runner already sets)
C — multiplexing channel-saturation fix (consume server's peer uni
streams in Http3GetClient — RFC 9114 §6.2 says clients MUST
process incoming control + QPACK streams)
Plan doc now also captures the latest test matrix (pre-acfe815e1
multi-ALPN-offer fix) and the predictions for the next run.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
The previous commit (e5bbf8509) switched ALPN per testcase based on
quic-interop-runner convention (h3 for http3/multiplexing, hq-interop
otherwise). That broke picoquic, which had been 4/4 green: picoquic-qns
strictly registers h3 ALPN and rejects hq-interop. Different servers
disagree on which ALPN they configure for the same testcase:
- quic-go-qns — strictly hq-interop for non-http3
- aioquic-qns — accepts either
- picoquic-qns — strictly h3 for all testcases
There's no per-testcase convention all peers honor. Right move is the
TLS-spec-supported one: offer BOTH h3 and hq-interop in the ClientHello,
let the server pick whichever matches its config, then dispatch the GET
client by `tls.negotiatedAlpn` after the handshake completes. http3 and
multiplexing still restrict to h3 only since they exercise H3 framing.
Brings picoquic back to fully green and should unblock quic-go for the
non-http3 testcases.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
Two more testcases now dispatched through runTransferTest:
- retry — exercises the RFC 9000 §17.2.5 + RFC 9001 §5.8 Retry
handling that landed in d03e17981 / 671f9c705 (DCID swap,
integrity-tag verify, key re-derivation, token threading).
- ipv6 — same flow over an IPv6 socket. JDK's DatagramChannel.connect
handles the v6 address resolution natively; if anything
breaks it'll be an actual bug worth surfacing.
Plan doc updated to reflect Phase 3 landings (ALPN per testcase,
HqInteropGetClient, multi-stream FIN delivery fix) and the current
validation matrix across aioquic / picoquic / quic-go.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
quic-go-qns interop revealed two coupled gaps in our endpoint:
1. ALPN per testcase. The runner convention (followed strictly by
quic-go-qns, lazily by aioquic / picoquic) is:
- testcase 'http3' / 'multiplexing' → ALPN 'h3' (full HTTP/3)
- everything else → ALPN 'hq-interop'
(HTTP/0.9 over QUIC)
We had hardcoded 'h3'. quic-go closed every non-http3 connection
with CRYPTO_ERROR 0x178 (TLS no_application_protocol).
2. We had no HQ-interop client. HQ is dead simple: open bidi, send
`GET /path\r\n` raw, FIN, read body verbatim until server FINs.
No framing, no QPACK, no control stream.
This commit adds:
- GetClient interface + GetResponse data class extracted from
Http3GetClient so the runner code dispatches uniformly.
- HqInteropGetClient — the 30-line HQ-interop GET implementation.
- Alpn enum (H3, HQ_INTEROP) wired through main() → runTransferTest
→ QuicConnection.alpnList. Picked from the testcase name per the
convention above.
Validated locally: :quic-interop:test green; :quic-interop:installDist
clean. Will need a real run against quic-go to confirm the fix.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
When QuicConnection tears down (CONNECTION_CLOSE, read-loop death,
INTERNAL_ERROR from a saturated stream channel, etc.) the per-stream
incomingChannel objects were left open, so any application coroutine
suspended on `stream.incoming.collect { … }` hung forever waiting for
a FIN that would never come. The connection-wide signal channels
(closedSignal, peerStreamSignal, incomingDatagramSignal) all closed
cleanly, but the per-stream Flows did not — surfacing in the
quic-interop-runner `multiplexing` case as 677 collectors stuck after
the connection died mid-response, so zero of the 1999 expected files
landed.
Fix: closeAllSignals() now also calls closeIncoming() on every stream
in streamsList. Channel.close() is idempotent, and consumeAsFlow drains
already-buffered chunks before honouring the close, so any bytes the
parser had already pushed are still surfaced to the collector before
the Flow terminates.
Adds MultiStreamFinDeliveryTest covering: (a) FIN delivery to N parallel
client-bidi streams, (b) connection-teardown unblocks every per-stream
Flow, (c) buffered bytes survive a teardown without an explicit FIN.
make smoke was the bisector for "is the bug in :quic or in the runner
environment?" while we were debugging the initial close-path / PTO /
padding issues. Now that the runner reliably runs the matrix end-to-end
(handshake + chacha20 green vs aioquic), smoke's only job — running
picoquic outside the runner — is unneeded, and the picoquic image
keeps changing its entrypoint / required args in ways that make smoke
finicky to maintain.
Removes:
- make smoke / smoke-down targets
- SMOKE_NET / SMOKE_PICOQUIC / SMOKE_CLIENT vars
- SMOKE_MODE handling in run_endpoint.sh (just always tolerates
/setup.sh failure now — same effect, less ceremony)
- Plan doc note about make smoke updated to reflect removal.
If we ever need a non-runner bisector again, it's two `docker run`
commands; not worth permanent maintenance.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
The runner aggregates container stderr verbatim, which gave us a
~50-line block of routing setup, NIC checksum offload toggles,
container lifecycle messages, and the long Command: WAITFORSERVER=...
line for every single testcase. Useful once for triage; pure noise
across a multi-test matrix run.
Two changes:
- run-matrix.sh pipes the runner output through a grep -Ev filter
that drops the boilerplate while keeping outcomes (Test: ... took /
status, the summary table, server's Starting server, sim scenario
+ capture lines, and any Python tracebacks). VERBOSE=1 bypasses
the filter for debugging.
- InteropClient drops its own pre-test header dump unless
QUIC_INTEROP_DEBUG=1 is set; the per-GET success line goes silent
too — failures still print as before.
Net result: a passing test reduces from ~50 noise lines to ~5
meaningful lines (test name, time, status, summary table).
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
Two coupled bugs in our endpoint that the runner just surfaced:
1. The runner mounts \$CLIENT_DOWNLOADS to /downloads as a Docker volume
(per quic-interop-runner's docker-compose.yml `client.volumes`).
There is no DOWNLOADS env var. Our endpoint was reading \$DOWNLOADS,
getting null, and (for handshake/chacha20) skipping any download path.
Hard-code /downloads.
2. The handshake / chacha20 / handshakeloss testcases don't just verify
the handshake completes — they also require the requested file at
/downloads/<basename>. The runner's _check_files validator
reported "Missing files: ['intense-tremendous-firefighter']" while
our client side reported `handshake ok`. Route handshake-flavor
testcases through runTransferTest so the full H3 GET pipeline runs.
`chacha20` keeps the cipher-suite override (ChaCha20-only ClientHello);
`handshakeloss` reuses the same H3 flow against a lossy sim.
Also drops the now-dead runHandshakeTest + parseFirstTarget helpers.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
pyshark's pcap reader calls asyncio.get_event_loop_policy().get_event_loop(),
which raises RuntimeError on Python 3.14 (deprecated in 3.12, removed in
3.14). Symptom: the matrix run completes the actual interop test
successfully but the runner's pcap-validation step crashes before it can
emit the result, dropping a 100+ line traceback.
run-matrix.sh now scans for python3.13 → 3.12 → 3.11 → python3, picking
the first that's both installed and < 3.14, and creates the venv with it.
Existing venvs created with 3.14 keep working (only matters for fresh
clones); for an existing broken venv, rm -rf .venv and re-run.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
Confirmed via `docker run --entrypoint find privateoctopus/picoquic:latest
/ -name picoquicdemo` — the binary isn't on PATH inside the image.
Use the absolute path so smoke runs without depending on PATH defaults.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
Claude