diag(quic): writer-side per-drain stats behind DEBUG=1 build flag
The qlog confirmed the writer emits 1 STREAM frame per packet on the
live wire, while MultiplexingCoalescingTest + MultiplexingAioquicTpsTest
both show ~9 streams per packet under synchronous drain. So the bug is
in the live driver flow — concurrent send loop + parser feed +
real-socket interleaving — and not in buildApplicationPacket itself.
To localize: add an opt-in trace at the END of buildApplicationPacket
that dumps per-drain state when QUIC_INTEROP_DEBUG=1:
[writer.app] frames=N stream_frames=K streamsView=M active=A
packetBudget_remaining=R connBudget_initial=C
- frames vs stream_frames tells us if non-stream frames (ACK,
MAX_DATA, MAX_STREAM_DATA) are bloating the packet
- active vs streamsView tells us if isClosed filter dropped streams
- packetBudget_remaining tells us if we hit the 64-byte break early
- connBudget_initial tells us if conn flow control was zero
Wired three pieces:
1. WriterDebug.kt — a single @Volatile boolean owned by commonMain,
`writerDebugEnabled`. Off by default.
2. InteropClient.main flips it to true if QUIC_INTEROP_DEBUG=1 is set
in the env.
3. Dockerfile + Makefile accept --build-arg DEBUG=1 (or `make build
DEBUG=1`) to bake the env var into the image.
Usage:
cd quic/interop
make build DEBUG=1
cd ../..
./quic/interop/run-matrix.sh -s aioquic -t multiplexing
cat ../quic-interop-runner/logs/run-*/aioquic_amethyst/multiplexing/output.txt | grep '^\[writer'
When off, cost is one volatile read in the writer hot path — negligible.
https://claude.ai/code/session_01HcvfQq1ttPV9PkRoJb4nyT
This commit is contained in:
@@ -14,3 +14,10 @@ RUN apt-get update \
|
|||||||
COPY quic/interop/build/install/quic-interop /opt/quic-interop
|
COPY quic/interop/build/install/quic-interop /opt/quic-interop
|
||||||
COPY quic/interop/run_endpoint.sh /run_endpoint.sh
|
COPY quic/interop/run_endpoint.sh /run_endpoint.sh
|
||||||
RUN chmod +x /run_endpoint.sh /opt/quic-interop/bin/quic-interop
|
RUN chmod +x /run_endpoint.sh /opt/quic-interop/bin/quic-interop
|
||||||
|
|
||||||
|
# Build-time toggle for verbose tracing. Pass --build-arg DEBUG=1 (or
|
||||||
|
# `make build DEBUG=1` via the Makefile) to bake QUIC_INTEROP_DEBUG into
|
||||||
|
# the image so the InteropClient + writer emit per-drain stats to stderr.
|
||||||
|
# Off by default — production matrix runs stay quiet.
|
||||||
|
ARG DEBUG=0
|
||||||
|
ENV QUIC_INTEROP_DEBUG=${DEBUG}
|
||||||
|
|||||||
@@ -10,6 +10,11 @@ IMAGE ?= amethyst-quic-interop:latest
|
|||||||
REPO_ROOT := $(shell git rev-parse --show-toplevel)
|
REPO_ROOT := $(shell git rev-parse --show-toplevel)
|
||||||
DIST_DIR := build/install/quic-interop
|
DIST_DIR := build/install/quic-interop
|
||||||
|
|
||||||
|
# Build-time toggle: `make build DEBUG=1` bakes QUIC_INTEROP_DEBUG=1 into
|
||||||
|
# the image so the InteropClient + writer emit per-drain diagnostics to
|
||||||
|
# stderr. Off by default — production matrix runs stay silent.
|
||||||
|
DEBUG ?= 0
|
||||||
|
|
||||||
.PHONY: build dist docker image-name clean
|
.PHONY: build dist docker image-name clean
|
||||||
|
|
||||||
build: docker
|
build: docker
|
||||||
@@ -18,7 +23,7 @@ dist:
|
|||||||
cd $(REPO_ROOT) && ./gradlew :quic-interop:installDist
|
cd $(REPO_ROOT) && ./gradlew :quic-interop:installDist
|
||||||
|
|
||||||
docker: dist
|
docker: dist
|
||||||
cd $(REPO_ROOT) && docker build -t $(IMAGE) -f quic/interop/Dockerfile .
|
cd $(REPO_ROOT) && docker build -t $(IMAGE) --build-arg DEBUG=$(DEBUG) -f quic/interop/Dockerfile .
|
||||||
|
|
||||||
image-name:
|
image-name:
|
||||||
@echo $(IMAGE)
|
@echo $(IMAGE)
|
||||||
|
|||||||
@@ -83,6 +83,12 @@ private const val PER_STREAM_TIMEOUT_SEC = 20L
|
|||||||
private const val MULTIPLEX_PARALLELISM = 64
|
private const val MULTIPLEX_PARALLELISM = 64
|
||||||
|
|
||||||
fun main() {
|
fun main() {
|
||||||
|
// Single env-var check, propagated to library code that opts into
|
||||||
|
// verbose tracing only when this is set.
|
||||||
|
if (System.getenv("QUIC_INTEROP_DEBUG") == "1") {
|
||||||
|
com.vitorpamplona.quic.connection.writerDebugEnabled = true
|
||||||
|
}
|
||||||
|
|
||||||
val role = System.getenv("ROLE") ?: "client"
|
val role = System.getenv("ROLE") ?: "client"
|
||||||
if (role != "client") {
|
if (role != "client") {
|
||||||
System.err.println("server role not implemented")
|
System.err.println("server role not implemented")
|
||||||
|
|||||||
@@ -705,6 +705,25 @@ private fun buildApplicationPacket(
|
|||||||
}
|
}
|
||||||
|
|
||||||
if (frames.isEmpty()) return null
|
if (frames.isEmpty()) return null
|
||||||
|
|
||||||
|
// Diagnostic: gated by QUIC_INTEROP_DEBUG=1 so prod is silent. Tells
|
||||||
|
// us exactly what state the writer was in when it built this packet.
|
||||||
|
// Hunting the multiplexing-on-the-wire bug where MultiplexingCoalescing
|
||||||
|
// Test passes (~9 streams/packet) but the live driver emits 1 STREAM
|
||||||
|
// per packet against aioquic.
|
||||||
|
if (com.vitorpamplona.quic.connection.writerDebugEnabled) {
|
||||||
|
val streamFrameCount = frames.count { it is StreamFrame }
|
||||||
|
val totalFrames = frames.size
|
||||||
|
val streamsViewSize = conn.streamsListLocked().size
|
||||||
|
val activeSize = conn.streamsListLocked().count { !it.isClosed }
|
||||||
|
System.err.println(
|
||||||
|
"[writer.app] frames=$totalFrames stream_frames=$streamFrameCount " +
|
||||||
|
"streamsView=$streamsViewSize active=$activeSize " +
|
||||||
|
"packetBudget_remaining=${1100 - (frames.filterIsInstance<StreamFrame>().sumOf { it.data.size + 32 })} " +
|
||||||
|
"connBudget_initial=${(conn.sendConnectionFlowCredit - conn.sendConnectionFlowConsumed).coerceAtLeast(0L)}",
|
||||||
|
)
|
||||||
|
}
|
||||||
|
|
||||||
val payload = encodeFrames(frames)
|
val payload = encodeFrames(frames)
|
||||||
val pn = state.pnSpace.allocateOutbound()
|
val pn = state.pnSpace.allocateOutbound()
|
||||||
// Retain the packet for RFC 9002 loss detection BEFORE the encrypt
|
// Retain the packet for RFC 9002 loss detection BEFORE the encrypt
|
||||||
|
|||||||
@@ -0,0 +1,34 @@
|
|||||||
|
/*
|
||||||
|
* Copyright (c) 2025 Vitor Pamplona
|
||||||
|
*
|
||||||
|
* Permission is hereby granted, free of charge, to any person obtaining a copy of
|
||||||
|
* this software and associated documentation files (the "Software"), to deal in
|
||||||
|
* the Software without restriction, including without limitation the rights to use,
|
||||||
|
* copy, modify, merge, publish, distribute, sublicense, and/or sell copies of the
|
||||||
|
* Software, and to permit persons to whom the Software is furnished to do so,
|
||||||
|
* subject to the following conditions:
|
||||||
|
*
|
||||||
|
* The above copyright notice and this permission notice shall be included in all
|
||||||
|
* copies or substantial portions of the Software.
|
||||||
|
*
|
||||||
|
* THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
|
||||||
|
* IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, FITNESS
|
||||||
|
* FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR
|
||||||
|
* COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN
|
||||||
|
* AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION
|
||||||
|
* WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.
|
||||||
|
*/
|
||||||
|
package com.vitorpamplona.quic.connection
|
||||||
|
|
||||||
|
/**
|
||||||
|
* Opt-in writer-side debug logging. Toggled by external code (the
|
||||||
|
* interop endpoint sets it from the QUIC_INTEROP_DEBUG env var at
|
||||||
|
* startup). Off by default — production must be silent.
|
||||||
|
*
|
||||||
|
* Cost when off: a single volatile read in the writer hot path,
|
||||||
|
* negligible against the encode + AEAD seal cost. Worth keeping
|
||||||
|
* inert in shipped code so the next interop investigation can flip
|
||||||
|
* it on without code changes.
|
||||||
|
*/
|
||||||
|
@Volatile
|
||||||
|
var writerDebugEnabled: Boolean = false
|
||||||
-1
@@ -20,7 +20,6 @@
|
|||||||
*/
|
*/
|
||||||
package com.vitorpamplona.quic.connection
|
package com.vitorpamplona.quic.connection
|
||||||
|
|
||||||
import com.vitorpamplona.quic.frame.StreamFrame
|
|
||||||
import com.vitorpamplona.quic.tls.InProcessTlsServer
|
import com.vitorpamplona.quic.tls.InProcessTlsServer
|
||||||
import kotlinx.coroutines.runBlocking
|
import kotlinx.coroutines.runBlocking
|
||||||
import kotlin.test.Test
|
import kotlin.test.Test
|
||||||
|
|||||||
Reference in New Issue
Block a user