← back to Ticket System

TK-11506: ship the head-of-line harness with its negative test

81f857a49383ff39c03f4379029ffbd432984264 · 2026-09-11 13:33:41 -0700 · Steve Abrams

A positive-only test on a detector proves nothing, so the harness documents and
was validated against an injected fault: the pre-fix build from 661b3c5 run on a
scratch port must make it exit 1. Proven the same minute at the same load -
patched live :9794 healthz 0.00099s PASS, unpatched :9881 healthz 10.75s FAIL.

Status code and timing come from separate curl -w tokens and a blank field
reports NOT_MEASURED, so timing can never be misread as a status code.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>

Files touched

• A test/tk11506-headofline.sh

Diff

commit 81f857a49383ff39c03f4379029ffbd432984264
Author: Steve Abrams <steve@designerwallcoverings.com>
Date:   Fri Sep 11 13:33:41 2026 -0700

    TK-11506: ship the head-of-line harness with its negative test
    
    A positive-only test on a detector proves nothing, so the harness documents and
    was validated against an injected fault: the pre-fix build from 661b3c5 run on a
    scratch port must make it exit 1. Proven the same minute at the same load -
    patched live :9794 healthz 0.00099s PASS, unpatched :9881 healthz 10.75s FAIL.
    
    Status code and timing come from separate curl -w tokens and a blank field
    reports NOT_MEASURED, so timing can never be misread as a status code.
    
    Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
---
 test/tk11506-headofline.sh | 86 ++++++++++++++++++++++++++++++++++++++++++++++
 1 file changed, 86 insertions(+)

diff --git a/test/tk11506-headofline.sh b/test/tk11506-headofline.sh
new file mode 100755
index 00000000..21ca31e0
--- /dev/null
+++ b/test/tk11506-headofline.sh
@@ -0,0 +1,86 @@
+#!/bin/bash
+# TK-11506 head-of-line-blocking harness.
+#
+# THE ACCEPTANCE TEST: /healthz must stay responsive WHILE an /api/tickets call is in
+# flight. The whole bug was head-of-line blocking on the single main thread, so a check
+# that only times /api/tickets in isolation would measure the wrong thing and go green.
+#
+# NEGATIVE TEST (run this before trusting a PASS — a positive-only test on a detector
+# proves nothing):
+#   git show 661b3c5:server.js > server-unpatched.tmp.js   # the pre-fix fold-per-request build
+#   PORT=9881 node ./server-unpatched.tmp.js &
+#   ./test/tk11506-headofline.sh 9881 'admin:DW2024!' NEGATIVE-CONTROL   # MUST exit 1 / VERDICT FAIL
+#   rm server-unpatched.tmp.js
+# Proven 2026-09-11: patched live :9794 = 0.00099s PASS while unpatched :9881 = 10.75s FAIL,
+# same minute, same load average.
+#
+# Status code and timing are read from SEPARATE curl -w tokens, and a blank field is
+# reported as NOT_MEASURED rather than defaulted, so timing output can never be
+# misparsed as a status code (that mistake produced a 30/30 FAIL on a healthy service).
+PORT="${1:-9794}"
+AUTH="${2:-admin:DW2024!}"
+LABEL="${3:-run}"
+BASE="http://127.0.0.1:$PORT"
+TMP=$(mktemp -d)
+
+# probe <name> <path> <auth?> -> echoes "code=<n> bytes=<n> secs=<f>"
+probe() {
+  local path="$1" use_auth="$2" out="$TMP/body.$$"
+  local args=(-s -o "$out" -w 'CODE:%{http_code} BYTES:%{size_download} SECS:%{time_total}' --max-time 30)
+  [ "$use_auth" = "auth" ] && args+=(-u "$AUTH")
+  local raw; raw=$(curl "${args[@]}" "$BASE$path" 2>/dev/null)
+  local code bytes secs
+  code=$(printf '%s' "$raw" | sed -n 's/.*CODE:\([0-9]*\).*/\1/p')
+  bytes=$(printf '%s' "$raw" | sed -n 's/.*BYTES:\([0-9]*\).*/\1/p')
+  secs=$(printf '%s' "$raw" | sed -n 's/.*SECS:\([0-9.]*\).*/\1/p')
+  # a missing/blank field is NOT-MEASURED, never a silent pass
+  [ -z "$code" ] && code=000
+  [ -z "$bytes" ] && bytes=-1
+  [ -z "$secs" ] && secs=-1
+  echo "$code $bytes $secs"
+}
+
+echo "=== TK-11506 harness [$LABEL] port=$PORT $(date -u +%Y-%m-%dT%H:%M:%SZ) ==="
+echo "load: $(uptime | sed 's/.*load averages*://')"
+
+# --- 1. cold + warm /api/tickets ---
+read C1 B1 S1 <<<"$(probe /api/tickets auth)"
+read C2 B2 S2 <<<"$(probe /api/tickets auth)"
+read C3 B3 S3 <<<"$(probe /api/tickets auth)"
+echo "tickets#1 code=$C1 bytes=$B1 secs=$S1"
+echo "tickets#2 code=$C2 bytes=$B2 secs=$S2"
+echo "tickets#3 code=$C3 bytes=$B3 secs=$S3"
+
+for p in /api/agents /api/messages /api/skills; do
+  read C B S <<<"$(probe $p auth)"; echo "$(printf '%-14s' $p) code=$C bytes=$B secs=$S"
+done
+
+# --- 2. THE ACCEPTANCE TEST: /healthz while N /api/tickets are in flight ---
+N=6
+echo "--- healthz under load: $N concurrent /api/tickets in flight ---"
+for i in $(seq $N); do
+  curl -s -u "$AUTH" -o /dev/null --max-time 30 "$BASE/api/tickets" &
+done
+sleep 0.15   # let the requests land on the server
+WORST=0; FAILS=0; SAMPLES=0
+for i in $(seq 12); do
+  read C B S <<<"$(probe /healthz noauth)"
+  SAMPLES=$((SAMPLES+1))
+  echo "  healthz[$i] code=$C secs=$S"
+  if [ "$C" != "200" ]; then FAILS=$((FAILS+1)); fi
+  awk -v a="$S" -v b="$WORST" 'BEGIN{exit !(a>b)}' && WORST=$S
+  sleep 0.08
+done
+wait
+
+# --- 3. verdict (three states; an unmeasured probe is never green) ---
+echo "--- verdict ---"
+echo "healthz_samples=$SAMPLES healthz_non200=$FAILS healthz_worst_secs=$WORST"
+BAD=$(awk -v w="$WORST" 'BEGIN{print (w>0.5)?1:0}')
+if [ "$SAMPLES" -eq 0 ]; then
+  echo "VERDICT: NOT_MEASURED (no healthz samples)"; exit 3
+elif [ "$FAILS" -gt 0 ] || [ "$BAD" = "1" ]; then
+  echo "VERDICT: FAIL (healthz head-of-line blocked: $FAILS non-200, worst ${WORST}s > 0.5s budget)"; exit 1
+else
+  echo "VERDICT: PASS (healthz stayed responsive under $N concurrent /api/tickets; worst ${WORST}s)"; exit 0
+fi

← b65f87ae TK-11506: cache the materialized ticket fold so /api/tickets  ·  back to Ticket System  ·  TK-11506: bound cache retention with idle eviction 965470be →