From 9d1d0534076252683ce74d04e989751cb82dcfeb Mon Sep 17 00:00:00 2001
From: Claude <noreply@anthropic.com>
Date: Thu, 7 May 2026 12:43:57 +0000
Subject: [PATCH] diag(quic-interop): hunt the connBudget-exhausted hypothesis
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

The 2026-05-07 qlog post-streamsLock-fix shows the smoking gun:
  - 1406 packets with exactly 1 stream frame each
  - 1 packet (out of 1407) with >1 stream frames
  - first stream packets at 1665ms / 1709ms (one RTT apart)

Wire shape says: writer is NOT bursting 64 streams per drain.
Hypothesis: connBudget exhaustion. Trace:

  Iteration 1 of buildApplicationPacket:
    streamA.takeChunk(maxBytes = min(streamCredit, connBudget))
    → returns 50-byte chunk
    → connBudget -= 50

  Iteration N: connBudget == 0
    streamN.takeChunk(maxBytes = 0)
    → returns null (fresh-bytes path: cap==0 ⇒ null)
    → skip
    → next iteration also skips
    → drain returns 1-stream packet

  Wait for peer's MAX_DATA (one RTT)
  → connBudget bumps by maybe 50 bytes
  → emit one more stream
  → repeat

This matches the 40ms-per-stream cadence in the qlog exactly.

If the hypothesis is right, peer's initial_max_data is too small and
we're connection-flow-control bound by design (or by aioquic-qns
config). Three new sections in inspect-multiplexing.sh:

  1. peer transport_parameters — directly shows initial_max_data
  2. MAX_DATA arrivals — confirms the cadence + delta-per-bump
  3. per-packet stream_id — confirms each packet carries a different
     stream's first chunk

Also filtered the runner's "Generated random file" + "Requests:"
spam from run-matrix.sh output (separately requested).

Re-run inspect on the existing log dir to verify (no new matrix run
needed):
  ./quic/interop/inspect-multiplexing.sh

If initial_max_data is small, the fix is on us — we should pre-
advertise a larger initial_max_data on our side AND push for a
larger one from the peer (via setting our initial_max_data so peer
knows we can receive a lot, which may inform their MAX_DATA cadence).

https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
---
 quic/interop/inspect-multiplexing.sh | 30 +++++++++++++++++++++-------
 quic/interop/run-matrix.sh           |  2 ++
 2 files changed, 25 insertions(+), 7 deletions(-)

diff --git a/quic/interop/inspect-multiplexing.sh b/quic/interop/inspect-multiplexing.sh
index 9a63b19188..a174745030 100755
--- a/quic/interop/inspect-multiplexing.sh
+++ b/quic/interop/inspect-multiplexing.sh
@@ -76,13 +76,29 @@ if [[ -n "$QLOG" ]]; then
       | sort -n | uniq -c
 
     echo
-    echo "=============== wall-clock arrival of first 30 sent stream-bearing packets ==============="
-    # Did we BURST 64 streams in ~50ms after handshake, or did we
-    # dribble them out over time?
-    grep '"name":"transport:packet_sent".*"frame_type":"stream"' "$QLOG" \
-      | head -n 30 \
-      | grep -oE '"time":[0-9]+' \
-      | head -n 30
+    echo "=============== peer transport_parameters (initial_max_data is the key) ==============="
+    # If initial_max_data is small (e.g. < 1000 bytes), our writer
+    # gets throttled to one stream per packet because connBudget
+    # exhausts after the first stream. Each subsequent stream has to
+    # wait for a MAX_DATA frame from the peer (1 RTT each).
+    grep '"name":"transport:parameters_set"' "$QLOG"
+
+    echo
+    echo "=============== peer MAX_DATA frame timestamps + values (received) ==============="
+    # If MAX_DATA frames arrive with small bumps and at one-per-RTT
+    # cadence, we're flow-control bottlenecked: peer extends credit
+    # by ~50 bytes per RTT, we send one stream per credit bump.
+    grep '"name":"transport:packet_received"' "$QLOG" \
+      | grep -oE '"frame_type":"max_data"[^}]*' \
+      | head -n 30 || echo "(no max_data frames in qlog — may need to upgrade qlog observer)"
+
+    echo
+    echo "=============== first 30 packet_sent stream offsets (per-stream byte count) ==============="
+    # If every stream emits exactly one ~50-byte chunk before the next
+    # stream starts, we're connection-flow-control bound.
+    grep '"name":"transport:packet_sent"' "$QLOG" \
+      | grep -oE '"stream_id":[0-9]+' \
+      | head -n 30 || echo "(no stream_id field in qlog — may need to upgrade qlog observer)"
 
     echo
     echo "=============== last 5 packet_received events ==============="
diff --git a/quic/interop/run-matrix.sh b/quic/interop/run-matrix.sh
index dbfa4f1a56..fcfa7eb12f 100755
--- a/quic/interop/run-matrix.sh
+++ b/quic/interop/run-matrix.sh
@@ -148,6 +148,8 @@ else
             -e '^sim +\| +(Received signal:|msg=|NS_FATAL)' \
             -e '^Using the client'\''s key log file\.$' \
             -e '^Command: WAITFORSERVER=' \
+            -e '^[0-9-]+ [0-9:,]+ Generated random file: ' \
+            -e '^[0-9-]+ [0-9:,]+ Requests: \[' \
             -e '^==> ' \
             -e '^$'
     exit "${PIPESTATUS[0]}"