From db27293fb0217f9d4da8da015d46e23469fdffc3 Mon Sep 17 00:00:00 2001 From: Claude Date: Thu, 7 May 2026 15:40:43 +0000 Subject: [PATCH] =?UTF-8?q?diag(quic-interop):=20inspect=20=E2=80=94=20sea?= =?UTF-8?q?rch=20per-testcase=20logs=20before=20falling=20back=20to=20stdo?= =?UTF-8?q?ut.log?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit When the runner's compliance-check phase produces traces but the actual testcase phase doesn't (matrix runs against multiple testcases sometimes lose later containers' stderr), the previous inspect script greppped the runner's stdout and silently produced nothing. Now: check per-testcase client/output.txt and output.txt first; fall back to the tee'd .stdout.log narrowed to this testcase's window. On total miss, print actionable hints (rebuild with DEBUG, run in isolation). --- quic/interop/inspect-testcase.sh | 62 +++++++++++++++++++++----------- 1 file changed, 41 insertions(+), 21 deletions(-) diff --git a/quic/interop/inspect-testcase.sh b/quic/interop/inspect-testcase.sh index f262f0850..2de0f3da8 100755 --- a/quic/interop/inspect-testcase.sh +++ b/quic/interop/inspect-testcase.sh @@ -48,27 +48,47 @@ fi echo echo "=============== client diagnostic traces (DEBUG=1) ===============" -# All [boot] / [interop] / [batch] / [writer.app] lines from the -# runner's tee'd stdout, narrowed to the timeframe of THIS testcase. -# The testcase's container restarts between tests so the lines -# between two 'Running test case:' markers are this run's. -if [[ -f "${RUN_DIR}.stdout.log" ]]; then - awk -v tc="$TC" ' - $0 ~ "Running test case: " tc { in_tc = 1; next } - in_tc && /Running test case:/ { exit } - in_tc && /\[(boot|interop|batch|writer\.)/ { print } - ' "${RUN_DIR}.stdout.log" | head -n 50 || true - echo "..." - echo "stream_frames histogram (this testcase only):" - awk -v tc="$TC" ' - $0 ~ "Running test case: " tc { in_tc = 1; next } - in_tc && /Running test case:/ { exit } - in_tc { print } - ' "${RUN_DIR}.stdout.log" \ - | grep -oE 'stream_frames=[0-9]+' \ - | sort | uniq -c | sort -rn || echo "(no stream_frames reports)" -else - echo "(no .stdout.log — re-run with DEBUG=1)" +# Three places to look, in priority order: +# 1. Per-testcase client output (testcases that write to file) +# 2. Per-testcase output.txt (some runner versions) +# 3. The runner's tee'd .stdout.log narrowed to this testcase's +# window — but only works for short tests, since matrix runs +# restart containers and longer tests' stderr can be lost +# when the container is killed mid-test. +CLIENT_TRACES=() +[[ -f "$TC_DIR/client/output.txt" ]] && CLIENT_TRACES+=("$TC_DIR/client/output.txt") +[[ -f "$TC_DIR/output.txt" ]] && CLIENT_TRACES+=("$TC_DIR/output.txt") +[[ -f "${RUN_DIR}.stdout.log" ]] && CLIENT_TRACES+=("${RUN_DIR}.stdout.log") + +found=0 +for f in "${CLIENT_TRACES[@]}"; do + n=$(grep -cE '\[(boot|interop|batch|writer\.)' "$f" 2>/dev/null || echo 0) + if [[ "$n" -gt 0 ]]; then + echo "(found $n diagnostic lines in $f)" + if [[ "$f" == *.stdout.log ]]; then + # Narrow to this testcase's window. + awk -v tc="$TC" ' + $0 ~ "Running test case: " tc { in_tc = 1; next } + in_tc && /Running test case:/ { exit } + in_tc && /\[(boot|interop|batch|writer\.)/ { print } + ' "$f" | head -n 50 || true + else + grep -E '\[(boot|interop|batch|writer\.)' "$f" | head -n 50 || true + fi + found=1 + break + fi +done + +if [[ "$found" -eq 0 ]]; then + echo "(no diagnostic lines for this testcase)" + echo + echo "Possible causes:" + echo " - The image was built without DEBUG=1: use 'DEBUG=1 ./run-matrix.sh ...'" + echo " - The container was killed mid-test before flushing stderr" + echo " - This testcase ran in a matrix and only the FIRST testcase's" + echo " traces were captured. Run this single testcase in isolation:" + echo " DEBUG=1 ./quic/interop/run-matrix.sh -s -t $TC" fi echo