test/wan.sh
Ref: Size: 76.4 KiB History
#!/usr/bin/env bash
# M6 WAN deployment + measurement harness.
#
# Deploys a static musl `mux` to a remote box, runs a session over it via
# `mux --via "<ssh> mux d proxy"`, and measures the numbers the M6 kill
# criterion is decided on:
#
# baseline raw byte round-trip through `<ssh> cat` — the floor mux is
# judged against, measured on the same warm channel
# attach client launch -> first painted byte
# echo keystroke -> that character painted back, through the WHOLE
# stack (ssh -> proxy -> daemon -> pty -> bash echo -> engine ->
# delta -> proxy -> ssh -> client paint)
# reattach kill -9 the client, relaunch, time to first painted byte, and
# check pre-kill session state is in that first paint
# hol echo latency while the session floods output (probes the
# proxy's known head-of-line blocking; recorded, not gated)
# reconnect M7: kill the ssh under a LIVE client N times; every tear must
# resume hands-off and be served by a delta (the remote
# daemon's snapshots counter must not move)
#
# M7 kill criterion (the retired plan is in git history):
# 10 consecutive transport kills against a live session, every one resumed
# with zero manual action, every one delta-served. The resume wall clock is
# printed, not gated: it necessarily includes the client's first backoff
# and an ssh channel open, so gating it would rule on ssh — the same
# reasoning as the M6 reattach ruling below.
#
# NARROWED, deliberately and on the record: the plan's criterion had a
# fourth element — "replica converged after the last tear (client render
# matches `mux d dump`)" — and this harness does NOT check that. The client
# emits a stream of paints, not a grid, so comparing it to a dump means
# parsing VT in the harness: a second terminal emulator, in Python, whose
# own bugs would then be indistinguishable from the ones it is meant to
# catch. (src/server/server.zig's tests do make that comparison, against a real
# replica Engine — over a socket, not over the WAN.) What is checked here
# instead: each tear round-trips a marker out to the remote shell and back
# through the rebuilt transport, and after the last tear the FIRST tear's
# marker must still be in the daemon's grid — accumulated state survived
# all ten resumes. That is the substitution, it is weaker than the plan's
# wording, and the full convergence check stays banked.
#
# M6 kill criterion (the retired plan is in git history):
# median echo <= baseline median + 120ms, and reattach <= ~2x the link
# round-trip "of the attach request" — i.e. measured from the attach, so
# the gate rules on the reattach's protocol share, with the measured ssh
# channel-open floor subtracted. Both that and the raw wall-clock number
# are printed; see the ruling at the reattach criterion below for why the
# wall clock cannot be the gate. Exits non-zero when either criterion
# fails. Do not tune the thresholds here; a failure is the milestone's
# answer.
#
# Ctrl-C inside a session used not to work at all when the daemon had been
# backgrounded by a non-interactive shell — which is how this script, e2e.sh
# and any deploy script start it. POSIX has such a shell set SIGINT/SIGQUIT
# to SIG_IGN for an async child; SIG_IGN survives exec, so the daemon passed it to
# the pty child, and a shell keeps signals ignored-on-entry ignored for the
# jobs it spawns. This run is what found it. FIXED in src/server/pty.zig, which now
# resets those dispositions in the forkpty child — see the comment there.
# The bounded flood in the head-of-line probe stays bounded anyway: that is
# a measurement constraint, not a workaround for this bug (see cmd_hol).
#
# NOT wired into build.zig: it needs a real remote box. The box is
# ephemeral and passed in by environment, never recorded in this file.
#
# MUX_WAN_SSH full ssh command string, incl. jump/control flags
# MUX_WAN_SCP matching scp command string (same ControlPath)
# MUX_WAN_HOST scp target prefix, e.g. user@host
# MUX_WAN_NETEM 1 to also measure under `netem delay 75ms loss 1%`
# MUX_WAN_REPS_RECONNECT M7 tears (default 10 — that IS the criterion)
# ZIG cross-compiling zig 0.15.2 (the Makefile's default)
set -euo pipefail
usage() {
cat >&2 <<'USAGE'
usage: MUX_WAN_SSH=... MUX_WAN_SCP=... MUX_WAN_HOST=... test/wan.sh
MUX_WAN_SSH ssh command string, e.g.
"ssh -o ControlMaster=auto -o ControlPath=/tmp/mux-cm \
-o ControlPersist=300 -J user@gate:2222 user@box"
(keep ControlPath short: long paths exceed sun_path)
MUX_WAN_SCP matching scp, e.g. "scp -o ControlPath=/tmp/mux-cm"
MUX_WAN_HOST scp target prefix, e.g. "user@box"
MUX_WAN_NETEM optional; 1 adds `delay 75ms loss 1%` on the box's
default interface and repeats the echo/reattach runs
USAGE
exit 2
}
[ -n "${MUX_WAN_SSH:-}" ] || usage
[ -n "${MUX_WAN_SCP:-}" ] || usage
[ -n "${MUX_WAN_HOST:-}" ] || usage
ROOT="$(cd "$(dirname "$0")/.." && pwd)"
ZIG="${ZIG:-$(dirname "$0")/../deps/zig/zig}"
MUX="$ROOT/zig-out/bin/mux"
REPS_ECHO="${MUX_WAN_REPS_ECHO:-20}"
REPS_BASE="${MUX_WAN_REPS_BASE:-20}"
REPS_ATTACH="${MUX_WAN_REPS_ATTACH:-3}"
REPS_REATTACH="${MUX_WAN_REPS_REATTACH:-3}"
REPS_HOL="${MUX_WAN_REPS_HOL:-5}"
# M7: the kill criterion names 10 consecutive tears; the default is the
# criterion, not a convenience.
REPS_RECONNECT="${MUX_WAN_REPS_RECONNECT:-10}"
# M9: keystrokes timed for leg 1, and adversarial bursts for leg 2. Ten
# bursts is the plan's number and therefore the default.
REPS_PREDICT="${MUX_WAN_REPS_PREDICT:-20}"
REPS_BURST="${MUX_WAN_REPS_BURST:-10}"
# Unique remote names: the box may be shared, and a crashed run must never
# leave a socket another run mistakes for its own.
TAG="wan-$$-$(date +%s)"
RBIN="/tmp/mux-$TAG"
RSOCK="/tmp/mux-$TAG.sock"
RLOG="/tmp/mux-$TAG.log"
# QUIC needs a key on both ends and a port of its own. The port is derived
# from the pid so two runs on one box cannot collide, and stays well clear
# of the ephemeral range.
RKEY="/tmp/mux-$TAG.key"
QPORT="${MUX_WAN_QPORT:-$(( 21000 + ($$ % 4000) ))}"
# Short on purpose. This is how fast a QUIC client notices a peer that has
# stopped answering, and it is pure configuration: the tear measurement below
# starts its clock after it, so a long value would only pad the wait while
# the client sat in a backoff it had already earned.
QIDLE="${MUX_WAN_QUIC_IDLE_MS:-400}"
FW_LEFT=0
WORK="$(mktemp -d "${TMPDIR:-/tmp}/mux-wan-XXXXXX")"
# Every attach records a wall tile in $XDG_STATE_HOME/mux/wall; without a
# hermetic home this suite's throwaway sockets pile up in the developer's
# real wall file and the hub tries to open them all.
XDG_STATE_HOME="$WORK/state"; XDG_CACHE_HOME="$WORK/cache"
export XDG_STATE_HOME XDG_CACHE_HOME
PY="$WORK/wan.py"
RESULTS="$WORK/results"
ERRLOG="$WORK/client.err"
: > "$RESULTS"
NETEM_IFACE=""
# Every remote pattern below is bracketed ('[m]uxd-') so it matches the
# processes we started but not the ssh-spawned shell running the pkill,
# whose own command line necessarily contains the pattern's text.
DEADMAN_SECS=900
NETEM_LEFT=0
DEADMAN_PGID=""
# Undo the netem qdisc and cancel its deadman. Degrading someone else's box
# is the one thing here that outlives the run, so this verifies against the
# box instead of believing an exit status.
netem_off() {
[ -n "$NETEM_IFACE" ] || return 0
local iface="$NETEM_IFACE"
NETEM_IFACE=""
# By process group, not by name: the deadman is a shell plus the `sleep`
# it is waiting on, and killing only the shell orphans a bare `sleep 900`
# that no safe pattern can pick out of someone else's processes. setsid
# made the pair its own group precisely so this one signal ends both.
if [ -n "$DEADMAN_PGID" ]; then
timeout 60 $MUX_WAN_SSH "sudo -n kill -TERM -$DEADMAN_PGID" >/dev/null 2>&1 || true
DEADMAN_PGID=""
fi
# Separate invocation, deliberately: a pkill sharing its remote shell
# with the tc command matches that shell's own command line and kills it
# before the qdisc is ever removed. That is not hypothetical — it left
# netem running on the box during development.
timeout 60 $MUX_WAN_SSH \
"sudo -n pkill -f '[s]leep $DEADMAN_SECS; tc qdisc del dev $iface'" \
>/dev/null 2>&1 || true
timeout 60 $MUX_WAN_SSH "sudo -n tc qdisc del dev $iface root" >/dev/null 2>&1 || true
if timeout 60 $MUX_WAN_SSH "tc qdisc show dev $iface" 2>/dev/null | grep -q netem; then
NETEM_LEFT=1
echo " WARNING: netem is STILL on $iface. Remove it by hand:"
echo " \$MUX_WAN_SSH 'sudo tc qdisc del dev $iface root'"
else
echo " netem removed from $iface (verified against the box)"
fi
}
cleanup() {
local rc=$?
echo
echo "-- cleanup"
netem_off
# The pkills travel alone: any command sharing their remote shell would
# put the tag in that shell's own command line, and -f would kill the
# shell before the rest of the line ran.
timeout 60 $MUX_WAN_SSH "pkill -f '[m]uxd-$TAG'" >/dev/null 2>&1 || true
sleep 0.5
timeout 60 $MUX_WAN_SSH "pkill -9 -f '[m]uxd-$TAG'" >/dev/null 2>&1 || true
# Tagged with this run's name so removal is exact. Looped because
# -D removes one matching rule per call and a crashed rep can leave
# more than one.
local fw_tries=0
while timeout 60 $MUX_WAN_SSH "sudo -n iptables -S INPUT 2>/dev/null | grep -q 'mux-$TAG'" 2>/dev/null; do
timeout 60 $MUX_WAN_SSH "sudo -n iptables -D INPUT -p udp --dport $QPORT \
-m comment --comment mux-$TAG -j DROP" >/dev/null 2>&1 || break
fw_tries=$((fw_tries + 1))
[ "$fw_tries" -lt 20 ] || break
done
if timeout 60 $MUX_WAN_SSH "sudo -n iptables -S INPUT 2>/dev/null | grep -q 'mux-$TAG'" 2>/dev/null; then
FW_LEFT=1
echo " WARNING: a udp DROP rule tagged mux-$TAG is STILL on the box:"
echo " \$MUX_WAN_SSH 'sudo iptables -D INPUT -p udp --dport $QPORT -m comment --comment mux-$TAG -j DROP'"
elif [ "$fw_tries" -gt 0 ]; then
echo " firewall rules removed ($fw_tries) — verified against the box"
fi
timeout 60 $MUX_WAN_SSH "rm -f $RBIN $RSOCK $RLOG $RKEY" \
>/dev/null 2>&1 || echo " WARNING: remote file cleanup failed; check for $TAG"
local left
left="$(timeout 60 $MUX_WAN_SSH "pgrep -af '[m]uxd-$TAG' || true" 2>/dev/null || true)"
if [ -n "$left" ]; then
echo " WARNING: remote processes survived: $left"
else
echo " remote clean (no mux-$TAG processes, files removed)"
fi
rm -rf "$WORK"
# A box left degraded is a failure of this script whatever the
# measurements said. A firewall rule counts as degraded: it silently
# blackholes a port for everyone.
[ "$NETEM_LEFT" -eq 0 ] || rc=3
[ "$FW_LEFT" -eq 0 ] || rc=3
exit $rc
}
trap cleanup EXIT INT TERM
say() { echo; echo "== $*"; }
# Run one python measurement; echo its human output, bank its #RESULT lines
# under a phase name so the summary can find them.
measure() {
local phase="$1"; shift
local out
if ! out="$(python3 "$PY" "$@" 2>&1)"; then
echo "$out"
echo "wan FAIL: measurement '$*' failed" >&2
[ -s "$ERRLOG" ] && { echo "-- client stderr:"; tail -30 "$ERRLOG"; }
# The daemon's own view, which is where a handshake failure that
# looks identical from outside (full session, wrong key, no
# listener) actually distinguishes itself.
echo "-- remote stats:"; timeout 30 $MUX_WAN_SSH "$RBIN d stats --sock $RSOCK" 2>&1 | tail -2 || true
echo "-- remote daemon log:"; timeout 30 $MUX_WAN_SSH "tail -20 $RLOG" 2>&1 || true
exit 1
fi
echo "$out" | grep -v '^#RESULT' || true
echo "$out" | sed -n "s/^#RESULT /$phase /p" >> "$RESULTS"
}
# val <phase> <name> <key> — pull one number out of the banked results.
val() {
awk -v p="$1" -v n="$2" -v k="$3" \
'$1==p && $2==n { for (i=3;i<=NF;i++) { split($i,kv,"="); if (kv[1]==k) { print kv[2]; exit } } }' \
"$RESULTS"
}
cat > "$PY" <<'PYEOF'
"""Timing helpers for wan.sh. Shell byte-timing is too crude for this: the
numbers are tens of milliseconds and must be taken around a single write().
Each subcommand prints human-readable lines plus one '#RESULT <name> k=v...'
line that wan.sh banks for the summary."""
import os
import re
import select
import shlex
import signal
import statistics
import subprocess
import sys
import time
TIMEOUT = 25.0
# The flood probe can deliver output faster than any test needs to remember,
# so the capture is a sliding window. Every needle waited for below is either
# unique to its rep or is matched within a paint or two of being typed, so
# dropping the oldest bytes cannot lose a match.
MAXBUF = 4 << 20
# Flood length in ticks of ~10ms each: long enough to cover every rep of the
# probe with margin, short enough that the session frees itself afterwards.
FLOOD_TICKS = 900
# The typed run that the echo measurement grows one character at a time. It
# starts with '#' so the line is a bash comment: nothing this harness types
# can ever execute on the remote box, whatever arrives at the shell.
ECHO_RUN = b"#abcdefghijklmnopqrstuvwxyz"
def now():
return time.monotonic()
def fail(msg):
sys.stderr.write("wan.py: %s\n" % msg)
sys.exit(1)
def report(name, samples, **extra):
s = sorted(samples)
kv = "".join(" %s=%s" % (k, v) for k, v in extra.items())
print("#RESULT %s min=%.1f med=%.1f max=%.1f n=%d%s"
% (name, s[0], statistics.median(s), s[-1], len(s), kv))
print(" %-26s min=%7.1fms med=%7.1fms max=%7.1fms (n=%d)"
% (name, s[0], statistics.median(s), s[-1], len(s)))
class Client:
"""An attached mux client held open on pipes.
Its own session (start_new_session) so the kill test can take down the
whole transport — client and the ssh it spawned — the way closing a
terminal window does, instead of orphaning ssh on the far side.
"""
def __init__(self, mux, via, errlog):
env = dict(os.environ)
# Nothing may fall back to a local default socket: over-the-wire is
# the only path being measured.
env["XDG_RUNTIME_DIR"] = "/nonexistent-mux-wan"
self.errf = open(errlog, "ab")
# `via` is either a --via command string or, for QUIC, a complete
# argv tail beginning with quic:// — split on spaces, which is safe
# because the only things in it are a URL, a key path and a number.
args = [mux] + via.split() if via.startswith("quic://") else [mux, "--via", via]
self.p = subprocess.Popen(
args,
stdin=subprocess.PIPE, stdout=subprocess.PIPE, stderr=self.errf,
bufsize=0, start_new_session=True, env=env)
self.buf = bytearray()
self.total = 0
def send(self, data):
self.p.stdin.write(data)
self.p.stdin.flush()
def _absorb(self, chunk):
self.buf += chunk
# Counts every byte ever seen, including trimmed ones: quiescence has
# to be judged on arrivals, and len(buf) can shrink.
self.total += len(chunk)
if len(self.buf) > MAXBUF:
del self.buf[:len(self.buf) - MAXBUF // 2]
def wait_for(self, pred, timeout=TIMEOUT):
"""Read until pred(self.buf); return elapsed seconds, or None if the
deadline passed or the transport died."""
start = now()
deadline = start + timeout
while not pred(self.buf):
remain = deadline - now()
if remain <= 0:
return None
r, _, _ = select.select([self.p.stdout], [], [], remain)
if not r:
continue
chunk = os.read(self.p.stdout.fileno(), 65536)
if not chunk:
return None
self._absorb(chunk)
return now() - start
def drain(self, seconds):
"""Collect whatever arrives for a fixed window."""
deadline = now() + seconds
while True:
remain = deadline - now()
if remain <= 0:
return
r, _, _ = select.select([self.p.stdout], [], [], remain)
if not r:
return
chunk = os.read(self.p.stdout.fileno(), 65536)
if not chunk:
return
self._absorb(chunk)
def alive(self):
return self.p.poll() is None
def kill(self):
try:
os.killpg(self.p.pid, signal.SIGKILL)
except (ProcessLookupError, PermissionError):
pass
self._close()
def detach(self):
try:
self.send(b"\x1c\x1c")
self.p.wait(timeout=8)
except Exception:
self.kill()
return
self._close()
def _close(self):
for f in (self.p.stdin, self.p.stdout):
try:
f.close()
except Exception:
pass
try:
self.p.wait(timeout=5)
except Exception:
pass
self.errf.close()
def settle(c, what):
"""Wait for the first paint, then prove the remote bash is at a prompt
and echoing by typing ECHO_RUN's first character ('#') and waiting for
it to come back. Everything downstream then measures against a shell
known to be answering — and cmd_echo continues the run from there.
The wait is anchored past whatever the first paint already contained,
so a prompt that itself ends in '#' cannot satisfy it vacuously.
"""
if c.wait_for(lambda b: len(b) > 0) is None:
fail("%s: no first paint (transport never came up)" % what)
start = len(c.buf)
c.send(ECHO_RUN[:1])
if c.wait_for(lambda b, s=start: ECHO_RUN[:1] in b[s:]) is None:
fail("%s: remote shell never echoed (no prompt?)" % what)
def wait_idle(c, what, timeout=60.0):
"""Wait until the session stops producing output."""
deadline = now() + timeout
while now() < deadline:
before = c.total
c.drain(0.8)
if c.total == before:
return
fail("%s: session never went idle" % what)
def prove_alive(c, what):
"""Prove the remote shell is back at a prompt and running commands. The
flood probe is the only step that leaves work running on the far side,
and this harness has no way to interrupt it (it types bytes down a pipe;
it cannot press a key), so the session's return to health is checked
rather than assumed."""
wait_idle(c, what)
c.send(b"\x15printf 'holdone-%s\\n' ok\n")
if c.wait_for(lambda b: b"holdone-ok" in b) is None:
fail("%s: shell never came back to a prompt after the flood" % what)
def cmd_baseline(argv):
"""Raw byte round-trip through `<ssh> cat`: the link's own number, taken
on a warm channel so it measures the link and not session setup."""
ssh_cmd, reps = argv[0], int(argv[1])
p = subprocess.Popen(shlex.split(ssh_cmd) + ["cat"],
stdin=subprocess.PIPE, stdout=subprocess.PIPE, bufsize=0)
samples = []
try:
for i in range(reps + 3): # first three are warmup
t0 = now()
p.stdin.write(b"x")
p.stdin.flush()
r, _, _ = select.select([p.stdout], [], [], TIMEOUT)
if not r:
fail("baseline: no echo from `ssh cat` within %gs" % TIMEOUT)
if not os.read(p.stdout.fileno(), 4096):
fail("baseline: `ssh cat` closed the pipe")
if i >= 3:
samples.append((now() - t0) * 1000.0)
finally:
p.stdin.close()
p.stdout.close()
p.wait(timeout=10)
report("baseline", samples)
def cmd_viafloor(argv):
"""The floor under any `--via` launch: spawn the transport exactly the
way mux does — /bin/sh -c "<ssh> <remote program>" — and time until the
remote program's first byte reaches our stdout.
Attach and reattach both pay this before one protocol byte can move, so
it is what separates 'the session is slow to restore' from 'ssh takes
this long to open a channel'. Measured on the warm master, so it is
channel setup and remote exec, not authentication.
"""
ssh_cmd, reps = argv[0], int(argv[1])
samples = []
for i in range(reps + 1): # first is warmup
t0 = now()
p = subprocess.Popen(["/bin/sh", "-c", ssh_cmd + " printf x"],
stdout=subprocess.PIPE, bufsize=0)
r, _, _ = select.select([p.stdout], [], [], TIMEOUT)
if not r or not os.read(p.stdout.fileno(), 16):
fail("viafloor: the transport produced no byte")
if i > 0:
samples.append((now() - t0) * 1000.0)
p.stdout.close()
p.wait(timeout=10)
report("viafloor", samples)
def cmd_attach(argv):
"""Client launch to first painted byte."""
mux, via, reps, errlog = argv[0], argv[1], int(argv[2]), argv[3]
samples = []
for _ in range(reps):
t0 = now()
c = Client(mux, via, errlog)
if c.wait_for(lambda b: len(b) > 0) is None:
c.kill()
fail("attach: no first paint")
samples.append((now() - t0) * 1000.0)
c.detach()
report("attach", samples)
def cmd_echo(argv):
"""Keystroke to painted echo, through the whole stack.
Each rep types the next character of ECHO_RUN and waits for the run so
far to appear. A delta paints the changed row whole, so the grown run
lands in one piece; and because the run only ever grows, the string
being waited for cannot have been on screen before the keystroke that
completes it. That is what makes a plain substring search a valid clock.
"""
mux, via, reps, errlog = argv[0], argv[1], int(argv[2]), argv[3]
if reps > len(ECHO_RUN) - 1:
fail("echo: at most %d reps" % (len(ECHO_RUN) - 1))
c = Client(mux, via, errlog)
samples = []
try:
settle(c, "echo")
for i in range(1, reps + 1):
want = ECHO_RUN[:i + 1]
t0 = now()
c.send(ECHO_RUN[i:i + 1])
if c.wait_for(lambda b, w=want: w in b) is None:
fail("echo: rep %d never echoed %r" % (i, want))
samples.append((now() - t0) * 1000.0)
c.send(b"\n") # the run is a comment; this just clears the line
finally:
c.detach()
report("echo", samples)
def cmd_reattach(argv):
"""kill -9 the client, relaunch, time to first painted byte — and prove
the paint carries session state from before the kill."""
mux, via, reps, errlog = argv[0], argv[1], int(argv[2]), argv[3]
samples = []
marker_ok = 1
for i in range(reps):
nonce = "%d-%d" % (os.getpid(), i)
marker = ("wanmark-" + nonce).encode()
c = Client(mux, via, errlog)
settle(c, "reattach")
# The typed line holds "wanmark-%s" and the nonce as separate words,
# so the joined marker exists only if the remote shell ran printf.
c.send(b'\x15printf "wanmark-%s\\n" ' + nonce.encode() + b"\n")
if c.wait_for(lambda b, m=marker: m in b) is None:
c.kill()
fail("reattach: pre-kill marker never appeared")
c.kill()
t0 = now()
c2 = Client(mux, via, errlog)
first = c2.wait_for(lambda b: len(b) > 0)
if first is None:
c2.kill()
fail("reattach: relaunched client never painted")
samples.append((now() - t0) * 1000.0)
c2.drain(0.4) # the rest of that first paint
if marker not in c2.buf:
marker_ok = 0
print(" reattach rep %d: FIRST PAINT MISSING PRE-KILL MARKER %s"
% (i, marker.decode()))
c2.detach()
report("reattach", samples, marker_ok=marker_ok)
def transport_pid(client_pid):
"""The transport process under a client.
`mux --via CMD` spawns /bin/sh -c CMD, which execs ssh, so the client's
only child IS the transport. Selected by PARENT PID, never by a
command-line pattern: the client's own argv contains the whole --via
string, so a pattern kill takes out the very client under test. (That
mistake has already been made once in this project's e2e work; it is a
rule now, not a preference.)
`ps --ppid` is a GNU procps flag, which is fine here: this rig runs on
a Linux dev box against Linux boxes, and it is not part of the e2e
suite the platform layer keeps portable.
"""
out = subprocess.run(["ps", "--ppid", str(client_pid), "-o", "pid="],
capture_output=True, text=True).stdout.split()
return int(out[0]) if out else None
def remote_dump(ssh_cmd, rbin, rsock):
"""The daemon's authoritative grid, as it sees it."""
return subprocess.run(shlex.split(ssh_cmd) + ["%s d dump --sock %s" % (rbin, rsock)],
capture_output=True, text=True, timeout=60).stdout
def remote_snapshots(ssh_cmd, rbin, rsock):
"""The remote daemon's snapshots counter.
This is the whole M7 assertion: a resume served by snapshot renders
exactly like one served by delta, so the counter is the only witness to
which of the two actually happened.
"""
out = subprocess.run(shlex.split(ssh_cmd) + ["%s d stats --sock %s" % (rbin, rsock)],
capture_output=True, text=True, timeout=60).stdout
m = re.search(r"\bsnapshots=(\d+)", out)
if m is None:
fail("reconnect: no snapshots counter in remote stats %r" % out.strip())
return int(m.group(1))
def cmd_reconnect(argv):
"""M7: tear the transport under a live session N times over the real
link. Every tear must resume hands-off — nothing relaunches the client,
nothing retypes for it — and every resume must be served by a delta.
Timing note: the marker is typed only AFTER the resume is observed, not
before. Input typed while disconnected is dropped by policy, so typing
into the gap would measure the policy rather than the reconnect.
On the convergence check: the plan's criterion asked for the client's
render to match `mux d dump` after the last tear. That is NOT what this
measures — see the header note. What it does measure is that the FIRST
tear's marker is still in the daemon's grid after the LAST one, which
is the accumulated-state half of that claim and costs one ssh call.
"""
mux, via, reps, errlog = argv[0], argv[1], int(argv[2]), argv[3]
ssh_cmd, rbin, rsock = argv[4], argv[5], argv[6]
c = Client(mux, via, errlog)
samples = []
resumed = 0
snaps_before = snaps_after = -1
first_marker = None
survived = 0
try:
settle(c, "reconnect")
# Start the run on a cleared screen so all `reps` markers fit in one
# 24-row viewport (two rows each: the echoed command and its
# output). Without this the survival check below would be a coin
# flip on whether the first marker had scrolled out of the grid —
# `mux d dump` shows the viewport, not the scrollback.
c.send(b"\x15clear\n")
wait_idle(c, "reconnect")
# Taken after the session is up and quiet, so the first attach's own
# snapshot is already counted and anything after it is a resume.
snaps_before = remote_snapshots(ssh_cmd, rbin, rsock)
for i in range(reps):
child = transport_pid(c.p.pid)
if child is None:
fail("reconnect: rep %d found no transport to tear" % i)
before = c.total
t0 = now()
os.kill(child, signal.SIGKILL)
# First frame after the tear: the client rebuilt the transport,
# re-attached, and was answered. Hands-off from the kill to here.
if c.wait_for(lambda b, c=c, t=before: c.total > t) is None:
fail("reconnect: rep %d never resumed after the transport died" % i)
samples.append((now() - t0) * 1000.0)
resumed += 1
# ...and the session is really usable again, not merely painted:
# a round trip through the new transport, out to bash and back.
nonce = "%d-%d" % (os.getpid(), i)
marker = ("wanre-" + nonce).encode()
if first_marker is None:
first_marker = marker
c.send(b'\x15printf "wanre-%s\\n" ' + nonce.encode() + b"\n")
if c.wait_for(lambda b, m=marker: m in b) is None:
fail("reconnect: rep %d resumed but the input path is dead" % i)
print(" reconnect rep %-2d first frame %7.1fms session usable"
% (i, samples[-1]))
wait_idle(c, "reconnect")
snaps_after = remote_snapshots(ssh_cmd, rbin, rsock)
# Accumulated state survived every resume: work from before the
# first tear is still on the daemon's grid after the last one. The
# per-rep markers cannot show this — each only proves the session
# was usable at that moment, not that nothing was lost along the way.
dump = remote_dump(ssh_cmd, rbin, rsock)
survived = 1 if first_marker.decode() in dump else 0
if not survived:
print(" reconnect: FIRST TEAR'S MARKER %s IS GONE from the grid"
% first_marker.decode())
finally:
c.detach()
report("reconnect", samples, resumed=resumed, reps=reps,
snaps_before=snaps_before, snaps_after=snaps_after,
delta_served=1 if snaps_after == snaps_before else 0,
first_survived=survived)
def remote_clients(ssh_cmd, rbin, rsock):
"""How many client slots the daemon is holding right now.
A gauge rather than a counter, and the instrument for the banked
half-open question: a QUIC connection that completes its handshake and
never attaches occupies a slot until its idle timeout, which was
previously unobservable from outside the process.
"""
out = subprocess.run(shlex.split(ssh_cmd) + ["%s d stats --sock %s" % (rbin, rsock)],
capture_output=True, text=True, timeout=60).stdout
m = re.search(r"\bclients=(\d+)", out)
return int(m.group(1)) if m else -1
def cmd_quicreconnect(argv):
"""The QUIC tear: a real UDP blackhole on the box, not a killed process.
ACCOUNTING, because the two transports do not detect a tear the same way
and comparing them without saying so would be dishonest. ssh notices
instantly — the process dies and the pipe reports EOF — so its whole
measured interval is recovery. QUIC has nothing to notice: packets simply
stop, and the connection is declared dead by a TIMER whose length is
--quic-idle-ms, a knob we set. Including that timer would measure our own
configuration and call it a transport property.
So the sample clock starts when the drop is REMOVED, i.e. when recovery
first becomes possible, and the detection time is reported separately as
the idle setting it is. Both numbers are printed; neither is hidden.
"""
mux, via, reps, errlog = argv[0], argv[1], int(argv[2]), argv[3]
ssh_cmd, rbin, rsock = argv[4], argv[5], argv[6]
qport, tag, idle_ms = argv[7], argv[8], int(argv[9])
def firewall(action):
# Tagged with the run's own comment so removal can be exact and
# verified, and so a crashed run leaves something findable rather
# than an anonymous DROP on someone else's box.
rule = ("INPUT -p udp --dport %s -m comment --comment mux-%s -j DROP"
% (qport, tag))
subprocess.run(shlex.split(ssh_cmd) +
["sudo -n iptables -%s %s" % (action, rule)],
capture_output=True, text=True, timeout=60)
c = Client(mux, via, errlog)
samples = []
detect_ms = []
resumed = 0
snaps_before = snaps_after = -1
clients_peak = 0
first_marker = None
survived = 0
try:
settle(c, "quicreconnect")
c.send(b"\x15clear\n")
wait_idle(c, "quicreconnect")
snaps_before = remote_snapshots(ssh_cmd, rbin, rsock)
for i in range(reps):
before = c.total
firewall("I")
t_drop = now()
# Held past the idle timeout with margin, so the client cannot
# mistake the blackhole for a slow moment.
time.sleep((idle_ms / 1000.0) * 1.6)
seen = remote_clients(ssh_cmd, rbin, rsock)
if seen > clients_peak:
clients_peak = seen
firewall("D")
t0 = now()
detect_ms.append((t0 - t_drop) * 1000.0)
if c.wait_for(lambda b, c=c, t=before: c.total > t) is None:
fail("quicreconnect: rep %d never resumed after the blackhole lifted" % i)
samples.append((now() - t0) * 1000.0)
resumed += 1
nonce = "%d-%d" % (os.getpid(), i)
marker = ("wanq-" + nonce).encode()
if first_marker is None:
first_marker = marker
c.send(b'\x15printf "wanq-%s\\n" ' + nonce.encode() + b"\n")
if c.wait_for(lambda b, m=marker: m in b) is None:
fail("quicreconnect: rep %d resumed but the input path is dead" % i)
print(" quic tear rep %-2d recovery %7.1fms session usable"
% (i, samples[-1]))
wait_idle(c, "quicreconnect")
snaps_after = remote_snapshots(ssh_cmd, rbin, rsock)
dump = remote_dump(ssh_cmd, rbin, rsock)
survived = 1 if first_marker.decode() in dump else 0
if not survived:
print(" quicreconnect: FIRST TEAR'S MARKER %s IS GONE from the grid"
% first_marker.decode())
finally:
firewall("D") # belt and braces; the shell trap verifies
c.detach()
report("quicreconnect", samples, resumed=resumed, reps=reps,
snaps_before=snaps_before, snaps_after=snaps_after,
delta_served=1 if snaps_after == snaps_before else 0,
first_survived=survived, clients_peak=clients_peak,
detect_ms=int(sum(detect_ms) / max(1, len(detect_ms))))
def cmd_quicabort(argv):
"""Ctrl-\ against a port that will never answer.
A blackholed port, not a closed one: a closed port answers ICMP, which
since M15 the client acts on — the dial dies in ~1 RTT and this would
measure the kernel rather than the abort key. Silence is what still
runs the attach budget out, so a blackhole is the only way to hold a
handshake open long enough for the property to be observed.
`bound_ms` is that budget (client.QuicTarget.deadline_ms, 2000), not
the connection's idle timeout, which no longer ends a dial.
"""
mux, spec, errlog, bound_ms = argv[0], argv[1], argv[2], int(argv[3])
c = Client(mux, spec, errlog)
t0 = now()
time.sleep(0.3)
c.send(b"\x1c")
try:
c.p.wait(timeout=bound_ms / 1000.0 * 0.8)
except Exception:
c.kill()
fail("quicabort: Ctrl-\\ went unanswered for most of the %dms bound" % bound_ms)
elapsed = (now() - t0) * 1000.0
c._close()
# Gated, not merely reported: an abort that is answered by the dial
# failing on its own exits 1, and without this the scenario would pass
# on the very outcome it exists to rule out.
if c.p.returncode != 0:
fail("quicabort: client exited %s (want 0; an abort is not a failure)"
% c.p.returncode)
report("quicabort", [elapsed], bound_ms=bound_ms, rc=c.p.returncode)
def cmd_hol(argv):
"""Echo latency while the session floods output. The proxy is a byte
pump with no notion of priority, so a flood shares the pipe with the
keystroke's echo; this number is the size of that effect. Recorded for
the record, not gated.
The flood is bounded and self-terminating because nothing here may
depend on interrupting it: this harness drives the session over a pipe,
so it types bytes rather than pressing keys, and an unbounded flood that
outlived its rep would silently add itself to every measurement taken
afterwards. (Until 153cb5f such a flood was also literally unstoppable —
Ctrl-C was dead in any script-started session; that is fixed in
src/server/pty.zig, and the bound is kept for the reason above.)
The flood is one line every 10ms, not `yes` at full tilt, and the rate
is the measurement, not a courtesy. A scrolling line rewrites every row,
so each tick costs a near-full-screen delta: ~100 of them a second is
already far more than an interactive link carries. Going faster does not
load the wire any further (the daemon sends grid states, not pty bytes)
and it destroys the measurement — under `yes` the echoed character is
scrolled off screen between two deltas and is never transmitted at all,
so there is nothing left to time.
"""
mux, via, reps, errlog = argv[0], argv[1], int(argv[2]), argv[3]
c = Client(mux, via, errlog)
samples = []
try:
settle(c, "hol")
c.send(b"\x15for ((i=0;i<%d;i++)); do echo wanflood; sleep 0.01; done\n"
% FLOOD_TICKS)
c.drain(1.5) # let the flood reach steady state
for i in range(reps):
# Unique per rep, and absent from the flood's own text, so a
# plain search cannot match an earlier rep or the flood itself.
tok = b"ZQXJ" + bytes([ord("A") + i])
t0 = now()
c.send(tok)
if c.wait_for(lambda b, t=tok: t in b, timeout=20) is None:
if not c.alive():
print(" hol: client died under the flood after %d reps" % i)
break
print(" hol: rep %d never echoed within 20s" % i)
break
samples.append((now() - t0) * 1000.0)
if c.alive():
prove_alive(c, "hol")
finally:
c.kill()
if not samples:
print("#RESULT hol min=0.0 med=0.0 max=0.0 n=0")
print(" hol: not measurable (no echo observed under flood)")
return
report("hol", samples)
def predict_stats(errlog):
"""The client's MUX_PREDICT_STATS line, as a dict. The LAST one in the
file: the log is appended to across a run, and only this phase's client
is being asked about."""
try:
with open(errlog, "rb") as f:
lines = [l for l in f.read().split(b"\n") if l.startswith(b"predict ")]
except OSError:
return {}
if not lines:
return {}
out = {}
for tok in lines[-1].decode("ascii", "replace").split()[1:]:
k, _, v = tok.partition("=")
try:
out[k] = int(v)
except ValueError:
pass
return out
def enter_cat(c, what):
"""Put the remote session into a genuinely canonical, echoing reader.
An interactive bash prompt is icanon=0/echo=0 — readline echoes for
itself — so it is the ADAPTIVE tier, where display has to be earned over
two confirmations. `cat` is the tier this leg is about: the line
discipline echoes, so a prediction is a deduction and paints from the
first keystroke. Returns once a prediction has actually been observed,
which is the only proof that the mode reached the client.
"""
c.send(b"cat\n")
deadline = now() + 20.0
probe = b"~"
while now() < deadline:
start = len(c.buf)
c.send(probe)
if c.wait_for(lambda b, s=start: b"\x1b[4m" in b[s:], timeout=3.0) is not None:
# Let the authoritative echo of the probe land, so the run
# measured below starts from a settled screen.
c.drain(0.5)
return
fail("%s: no prediction ever painted; the session never reached the "
"always-predict tier (is `cat` running on the far side?)" % what)
def cmd_predict(argv):
"""M9 leg 1: the predicted glyph, and the authoritative echo of the SAME
keystroke, timed from the same instant.
That pairing is the measurement. One number is supposed to be a function
of the local paint and nothing else; the other is supposed to be a
function of the path. Taking them from one keystroke on one connection
means no argument about warm caches or differing conditions can be made
about the gap between them — and the control is what proves the harness
is measuring the path at all rather than the hardware.
"""
mux, via, reps, errlog = argv[0], argv[1], int(argv[2]), argv[3]
if reps > len(ECHO_RUN) - 1:
fail("predict: at most %d reps" % (len(ECHO_RUN) - 1))
c = Client(mux, via, errlog)
pred, auth = [], []
try:
settle(c, "predict")
enter_cat(c, "predict")
run = b""
for i in range(reps):
ch = ECHO_RUN[i + 1:i + 2] # skip the leading '#'
run += ch
start = len(c.buf)
t0 = now()
c.send(ch)
# The prediction: painted locally, underlined, at the cell the
# cursor is on. Searched from `start` so a repeat of the same
# character cannot match an earlier rep's paint.
if c.wait_for(lambda b, s=start, x=ch: b"\x1b[4m" + x in b[s:],
timeout=10.0) is None:
fail("predict: rep %d was never predicted" % i)
pred.append((now() - t0) * 1000.0)
# The authoritative echo of the same keystroke. Two conditions
# make a plain substring search a valid clock here, and BOTH
# were got wrong first time round:
#
# - Search from `start`, not the whole buffer. Searching
# everything let rep 0's needle match the shell's echo of
# the `cat` command typed during setup, stopping the clock
# at ~0 and putting an artifact in the record.
# - Needle of at least two characters. Predictions paint one
# cell at a time with a cursor move between them, so a run
# of two or more appears contiguously ONLY in a daemon row
# paint — but a one-character needle is a substring of the
# prediction's own `ESC[4mX` and would time that instead.
# So rep 0 contributes no authoritative sample; it cannot,
# and inventing one is how the first artifact got in.
if c.wait_for(lambda b, w=run, s=start: w in b[s:],
timeout=20.0) is None:
fail("predict: rep %d never echoed authoritatively" % i)
if len(run) >= 2:
auth.append((now() - t0) * 1000.0)
# The control the criterion asks for: input prediction does NOT
# apply to, timed on the same connection in the same run.
#
# "Echo-off context" is the plan's wording and it cannot be timed as
# written — with echo off nothing is painted at all, so there is no
# arrival to put a clock on. The measurable form of the same claim is
# input the overlay REFUSES: two characters in one write reach the
# client as one chunk, which is refused for being multi-byte, so the
# glyphs cannot appear until the daemon answers. If prediction were
# secretly doing the work in the numbers above, these would be fast
# too. They are not, and that is the point of measuring them.
off = []
for i in range(min(reps, 10)):
pair = bytes("Q%d" % i, "ascii")
start = len(c.buf)
t0 = now()
c.send(pair) # ONE write, so ONE read at the far end
if c.wait_for(lambda b, w=pair, s=start: w in b[s:],
timeout=20.0) is None:
fail("predict: unpredicted control %d never painted" % i)
off.append((now() - t0) * 1000.0)
c.drain(0.1)
# Deliberately no EOF to end `cat`. Ending it means the next
# keystroke lands at a bash prompt, which is a different termios and
# therefore a different prediction tier — and over a 150ms path the
# EOF may not even have been processed before this client detaches,
# so the following phase would find a session in a state that
# depended on timing. Leaving the reader running is the state the
# next phase wants anyway; the daemon is torn down at cleanup.
c.drain(0.5)
finally:
c.detach()
st = predict_stats(errlog)
report("predict", pred, **{k: st.get(k, -1) for k in
("made", "displayed", "confirmed",
"contradicted", "expired", "abandoned",
"suppressed")})
report("predictauth", auth)
report("predictoff", off)
def cmd_predictburst(argv):
"""M9 leg 2: adversarial bursts, then convergence by attribution.
Each burst types faster than the path can answer, which is the case that
used to refute itself once per round trip. Convergence is asserted the
way this harness asserts everything else about a client's grid — through
the daemon and the counters, not by parsing VT in the harness. Every
prediction must end accounted for (made = confirmed + abandoned, with
nothing left pending) and the daemon's grid must hold what was typed.
"""
mux, via, bursts, errlog = argv[0], argv[1], int(argv[2]), argv[3]
ssh_cmd, rbin, rsock = argv[4], argv[5], argv[6]
c = Client(mux, via, errlog)
conv = []
try:
settle(c, "predictburst")
enter_cat(c, "predictburst")
for b_i in range(bursts):
word = bytes("bst%02d" % b_i, "ascii")
start = len(c.buf)
t0 = now()
# Paced, not blasted. Sent back to back they arrive at the
# client as ONE read, which is a multi-byte chunk and is refused
# for being one — so the burst would be measured with no
# predictions in it at all, and the leg would pass while proving
# nothing. 20ms apart is five separate keystrokes inside 80ms,
# still far inside the 150ms round trip, so every one of them is
# outstanding when the first answer arrives. That is the burst
# this leg is about.
for ch in word:
c.send(bytes([ch]))
time.sleep(0.02)
if c.wait_for(lambda b, w=word, s=start: w in b[s:],
timeout=25.0) is None:
fail("predictburst: burst %d never converged" % b_i)
conv.append((now() - t0) * 1000.0)
c.send(b"\n")
c.drain(0.3)
# Read the daemon's grid while this client is still attached: the
# detach below is what makes the counters printable, and anything
# sent to get there could change the screen the check is about.
grid = remote_dump(ssh_cmd, rbin, rsock)
finally:
c.detach()
st = predict_stats(errlog)
made = st.get("made", -1)
confirmed = st.get("confirmed", 0)
abandoned = st.get("abandoned", 0)
pending = made - confirmed - abandoned if made >= 0 else -1
last = "bst%02d" % (bursts - 1)
converged = 1 if last in grid else 0
report("predictburst", conv, made=made, confirmed=confirmed,
abandoned=abandoned, pending=pending,
contradicted=st.get("contradicted", -1),
expired=st.get("expired", -1), converged=converged)
COMMANDS = {
"predict": cmd_predict,
"predictburst": cmd_predictburst,
"baseline": cmd_baseline,
"viafloor": cmd_viafloor,
"attach": cmd_attach,
"echo": cmd_echo,
"reattach": cmd_reattach,
"reconnect": cmd_reconnect,
"quicreconnect": cmd_quicreconnect,
"quicabort": cmd_quicabort,
"hol": cmd_hol,
}
if len(sys.argv) < 2 or sys.argv[1] not in COMMANDS:
fail("usage: wan.py {%s} ..." % "|".join(COMMANDS))
COMMANDS[sys.argv[1]](sys.argv[2:])
PYEOF
say "warming the ssh control master"
$MUX_WAN_SSH true || { echo "wan FAIL: cannot reach the box with MUX_WAN_SSH" >&2; exit 1; }
say "deploying a static musl mux to $MUX_WAN_HOST:$RBIN"
(cd "$ROOT" && "$ZIG" build -Dtarget=x86_64-linux-musl)
$MUX_WAN_SCP "$ROOT/zig-out/bin/mux" "$MUX_WAN_HOST:$RBIN"
$MUX_WAN_SSH "chmod +x $RBIN && file $RBIN 2>/dev/null | head -1" || true
# The local mux must be native again before anything measures it.
make -C "$ROOT" build >/dev/null
[ -x "$MUX" ] || { echo "wan FAIL: no native mux at $MUX" >&2; exit 1; }
VIA="$MUX_WAN_SSH $RBIN d proxy --sock $RSOCK"
say "baseline: raw byte round-trip through \`ssh cat\` ($REPS_BASE reps)"
measure clean baseline "$MUX_WAN_SSH" "$REPS_BASE"
measure clean viafloor "$MUX_WAN_SSH" 5
QUIC_ARGS=""
LKEY=""
if [ "${MUX_WAN_QUIC:-}" = "1" ]; then
say "deploying a QUIC key (owner-only, both ends)"
LKEY="$WORK/mux-$TAG.key"
head -c 32 /dev/urandom > "$LKEY"
chmod 600 "$LKEY"
$MUX_WAN_SCP "$LKEY" "$MUX_WAN_HOST:$RKEY"
# The daemon refuses a group- or world-readable key, exactly as ssh does, so
# this is required rather than tidy.
$MUX_WAN_SSH "chmod 600 $RKEY"
QUIC_ARGS="--quic 0.0.0.0:$QPORT --key $RKEY --quic-idle-ms 15000"
echo " udp $QPORT, key $RKEY"
fi
say "starting the remote daemon"
$MUX_WAN_SSH "rm -f $RSOCK; nohup $RBIN d start --sock $RSOCK --shell /bin/bash \
$QUIC_ARGS >$RLOG 2>&1 </dev/null & sleep 0.2"
i=0
until $MUX_WAN_SSH "test -S $RSOCK" 2>/dev/null; do
i=$((i + 1))
[ "$i" -lt 20 ] || { echo "wan FAIL: remote socket never appeared" >&2
$MUX_WAN_SSH "cat $RLOG" || true; exit 1; }
sleep 0.5
done
sleep 1.5 # let bash reach a prompt on its pty
RPID="$($MUX_WAN_SSH "pgrep -f '[m]uxd-$TAG' | head -1" | tr -cd '0-9')"
echo " daemon up on $RSOCK (remote pid ${RPID:-unknown})"
say "attach latency (launch -> first painted byte, $REPS_ATTACH reps)"
measure clean attach "$MUX" "$VIA" "$REPS_ATTACH" "$ERRLOG"
say "keystroke echo through the full stack ($REPS_ECHO reps)"
measure clean echo "$MUX" "$VIA" "$REPS_ECHO" "$ERRLOG"
say "reattach after kill -9 ($REPS_REATTACH reps)"
measure clean reattach "$MUX" "$VIA" "$REPS_REATTACH" "$ERRLOG"
# M7. Measured on the clean link only: the criterion is about resuming at
# all, hands-off, and being served a delta while doing it — none of which
# netem's added delay makes more or less true, and each tear costs a real
# ssh channel open.
say "M7 reconnect: tear the transport under a live session ($REPS_RECONNECT tears)"
measure clean reconnect "$MUX" "$VIA" "$REPS_RECONNECT" "$ERRLOG" \
"$MUX_WAN_SSH" "$RBIN" "$RSOCK"
if [ "${MUX_WAN_QUIC:-}" = "1" ]; then
# One daemon, two transports, one link, one run: the ssh-via numbers
# above and the QUIC numbers below are the same session over the same
# wire, which is what makes them comparable at all.
QHOST="${MUX_WAN_QUIC_HOST:-$(echo "$MUX_WAN_HOST" | sed 's/.*@//')}"
QSPEC="quic://$QHOST:$QPORT --key $LKEY --quic-idle-ms $QIDLE"
# OUR daemon owns that port, not merely somebody's socket. Matching the
# port alone in the remote box's /proc/net/udp would pass just as
# happily on a stranger's listener, and then every QUIC number below
# would be measuring a handshake against something else entirely. (The
# read runs over ssh on a Linux box, so its own /proc and `ss` are the
# oracle there; e2e_lib.sh's helpers answer about the local box.)
say "QUIC: checking the daemon owns udp $QPORT"
# Matched on PID, not on name: ss truncates a process name to 15
# characters, and a tag this long is exactly the kind of thing that
# silently never matches.
QOWNER="$($MUX_WAN_SSH "ss -ulnp 2>/dev/null | grep ':$QPORT ' || true")"
echo " $QOWNER"
case "$QOWNER" in
*"pid=$RPID,"*) : ;;
*) echo "wan FAIL: udp $QPORT is not held by our daemon (pid $RPID)" >&2
$MUX_WAN_SSH "cat $RLOG" || true; exit 1 ;;
esac
echo " remote stats before QUIC: $($MUX_WAN_SSH "$RBIN d stats --sock $RSOCK")"
say "QUIC attach latency (launch -> first painted byte, $REPS_ATTACH reps)"
measure quic attach "$MUX" "$QSPEC" "$REPS_ATTACH" "$ERRLOG"
say "QUIC keystroke echo through the full stack ($REPS_ECHO reps)"
measure quic echo "$MUX" "$QSPEC" "$REPS_ECHO" "$ERRLOG"
say "QUIC tears: a real UDP blackhole on the box ($REPS_RECONNECT tears)"
measure quic quicreconnect "$MUX" "$QSPEC" "$REPS_RECONNECT" "$ERRLOG" \
"$MUX_WAN_SSH" "$RBIN" "$RSOCK" "$QPORT" "$TAG" "$QIDLE"
# The abort key against a port that will never answer. A DROP rather
# than an unused port: an unused one answers ICMP and the client gives
# up on its own — in ~1 RTT since M15 — which would measure the kernel
# instead of the property. The bound is the client's 2000ms attach
# budget, which is what ends this dial; no --quic-idle-ms, since the
# idle timeout does not bound a handshake and naming one here would
# suggest it does.
say "QUIC abort: Ctrl-\\ against a blackholed port"
QDEAD=$(( QPORT + 1 ))
$MUX_WAN_SSH "sudo -n iptables -I INPUT -p udp --dport $QDEAD \
-m comment --comment mux-$TAG -j DROP"
measure quic quicabort "$MUX" \
"quic://$QHOST:$QDEAD --key $LKEY" "$ERRLOG" 2000 || true
$MUX_WAN_SSH "sudo -n iptables -D INPUT -p udp --dport $QDEAD \
-m comment --comment mux-$TAG -j DROP" >/dev/null 2>&1 || true
fi
# Every clean-link figure is taken before the box is degraded, so a netem
# that failed to clear can never quietly relabel itself as the clean link.
say "head-of-line probe: echo while the session floods output ($REPS_HOL reps)"
measure clean hol "$MUX" "$VIA" "$REPS_HOL" "$ERRLOG"
if [ "${MUX_WAN_NETEM:-}" = "1" ]; then
# The interface facing US, not merely a default route. A dual-homed box
# has more than one default and `ip route show default` prints them all
# — shaping the wrong one produces a "netem" column that is really the
# clean link, which is worse than no measurement. Asking the box which
# device it would use to reach this client answers it exactly.
CLIENT_IP="$($MUX_WAN_SSH 'echo $SSH_CLIENT' | awk '{print $1}' | tr -d '\r\n')"
[ -n "$CLIENT_IP" ] || { echo "wan FAIL: cannot tell which address the box sees us on" >&2; exit 1; }
IFACE="$($MUX_WAN_SSH "ip route get $CLIENT_IP" | sed -n 's/.* dev \([^ ]*\).*/\1/p' | head -1 | tr -d '\r\n')"
[ -n "$IFACE" ] || { echo "wan FAIL: no default interface on the box" >&2; exit 1; }
# A root netem qdisc shapes egress only, so this adds ~75ms to the round
# trip, not ~150ms — measured, not assumed.
say "netem: delay 75ms loss 1% on $IFACE (~75ms added round-trip)"
$MUX_WAN_SSH "sudo -n tc qdisc add dev $IFACE root netem delay 75ms loss 1%"
NETEM_IFACE="$IFACE"
# Deadman switch. The trap is the normal path; this covers the one case
# the trap cannot — a hard kill of this script — because the qdisc we
# just installed degrades the box for everyone, not only for us. It is
# matched and cancelled by command line in netem_off.
DEADMAN_PGID="$($MUX_WAN_SSH "setsid sudo -n sh -c \
'sleep $DEADMAN_SECS; tc qdisc del dev $IFACE root' \
>/dev/null 2>&1 </dev/null & echo \$!" | tr -cd '0-9')" || true
measure netem baseline "$MUX_WAN_SSH" "$REPS_BASE"
measure netem viafloor "$MUX_WAN_SSH" 5
measure netem attach "$MUX" "$VIA" "$REPS_ATTACH" "$ERRLOG"
measure netem echo "$MUX" "$VIA" "$REPS_ECHO" "$ERRLOG"
measure netem reattach "$MUX" "$VIA" "$REPS_REATTACH" "$ERRLOG"
measure netem hol "$MUX" "$VIA" "$REPS_HOL" "$ERRLOG"
if [ "${MUX_WAN_QUIC:-}" = "1" ]; then
# Connection setup is the leg where the transports actually differ,
# and it is RTT that separates them: ssh pays a channel open, QUIC
# pays a handshake plus the Retry this listener always sends. At LAN
# RTT both round to nothing, so the comparison only means something
# once there is a real delay in the path.
say "QUIC attach under netem ($REPS_ATTACH reps)"
measure quicnetem attach "$MUX" "$QSPEC" "$REPS_ATTACH" "$ERRLOG"
say "QUIC echo under netem ($REPS_ECHO reps)"
measure quicnetem echo "$MUX" "$QSPEC" "$REPS_ECHO" "$ERRLOG"
fi
netem_off
fi
if [ "${MUX_WAN_PREDICT:-}" = "1" ]; then
# M9 leg 1 is only meaningful at RTT >= 50ms and the criterion names
# 150ms, so this phase brings its own delay rather than borrowing the
# 75ms one above. Same interface question, same dual-home trap: ask the
# box which device it would use to reach US.
CLIENT_IP="$($MUX_WAN_SSH 'echo $SSH_CLIENT' | awk '{print $1}' | tr -d '\r\n')"
[ -n "$CLIENT_IP" ] || { echo "wan FAIL: cannot tell which address the box sees us on" >&2; exit 1; }
PIFACE="$($MUX_WAN_SSH "ip route get $CLIENT_IP" | sed -n 's/.* dev \([^ ]*\).*/\1/p' | head -1 | tr -d '\r\n')"
[ -n "$PIFACE" ] || { echo "wan FAIL: no interface toward this client" >&2; exit 1; }
# A root qdisc shapes EGRESS only, so 150ms here is ~150ms of round
# trip, not 300ms. The criterion asks for >=150ms RTT; the baseline
# printed below is what settles whether it got it.
say "M9: netem delay 150ms on $PIFACE (~150ms added round-trip)"
$MUX_WAN_SSH "sudo -n tc qdisc add dev $PIFACE root netem delay 150ms"
NETEM_IFACE="$PIFACE"
DEADMAN_PGID="$($MUX_WAN_SSH "setsid sudo -n sh -c \
'sleep $DEADMAN_SECS; tc qdisc del dev $PIFACE root' \
>/dev/null 2>&1 </dev/null & echo \$!" | tr -cd '0-9')" || true
# The path's own number under this delay, so leg 1's control has
# something measured to be compared against rather than the nominal
# 150ms the qdisc was asked for.
measure predict baseline "$MUX_WAN_SSH" "$REPS_BASE"
say "M9 leg 1: predicted paint vs the same keystroke's authoritative echo"
MUX_PREDICT_STATS=1 measure predict predict \
"$MUX" "$VIA" "$REPS_PREDICT" "$WORK/predict.err"
say "M9 leg 2: $REPS_BURST adversarial bursts, convergence by attribution"
MUX_PREDICT_STATS=1 measure predict predictburst \
"$MUX" "$VIA" "$REPS_BURST" "$WORK/burst.err" \
"$MUX_WAN_SSH" "$RBIN" "$RSOCK"
netem_off
fi
# ---- M18: named sessions over the real link -------------------------------
# Everything above drives the DEFAULT session, because everything above
# predates M18. This is the leg that asks whether a session NAME survives a
# real link — not a loopback, not a container bridge. Three claims, each its
# own assertion: two named sessions on one remote daemon hold only their own
# content; the default session holds neither; and re-attaching BY NAME lands
# back in the shell that name already had rather than in a fresh one.
#
# Deliberately placed after every measurement above. It leaves two more
# shells on the box, and a session that exists is a session the timing legs
# would otherwise have shared a daemon with.
#
# Those two shells are left behind ON PURPOSE and re-running is safe, which
# is worth saying because "leaves sessions on the box" reads as a leak. The
# daemon here is this run's own ($RBIN on $RSOCK, torn down with it), so
# nothing outlives the harness. And within a run the leg is idempotent by
# construction: attach-or-create REJOINS `a` and `b` rather than failing on
# them, and every marker carries $$, so a grid left by an earlier run can
# never satisfy a later run's grep.
say "M18: named sessions over the real link"
M18_OK=1
M18_N="$$"
for S in a b; do
# A marker the REMOTE shell has to expand: the typed line carries a
# literal %s, so the joined form can only exist if bash on the box ran
# printf. An echo of our own keystrokes cannot satisfy the greps below.
{ printf 'printf "wansess-%s-%%s\\n" %s\n' "$S" "$M18_N"; sleep 3; printf '\034\034'; } | \
timeout 90 "$MUX" --via "$VIA" --session "$S" > "$WORK/m18-$S.out" 2>&1
rc=$?
if [ "$rc" -ne 0 ]; then
echo " FAIL: --session $S over --via exited $rc"
sed -n '1,3p' "$WORK/m18-$S.out"
M18_OK=0
fi
done
if [ "$M18_OK" -eq 1 ]; then
A_GRID="$(timeout 60 $MUX_WAN_SSH "$RBIN d dump --sock $RSOCK --session a" 2>/dev/null)"
B_GRID="$(timeout 60 $MUX_WAN_SSH "$RBIN d dump --sock $RSOCK --session b" 2>/dev/null)"
D_GRID="$(timeout 60 $MUX_WAN_SSH "$RBIN d dump --sock $RSOCK" 2>/dev/null)"
# Positive AND negative per session: "a holds a's marker" is satisfied
# just as well by one shared shell, so only the negative separates them.
case "$A_GRID" in *"wansess-a-$M18_N"*) ;; *)
echo " FAIL: session a's marker is not on session a's grid"; M18_OK=0 ;; esac
case "$A_GRID" in *"wansess-b-$M18_N"*)
echo " FAIL: session b's marker is on session a's grid — one shell, not two"
M18_OK=0 ;; esac
case "$B_GRID" in *"wansess-b-$M18_N"*) ;; *)
echo " FAIL: session b's marker is not on session b's grid"; M18_OK=0 ;; esac
case "$B_GRID" in *"wansess-a-$M18_N"*)
echo " FAIL: session a's marker is on session b's grid — one shell, not two"
M18_OK=0 ;; esac
# The default session is the one every leg above drove. Neither name may
# have leaked into it.
case "$D_GRID" in *"wansess-a-$M18_N"*|*"wansess-b-$M18_N"*)
echo " FAIL: a named session's marker reached the default grid"; M18_OK=0 ;; esac
fi
if [ "$M18_OK" -eq 1 ]; then
# Re-attach by name: this must JOIN the shell `a` already has. The proof
# is both markers on one grid afterwards — a fresh shell would carry the
# new marker alone, which is exactly the failure a name that resolved
# per-connection would produce.
{ printf 'printf "wanre-%%s\\n" %s\n' "$M18_N"; sleep 3; printf '\034\034'; } | \
timeout 90 "$MUX" --via "$VIA" --session a > "$WORK/m18-re.out" 2>&1
rc=$?
if [ "$rc" -ne 0 ]; then
echo " FAIL: re-attach to session a exited $rc"; M18_OK=0
else
A2="$(timeout 60 $MUX_WAN_SSH "$RBIN d dump --sock $RSOCK --session a" 2>/dev/null)"
case "$A2" in *"wanre-$M18_N"*) ;; *)
echo " FAIL: the re-attach's own marker never reached session a"; M18_OK=0 ;; esac
case "$A2" in *"wansess-a-$M18_N"*) ;; *)
echo " FAIL: re-attaching to 'a' found a FRESH shell, not the one it named"
M18_OK=0 ;; esac
# ...and it joined rather than created: a fourth session here would
# mean the name resolved per-connection.
M18_STATS="$(timeout 60 $MUX_WAN_SSH "$RBIN d stats --sock $RSOCK" 2>/dev/null)"
case "$M18_STATS" in *"sessions=3"*) ;; *)
echo " FAIL: re-attach by name changed the session count: $M18_STATS"
M18_OK=0 ;; esac
fi
fi
if [ "$M18_OK" -eq 1 ]; then
echo " two named sessions isolated over the link; re-attach by name rejoined"
echo " its own shell; default session untouched; sessions=3"
fi
# ---- summary + the kill criterion -----------------------------------------
FAILED=0
# M18's leg is a functional gate, not a measured one. It is deliberately
# kept OUT of $FAILED: that variable drives the "kill criteria (M6 + M7)"
# line, and a named-session failure is not an M6 or M7 failure. Reported
# on its own below, and folded into the exit status there. (The first
# version of this did set FAILED, and the falsification run printed
# "kill criteria (M6 + M7): FAIL" for a defect in neither — which is how
# the mistake was found.)
phase_block() {
local phase="$1" label="$2"
local base echo_med reatt_med attach_med marker_ok
base="$(val "$phase" baseline med)"
echo_med="$(val "$phase" echo med)"
reatt_med="$(val "$phase" reattach med)"
attach_med="$(val "$phase" attach med)"
marker_ok="$(val "$phase" reattach marker_ok)"
[ -n "$base" ] || return 0
echo
echo "$label"
printf ' %-34s %8s %8s %8s %5s\n' "" min med max n
local name
for name in baseline viafloor attach echo reattach hol; do
[ -n "$(val "$phase" "$name" med)" ] || continue
printf ' %-34s %8s %8s %8s %5s\n' "$name" \
"$(val "$phase" "$name" min)" "$(val "$phase" "$name" med)" \
"$(val "$phase" "$name" max)" "$(val "$phase" "$name" n)"
done
echo " (all figures milliseconds)"
local budget verdict
budget="$(awk -v b="$base" 'BEGIN{printf "%.1f", b+120}')"
verdict="$(awk -v e="$echo_med" -v t="$budget" 'BEGIN{print (e<=t)?"PASS":"FAIL"}')"
printf ' echo criterion: med %s <= baseline med %s + 120 = %s -> %s (margin %s)\n' \
"$echo_med" "$base" "$budget" "$verdict" \
"$(awk -v e="$echo_med" -v t="$budget" 'BEGIN{printf "%+.1f", t-e}')"
[ "$verdict" = PASS ] || FAILED=1
# Both readings are printed; the exit status rules on the protocol's
# share, per the plan's "within ~2xRTT *of the attach request*".
#
# The ruling, recorded here so the gate is never mistaken for a threshold
# someone softened: a reattach cannot begin until ssh has opened a
# channel, and that floor is measured (`viafloor`), not assumed. Across
# the M6 runs it was 35.3-37.5ms against a 15.7-16.5ms round trip —
# 2.2-2.4xRTT, already past the whole 2xRTT budget before one protocol
# byte moves. Gating the wall-clock number would therefore fail on every
# fast link no matter what the protocol did, which gates nothing and
# cannot falsify a design. That is why this gate changed: the strict
# reading was gated first and printed FAIL, and the decomposition below
# is what showed the failure to be ssh's channel setup. The strict
# reading stays on the page because it is what a user waits through.
local floor protocol pverdict
floor="$(val "$phase" viafloor med)"
budget="$(awk -v b="$base" 'BEGIN{printf "%.1f", 2*b}')"
verdict="$(awk -v r="$reatt_med" -v t="$budget" 'BEGIN{print (r<=t)?"PASS":"FAIL"}')"
protocol="$(awk -v r="$reatt_med" -v f="$floor" 'BEGIN{printf "%.1f", r-f}')"
pverdict="$(awk -v p="$protocol" -v t="$budget" 'BEGIN{print (p<=t)?"PASS":"FAIL"}')"
printf ' reattach, wall clock (reported): med %s <= 2 x round-trip %s = %s -> %s (margin %s)\n' \
"$reatt_med" "$base" "$budget" "$verdict" \
"$(awk -v r="$reatt_med" -v t="$budget" 'BEGIN{printf "%+.1f", t-r}')"
printf ' decomposition: %s = %s transport setup (ssh channel open + exec) + %s protocol\n' \
"$reatt_med" "$floor" "$protocol"
printf ' reattach criterion (GATED, protocol share): %s <= %s -> %s (margin %s)\n' \
"$protocol" "$budget" "$pverdict" \
"$(awk -v p="$protocol" -v t="$budget" 'BEGIN{printf "%+.1f", t-p}')"
[ "$pverdict" = PASS ] || FAILED=1
printf ' reattach first paint carried pre-kill state: %s\n' \
"$([ "$marker_ok" = 1 ] && echo yes || echo NO)"
[ "$marker_ok" = 1 ] || FAILED=1
printf ' attach (fresh client, same path): med %s\n' "$attach_med"
}
# M7's own criterion: resumption is pass/fail, and the resume kind is read
# off the daemon's counters. The wall-clock column is printed and not gated,
# for the same reason the M6 reattach ruling above gives — every resume pays
# an ssh channel open (`viafloor`) before a protocol byte can move, so gating
# it would rule on ssh, not on this design.
m7_block() {
local resumed reps snaps_b snaps_a delta_served verdict floor survived
resumed="$(val clean reconnect resumed)"
[ -n "$resumed" ] || return 0
reps="$(val clean reconnect reps)"
snaps_b="$(val clean reconnect snaps_before)"
snaps_a="$(val clean reconnect snaps_after)"
delta_served="$(val clean reconnect delta_served)"
floor="$(val clean viafloor med)"
echo
echo "M7 reconnect (transport torn under a live session):"
printf ' %-34s %8s %8s %8s %5s\n' "" min med max n
printf ' %-34s %8s %8s %8s %5s\n' "first frame after tear" \
"$(val clean reconnect min)" "$(val clean reconnect med)" \
"$(val clean reconnect max)" "$(val clean reconnect n)"
echo " (milliseconds; one ssh channel open — measured just above as"
echo " viafloor med ${floor}ms — plus the protocol's own share. The"
echo " first attempt is immediate since M8 Task 0; before that this"
echo " number also carried a 200ms backoff that bought nothing."
echo " Printed, not gated, per the reattach ruling above)"
printf ' resumed hands-off: %s of %s\n' "$resumed" "$reps"
printf ' daemon snapshots across all tears: %s -> %s (%s)\n' \
"$snaps_b" "$snaps_a" \
"$([ "$delta_served" = 1 ] && echo "unchanged: every resume delta-served" \
|| echo "CHANGED: a resume fell back to a full snapshot")"
survived="$(val clean reconnect first_survived)"
printf ' first tear'"'"'s marker still on the grid after the last: %s\n' \
"$([ "$survived" = 1 ] && echo yes || echo NO)"
verdict=FAIL
[ "$resumed" = "$reps" ] && [ "$delta_served" = 1 ] && [ "$survived" = 1 ] &&
verdict=PASS
printf ' M7 criterion: %s tears, all resumed, all delta-served, state kept -> %s\n' \
"$reps" "$verdict"
[ "$verdict" = PASS ] || FAILED=1
}
echo
echo "=================== WAN measurement summary ======================"
echo "date: $(date -u +%Y-%m-%dT%H:%M:%SZ) host: (ephemeral, from MUX_WAN_SSH)"
phase_block clean "link as-is:"
phase_block netem "with netem delay 75ms loss 1%:"
m7_block
# ---- M8: the QUIC legs -----------------------------------------------------
if [ "${MUX_WAN_QUIC:-}" = "1" ]; then
q_attach="$(val quic attach med)"
q_echo="$(val quic echo med)"
q_tear="$(val quic quicreconnect med)"
q_detect="$(val quic quicreconnect detect_ms)"
q_snapb="$(val quic quicreconnect snaps_before)"
q_snapa="$(val quic quicreconnect snaps_after)"
q_resumed="$(val quic quicreconnect resumed)"
q_reps="$(val quic quicreconnect reps)"
q_survived="$(val quic quicreconnect first_survived)"
q_clients="$(val quic quicreconnect clients_peak)"
q_abort="$(val quic quicabort med)"
s_attach="$(val clean attach med)"
s_tear="$(val clean reconnect med)"
echo
echo "M8 QUIC (same daemon, same link, same run):"
printf ' %-40s %8s %8s\n' "" "quic" "ssh-via"
printf ' %-40s %8s %8s\n' "cold attach -> first paint (med ms)" "$q_attach" "$s_attach"
printf ' %-40s %8s %8s\n' "echo (med ms)" "$q_echo" "$(val clean echo med)"
printf ' %-40s %8s %8s\n' "tear -> usable (med ms)" "$q_tear" "$s_tear"
echo " tear accounting: the two transports do NOT detect a tear alike."
echo " ssh dies with its process, so EOF is instant and its whole"
echo " interval is recovery. QUIC has nothing to notice: it is declared"
echo " dead by a timer set to --quic-idle-ms (${QIDLE}ms here, ${q_detect}ms"
echo " of blackhole measured before the clock starts). The quic column"
echo " is measured from the blackhole LIFTING, so it excludes that"
echo " detection and includes whatever backoff the client had already"
echo " entered while it waited."
echo " leg 1 (semantics): resumed $q_resumed/$q_reps, snapshots $q_snapb -> $q_snapa, first marker kept: $q_survived"
echo " leg 3 (cold attach): quic $q_attach vs ssh-via $s_attach"
if [ -n "$(val quicnetem attach med)" ]; then
echo " leg 3 under netem (the RTT that makes setup mean something):"
echo " quic $(val quicnetem attach med) vs ssh-via $(val netem attach med) (echo: quic $(val quicnetem echo med) vs ssh-via $(val netem echo med))"
fi
echo " NOTE: the quic figure INCLUDES the Retry round trip — this"
echo " listener answers every fresh Initial with one, so address"
echo " validation is inside the number, not netted out of it. ssh pays"
echo " no such round trip. The comparison is therefore pessimistic for"
echo " QUIC by roughly one RTT."
echo " abort during handshake: ${q_abort}ms against a 15000ms bound"
echo " client slots held at peak during tears: $q_clients"
fi
echo
if [ "${M18_OK:-1}" -eq 1 ]; then
echo "M18 named sessions over the link: PASS"
else
echo "M18 named sessions over the link: FAIL"
fi
if [ "$FAILED" -eq 0 ]; then
echo "kill criteria (M6 + M7): PASS"
else
echo "kill criteria (M6 + M7): FAIL — report the numbers; do not tune the thresholds."
fi
# ---- M9 prediction ---------------------------------------------------------
if [ -n "$(val predict predict med)" ]; then
P_RTT="$(val predict baseline med)"
P_MED="$(val predict predict med)"
P_MAX="$(val predict predict max)"
P_AUTH="$(val predict predictauth med)"
echo
echo "M9 prediction (netem 150ms egress):"
printf ' %-34s %8s %8s %8s %5s\n' "" min med max n
for name in baseline predict predictoff predictauth predictburst; do
[ -n "$(val predict "$name" med)" ] || continue
printf ' %-34s %8s %8s %8s %5s\n' "$name" \
"$(val predict "$name" min)" "$(val predict "$name" med)" \
"$(val predict "$name" max)" "$(val predict "$name" n)"
done
echo " (all figures milliseconds)"
# The floor rule, applied rather than described: leg 1 says nothing at a
# round trip prediction could not plausibly beat, so below 50ms it is
# reported as not exercised — never as passed.
if awk -v r="$P_RTT" 'BEGIN{exit !(r < 50)}'; then
echo " leg 1: NOT EXERCISED — round trip $P_RTT ms is below the 50ms floor"
elif awk -v m="$P_MED" 'BEGIN{exit !(m <= 30)}'; then
P_OFF="$(val predict predictoff med)"
echo " leg 1: predicted paint med $P_MED <= 30ms (round trip $P_RTT ms)"
echo " control, unpredicted input (refused as multi-byte): med ${P_OFF:-ABSENT} ms"
echo " control, same keystroke's authoritative echo: med ${P_AUTH:-ABSENT} ms"
echo " Both track the measured round trip while the predicted number does"
echo " not, which is what rules out the harness having timed the hardware."
# A missing control is a FAILED leg, not a quiet one. Skipping the
# check when the number is absent is the same mistake as accepting a
# control that cannot fail: leg 1 would pass on the strength of a
# comparison nothing had made.
if [ -z "$P_OFF" ] || [ -z "$P_AUTH" ]; then
echo " leg 1 CONTROL MISSING: predictoff='${P_OFF:-}' predictauth='${P_AUTH:-}'."
echo " Leg 1 cannot pass without both — the predicted number alone says"
echo " nothing about the path it was measured over."
FAILED=1
# A control that came back fast means the "unpredicted" input was
# being predicted after all, and leg 1's number would be meaningless.
elif awk -v o="$P_OFF" -v r="$P_RTT" 'BEGIN{exit !(o < r/2)}'; then
echo " leg 1 CONTROL FAILED: unpredicted input came back in $P_OFF ms, well"
echo " under the $P_RTT ms path — it cannot have waited for the daemon,"
echo " so the comparison above proves nothing."
FAILED=1
else
echo " leg 1: PASS (threshold met, both controls present and slow)"
fi
else
echo " leg 1: predicted paint med $P_MED > 30ms -> FAIL (round trip $P_RTT ms)"
FAILED=1
fi
B_MADE="$(val predict predictburst made)"
B_PEND="$(val predict predictburst pending)"
B_CONF="$(val predict predictburst confirmed)"
B_ABND="$(val predict predictburst abandoned)"
B_CONV="$(val predict predictburst converged)"
B_CONTRA="$(val predict predictburst contradicted)"
B_EXP="$(val predict predictburst expired)"
if [ -n "$B_MADE" ]; then
echo " counters after $REPS_BURST bursts: made=$B_MADE confirmed=$B_CONF" \
"contradicted=$B_CONTRA expired=$B_EXP abandoned=$B_ABND pending=$B_PEND"
# The ceiling these numbers live under, printed WITH them because it
# is what decides whether they are reproducible on a slower path. A
# prediction is retired unanswered after expire_after_ms; the wait it
# actually has to survive is the round trip plus however long the
# burst's later keystrokes queue behind the earlier ones. Measured
# here as the burst's own convergence time. Cross this and the
# predictions expire mid-burst and the counters collapse — which is
# exactly what happened at 400ms each way in the e2e suite.
B_CONVMED="$(val predict predictburst med)"
echo " headroom: burst converged in ${B_CONVMED}ms (round trip $P_RTT ms +"
echo " the burst's own typing span) against the overlay's 1000ms"
echo " expiry bound — the margin a slower path spends first"
# Leg 2, in this harness's substituted form. Comparing the client's
# paint stream to `mux d dump` byte for byte needs a second terminal
# emulator in the harness — the same narrowing recorded for M7 at
# the top of this file — so convergence is asserted through the
# daemon's grid plus attribution: no prediction may outlive the run
# unaccounted for.
if [ "$B_PEND" = "0" ] && [ "$B_CONV" = "1" ]; then
echo " leg 2: every prediction accounted for (pending=0) and the last"
echo " burst is in the daemon's grid -> PASS"
else
echo " leg 2: pending=$B_PEND converged=$B_CONV -> FAIL"
FAILED=1
fi
fi
fi
echo "=================================================================="
# Either gate can fail the run; neither speaks for the other.
[ "${M18_OK:-1}" -eq 1 ] || FAILED=1
exit "$FAILED"