From 9917c5659abebef8de8ddec96d7b49f08820da75 Mon Sep 17 00:00:00 2001 From: "opencode.energia.arti.ee" Date: Sat, 31 Oct 2026 01:08:54 +0000 Subject: [PATCH] fix(stream): delivery metric normalised to the status frame counter --- harness/udpstream/test-stream.sh | 161 ++++++++++++++++++++++--------- 1 file changed, 115 insertions(+), 46 deletions(-) diff --git a/harness/udpstream/test-stream.sh b/harness/udpstream/test-stream.sh index 7117a36..5ac5324 100755 --- a/harness/udpstream/test-stream.sh +++ b/harness/udpstream/test-stream.sh @@ -14,28 +14,42 @@ # [rows] and [stretch] are the strip geometry (default 128 x 8 = the whole # screen, ruling R3); rows*stretch must be 1024 or the encoder refuses. # -# WHAT IT RUNS. harness/udpstream/vidsend.py paced at 30 fps for 300 frames, -# with the terminal's status frames read back on the same interface. vidsend -# prints its own CSV (frame,elapsed_s,fps,bytes) every 30 frames and its status -# reports as prose; both are line-flushed, so this script captures them in one -# stream and merges them in arrival order into: +# THE REPORTING LAG. The terminal emits a status frame every 64 ACCEPTED frames +# (STATUS_EVERY in vidstream.c), and its `frame_no` field is that report's own +# sequence number (0, 1, 2, ...), NOT a frame counter. So a status read at any +# instant describes a terminal that is 0..63 accepted frames behind what the host +# has already sent, and a plain frames_rx/sent ratio is confounded by that: a +# 300-frame run whose last report is the 256th reads ~85 % even when not one frame +# was lost. This script therefore reports three things instead: # -# frame,elapsed_s,fps,bytes,frames_rx,delivery_pct,drops,csr0 +# * the CSV, one row per 30 frames (stdout): the host's `sent` count, the +# status's own `status_no` (its frame_no), its `frames_rx`, the `gap` +# (sent - frames_rx) and `delivery_lo_pct` = 100 * frames_rx / sent. That +# last column is a LOWER BOUND only -- it can never exceed the terminal's +# own progress, and it is as loose as the 63-frame cadence allows; +# * an interval table pairing CONSECUTIVE status frames (stderr): +# delivery = 100 * (frames_rx_k - frames_rx_k-1) / (sent_k - sent_k-1). +# Both terms are deltas between the same two report arrivals, so the +# reporting lag cancels instead of biasing the number: a lost frame shows up +# as the host having sent more than the 64 frames the terminal accepted; +# * a final line (stderr) that compares the end-of-run gap with the lag budget: +# 63 frames of report cadence + 2 frames in flight = 65. +# Within it, no loss is measured; beyond it, at least (gap - 65) frames were +# lost and the script exits 1. # -# frames_rx/drops/csr0 are the LAST status the terminal had sent at that point -# (a status only arrives every 64 accepted frames, so the first two blocks -# repeat the same report). delivery_pct = 100 * frames_rx / frame, i.e. what -# the terminal says it has finished against what the host has sent -- it sits -# just under 100 % while a frame is in flight, and a real loss shows as a step. +# The sender is run with --report-every 1 so a status frame can be paired with +# the host's sent count to within one frame; only every 30th row is printed. # -# Exit status: vidsend.py's (0 only if a status frame arrived and the last one -# reports drops == 0 and crc_err == 0), or 2/3 for a missing prerequisite. +# Exit status: 0 only if a status arrived, at least two reports could be paired, +# the end-of-run gap is inside the lag budget, and vidsend.py itself passed (it +# fails when the last status reports drops or crc_err). 2/3 mean a missing +# prerequisite (arguments, interface, root, sender); 1 means unmeasured or loss. # # WHAT THIS CANNOT SHOW FROM HERE: OS_TOUCH (spec 8.9's VRAM canary, marker bit # 0x01810220) and the terminal's free heap before the run are on the terminal, # not in the status frame. Read them on the terminal with its own debugger # alongside a run and record them with this CSV; an OS repaint during the run -# also shows up here as a fall in delivery_pct. +# also shows up here as a fall in the interval delivery, not as a cadence effect. # # The three unit runs (plan Task 7 step 6): # @@ -87,13 +101,13 @@ esac OUT=${OUT:-/tmp/opencode/test-stream.log} mkdir -p "$(dirname "$OUT")" -echo "test-stream.sh: $IFACE -> $MAC, $ROWS rows x $STRETCH, $FRAMES frames at $FPS fps" -echo "test-stream.sh: capture $OUT" +echo "test-stream.sh: $IFACE -> $MAC, $ROWS rows x $STRETCH, $FRAMES frames at $FPS fps" >&2 +echo "test-stream.sh: capture $OUT" >&2 set +e python3 "$SENDER" --iface "$IFACE" --dst "$MAC" --rows "$ROWS" \ --stretch "$STRETCH" --fps "$FPS" --frames "$FRAMES" \ - --report-every "$REPORT" > "$OUT" 2>&1 + --report-every 1 > "$OUT" 2>&1 STATUS=$? set -e if [ "$STATUS" -ne 0 ] && [ ! -s "$OUT" ]; then @@ -103,55 +117,110 @@ fi # Merge the sender's CSV rows with the terminal's status reports, in the order # they arrived. Both are printed line by line with a flush, so the order in -# this one file IS the chronological order; no timestamps are needed. +# this one file IS the chronological order; no timestamps are needed. vidsend +# runs with --report-every 1, so `sent` is exact to within the one frame that is +# in flight when a status is read. set +e -python3 - "$OUT" <<'PY' +python3 - "$OUT" "$REPORT" <<'PY' import re, sys -path = sys.argv[1] +path, every = sys.argv[1], int(sys.argv[2]) row = re.compile(r"^(\d+),([\d.]+),([\d.]+),(\d+)$") status = re.compile( r"^status (\d+): frame_no=(\d+) frames_rx=(\d+) crc_err=(\d+) " r"drops=(\d+) csr0=0x([0-9A-Fa-f]+) heap_free_kb=(\d+)$") -last = None # the most recent status, as a dict -reports = 0 -print("frame,elapsed_s,fps,bytes,frames_rx,delivery_pct,drops,csr0") -bad = 0 +# The terminal reports every 64 accepted frames, so its last report can be 63 +# frames old; two more cover the frame on the wire and the one on the screen. +LAG = 63 +INFLIGHT = 2 +BUDGET = LAG + INFLIGHT + +sent = 0 +last = None +events = [] +rows = [] with open(path, "r", encoding="utf-8", errors="replace") as f: for line in f: line = line.rstrip("\n") - m = status.match(line) - if m: - reports += 1 - last = dict(frames_rx=int(m.group(3)), crc_err=int(m.group(4)), - drops=int(m.group(5)), csr0=int(m.group(6), 16)) - continue m = row.match(line) + if m: + sent = int(m.group(1)) + if every > 0 and sent % every == 0: + rows.append((sent, m.group(2), m.group(3), m.group(4), last)) + continue + m = status.match(line) if not m: continue - frame = int(m.group(1)) - if last is None: - print("%d,%s,%s,%s,,,," % (frame, m.group(2), m.group(3), - m.group(4))) - continue - pct = 100.0 * last["frames_rx"] / frame if frame else 0.0 - print("%d,%s,%s,%s,%d,%.1f,%d,0x%04X" - % (frame, m.group(2), m.group(3), m.group(4), - last["frames_rx"], pct, last["drops"], last["csr0"])) -if reports == 0: - print("test-stream.sh: no status frame arrived, so delivery and drops are " - "unknown (the terminal said nothing)", file=sys.stderr) - bad = 1 -sys.exit(bad) + last = dict(status_no=int(m.group(2)), frames_rx=int(m.group(3)), + crc_err=int(m.group(4)), drops=int(m.group(5)), + csr0=int(m.group(6), 16), sent=sent) + events.append(last) + +print("frame,elapsed_s,fps,bytes,sent,status_no,frames_rx,gap,delivery_lo_pct") +for sent_n, elapsed, fps, nbytes, ev in rows: + if ev is None: + print("%d,%s,%s,%s,%d,,,,," % (sent_n, elapsed, fps, nbytes, sent_n)) + continue + gap = sent_n - ev["frames_rx"] + lo = 100.0 * ev["frames_rx"] / sent_n if sent_n else 0.0 + print("%d,%s,%s,%s,%d,%d,%d,%d,%.1f" + % (sent_n, elapsed, fps, nbytes, sent_n, ev["status_no"], + ev["frames_rx"], gap, lo)) + +print("", file=sys.stderr) +if len(events) == 0: + print("test-stream: UNMEASURED: no status frame arrived, so delivery and " + "drops are unknown (the terminal said nothing)", file=sys.stderr) + sys.exit(1) +if len(events) < 2: + print("test-stream: UNMEASURED: only one status frame arrived (status_no=" + "%d, frames_rx=%d); delivery is a paired ratio and needs two reports" + % (events[0]["status_no"], events[0]["frames_rx"]), file=sys.stderr) + sys.exit(1) + +print("interval,status_no_from,status_no_to,accepted,sent,delivery_pct", + file=sys.stderr) +i = 0 +for prev, cur in zip(events, events[1:]): + i += 1 + d_acc = cur["frames_rx"] - prev["frames_rx"] + d_sent = cur["sent"] - prev["sent"] + if d_sent <= 0: + # Two reports with no send between them: the sender stalled (or the + # status pair straddles the last frame). No ratio, said so. + print("%d,%d,%d,%d,%d,?" % (i, prev["status_no"], cur["status_no"], + d_acc, d_sent), file=sys.stderr) + continue + pct = 100.0 * d_acc / d_sent + print("%d,%d,%d,%d,%d,%.1f" % (i, prev["status_no"], cur["status_no"], + d_acc, d_sent, pct), file=sys.stderr) + +first, final = events[0], events[-1] +d_acc = final["frames_rx"] - first["frames_rx"] +d_sent = final["sent"] - first["sent"] +paired = ("%.1f%%" % (100.0 * d_acc / d_sent)) if d_sent > 0 else "?" +gap = sent - final["frames_rx"] +if gap <= BUDGET: + verdict = "WITHIN REPORTING LAG (%d allowed): no loss measured" % BUDGET + code = 0 +else: + verdict = ("BEYOND REPORTING LAG: at least %d frame(s) lost" + % (gap - BUDGET)) + code = 1 +print("test-stream: FINAL sent=%d accepted=%d (status_no=%d) gap=%d budget=%d " + "paired_delivery=%s -> %s" + % (sent, final["frames_rx"], final["status_no"], gap, BUDGET, paired, + verdict), file=sys.stderr) +sys.exit(code) PY MERGE=$? set -e -echo "test-stream.sh: vidsend.py status $STATUS, merge status $MERGE" +echo "test-stream.sh: vidsend.py status $STATUS, merge status $MERGE" >&2 echo "test-stream.sh: OS_TOUCH and the terminal's heap are NOT in this table:" \ "read marker bit 0x01810220 and POOL_FREE* on the terminal and record them" \ - "with this CSV." + "with this CSV." >&2 if [ "$STATUS" -ne 0 ] || [ "$MERGE" -ne 0 ]; then exit 1 fi