#!/bin/bash # match-telemetry-reconcile.sh — DETECTOR (S). Built sweep #466. # # ───────────────────────────────────────────────────────────────────────────────────── # WHY THIS EXISTS — it turns the sweep's most-skimmable MANUAL EYEBALL into a control. # # Detector (4b) (kill-telemetry-scan) reads `mod_kill_telemetry` and reports alt-farming. # Its EMPTY is only meaningful if the table's PRODUCER actually ran — and the producer has # now failed in TWO distinct ways, each of which printed a confident, well-formatted clean: # # #457 — THE DEAD PRODUCER. `handleSetRoomProps` gated on a STRING game-state; the Unity # client sends an INT. onGameStateChange() was never called. The table had ZERO # rows, ever. ~450 sweeps recorded a vacuous clean over an entire cheat class. # # #464 — THE PRODUCER THAT ONLY FIRES ON THE HAPPY PATH. Telemetry was written only on # the Battle->Results transition. But a room also ends by simply EMPTYING OUT and # being DISPOSED mid-Battle — and onDispose() wrote nothing. 55% of matches were # orphaned. An alt-farmer's most natural behaviour (farm your alt, quit before the # Results screen) beat the detector without him even trying. # # Both were found by a human squinting at "matches STARTed" vs "rows landed" and noticing a # mismatch. That reconciliation has been a manual step on every wake since — and a human # WILL eventually skim it. This detector performs it, and refuses to call an empty (4b) # clean unless it can prove the producer fired for every match that had kills to report. # # THE LAW IT ENFORCES (#464): # "A DETECTOR IS ONLY AS COMPLETE AS ITS PRODUCER'S RAREST TRIGGER PATH." # Enumerate the exits, not just the entrance. # # ───────────────────────────────────────────────────────────────────────────────────── # THE THREE VERDICTS — note that CLEAN and UNMEASURED are NOT the same thing. # # UNMEASURED — zero matches started in the window. (4b)'s empty means NOTHING; there was # nothing to catch. This is the common case on a quiet 03:00-07:00 wake and # it MUST NOT be laundered into a clean. (Sweep #465 hit exactly this.) # CLEAN — every match that had kills landed telemetry (or provably had no kills to # land). The producer fired on every exit it should have. # REGRESSION — a match with kills tallied did NOT land telemetry. Either it ORPHANED (no # END and no ABANDONED line — the #464 signature) or it terminated but wrote # no row. THE PRODUCER IS DROPPING MATCHES. Do not trust (4b) until fixed. # # ⚠️ A KILL-LESS MATCH THAT LANDS NO ROW IS **CORRECT**, NOT A REGRESSION. # recordKillTelemetry() early-returns on an empty kill matrix, so an ordinary empty-room # teardown posts nothing. Keying the alarm on "started but no row" (instead of on "had # KILLS but no row") would fire on every quiet room and train the next agent to ignore it. # The alarm is keyed on KILLS TALLIED. This is the S2 negative control. # # 🚨 ⚠️ AND THE FALSE-P0 THIS DETECTOR SHIPPED-AND-FIXED IN ITS OWN FIRST RUN (#466). # The first cut graded ANY match with no END/ABANDONED line as an ORPHAN. Its very first # live run flagged `TgMQNgmjG-1` — a match that had started 47 SECONDS EARLIER and was # STILL BEING PLAYED (the player was actively capturing flags as the detector ran). # It had no kills, so it landed on a benign verdict and the bug nearly shipped invisibly. # With kills, it would have cried REGRESSION_ORPHANED_WITH_KILLS **on a perfectly healthy # live match, on every single sweep.** # A MATCH IN PROGRESS HAS NOT "FAILED TO TERMINATE" — IT HAS NOT TERMINATED *YET*. # Hence the GRACE period: an unterminated match younger than GRACE is IN_FLIGHT (it will # be reconciled next sweep), not an orphan. Observed match durations are ~8-12 min, so the # default 20 min is comfortably clear of a legitimately long match. # ⚠️ A GRACE PERIOD IS A **SUPPRESSION**, and a suppression can only ever make a detector # QUIETER (the #452 N1/moon1 law). So it ships with a canary: S3a asserts the real, hours-old # #464 orphan is STILL flagged through the grace rule — the grace must never eat a real # dropped match. Verified both ways by forcing GRACE_MIN=0 (the live in-flight match flips # to ORPHAN) and GRACE_MIN=20 (it is spared) while LD974FX-X-1 stays REGRESSION in both. # # Usage (on the droplet — needs journalctl + mysql): # bash match-telemetry-reconcile.sh [since] # since: journalctl format # Env: GRACE_MIN= in-flight grace before an unterminated match counts as ORPHAN (default 20) # Exit: 0 = CLEAN or UNMEASURED (both are honest, non-alarming states) # 1 = REGRESSION, or a CANARY FAILED (the detector cannot prove it can see the bug) set -uo pipefail DBPW="${1:?usage: match-telemetry-reconcile.sh [since]}" SINCE="${2:-1 hour ago}" GRACE_MIN="${GRACE_MIN:-20}" # ── The canary window. A FIXED historical window containing a KNOWN instance of each case. # If journal retention has aged it out, the canary reports UNAVAILABLE — never PASS. A canary # that cannot run is not a canary that passed (the #456 proof-of-execution lesson). CANARY_SINCE="2026-07-14 00:00:00" CANARY_ORPHAN_WITH_KILLS="LD974FX-X-1" # POSITIVE: real #464 victim. Started 16:19:07 room 4153, # took 2 kills at 16:20, then NEITHER END NOR ABANDONED on # the pre-fix build. Its telemetry was LOST. If (S) cannot # flag THIS, (S) is blind to the exact bug it exists for. CANARY_ABANDONED_NO_KILLS="OoFKdQSpe-1" # NEGATIVE: kill-less abandoned match (19:47:11 -> 19:48:41, # post-fix build). Correctly posts NO row. Must NOT be # graded a regression, or every empty-room teardown is a P0. CANARY_ENDED_WITH_ROWS="SYNTHETIC-MEASURED-1" # POSITIVE synthetic fixture: ended normally, kills tallied, # and its match id is supplied as a landed DB row. This must # reconcile as MEASURED without depending on journal retention. # ───────────────────────────────────────────────────────────────────────────────────── # reconcile -> emits "matchIdroomterminalkillsrowsverdict" # # The join key between a kill and its match is the ROOM, not the matchId: the `xp-tally kill` # line carries room= but no matchId. So we walk the journal chronologically per room, opening a # match on START and closing it on END/ABANDONED, attributing every kill in between. A match # still open at the end of the window is an ORPHAN — the #464 signature. # ───────────────────────────────────────────────────────────────────────────────────── reconcile() { local since="$1" rows_csv="$2" # -o short-unix puts the EPOCH in $1, so the in-flight grace can be computed without date parsing. # JOURNAL_SRC lets a canary feed a SYNTHETIC fixture instead of the live journal. That is what # makes the in-flight grace testable at all: a real in-flight match cannot be used as a fixture # because it TERMINATES while you are testing it (it did, mid-verification, in #466). { if [[ -n "${JOURNAL_SRC:-}" ]]; then cat "$JOURNAL_SRC" else journalctl -u martian-rt --since "$since" --no-pager -o short-unix 2>/dev/null; fi; } \ | awk -v rows_csv="$rows_csv" -v now="${NOW_OVERRIDE:-$(date +%s)}" -v grace_min="$GRACE_MIN" ' BEGIN { n = split(rows_csv, r, ","); for (i = 1; i <= n; i++) if (r[i] != "") has_rows[r[i]] = 1 grace = grace_min * 60 } { ts = $1 + 0 } # room=NNNN appears on every [MartianRoom] line match($0, /room=[0-9]+/) { room = substr($0, RSTART + 5, RLENGTH - 5) } /xp-match START/ { if (match($0, /matchId=[^ ]+/)) { id = substr($0, RSTART + 8, RLENGTH - 8) open_match[room] = id; kills[id] = 0; roomof[id] = room; started[id] = ts order[++seq] = id; terminal[id] = "ORPHAN" # assume orphan until a terminal line proves otherwise } next } /xp-tally kill/ { id = open_match[room] if (id != "") kills[id]++ # a kill outside any open match is not attributable next } # ⚠️ THE `id in roomof` GUARD IS LOAD-BEARING — DO NOT REMOVE IT (#467). # A window BOUNDARY cuts matches in half: a match that STARTed before $since ends INSIDE the # window, so its terminal line arrives with no in-window START. Without this guard the nested # `roomof[id]` subscript on an unseen id makes gawk die outright: # fatal: attempt to use array (null) in a scalar context (exit 2) # NOTE: no apostrophes in these comments — the awk program is single-quoted, so one stray # apostrophe closes it and breaks the script. (That bit while writing this very fix.) # It dies on the FIRST straddling line, emits ZERO rows, and the caller then read that empty # output as "0 matches started" -> UNMEASURED. A 5-match window was laundered into "nothing to # see" by the very detector built to stop exactly that laundering. # A straddler belongs to the PREVIOUS window (its START and its kills are outside ours), so the # correct handling is to IGNORE it — never to crash, and never to reconcile it half-seen. /xp-match END/ { if (match($0, /matchId=[^ ]+/)) { id = substr($0, RSTART + 8, RLENGTH - 8) if (id in roomof) { terminal[id] = "END"; delete open_match[roomof[id]] } } next } /xp-match ABANDONED/ { if (match($0, /matchId=[^ ]+/)) { id = substr($0, RSTART + 8, RLENGTH - 8) if (id in roomof) { terminal[id] = "ABANDONED"; delete open_match[roomof[id]] } } next } END { for (i = 1; i <= seq; i++) { id = order[i]; k = kills[id]; t = terminal[id]; hr = (id in has_rows) ? 1 : 0 # A match still open but YOUNGER than the grace window has not failed to terminate — # it is being PLAYED right now. Reconcile it next sweep, do not alarm on it. if (t == "ORPHAN" && (now - started[id]) < grace) t = "IN_FLIGHT" # THE PREDICATE. Keyed on KILLS TALLIED, never on "started but no row" (see S2 note). if (t == "IN_FLIGHT") v = "PENDING_IN_FLIGHT" # still being played; not yet judgable else if (k == 0 && hr == 0) v = "OK_NO_KILLS_NO_ROW" # correct: empty matrix -> no post else if (k > 0 && hr == 1) v = "OK_MEASURED" # correct: kills -> row landed else if (k > 0 && hr == 0) v = (t == "ORPHAN") \ ? "REGRESSION_ORPHANED_WITH_KILLS" \ : "REGRESSION_TERMINATED_BUT_NO_ROW" else v = "ODD_ROW_WITHOUT_TALLIED_KILLS" # row but no tallied kill: not an # alarm (journal may be truncated), # but say so rather than hide it. printf "%s\t%s\t%s\t%s\t%s\t%s\n", id, roomof[id], t, k, hr, v } }' } # Which match_ids actually landed telemetry? (comma-joined for awk) db_rows() { mysql -uroot -p"$DBPW" martian_games -N -B -e \ "SELECT DISTINCT match_id FROM mod_kill_telemetry;" 2>/dev/null | paste -sd, - } ROWS_CSV="$(db_rows)" if [[ -z "$ROWS_CSV" ]]; then echo " [WARN] mod_kill_telemetry has NO rows at all. That is the #457 dead-producer signature." echo " It is only benign if NO match has had a kill since the table was created." fi echo "==============================================================================" echo " DETECTOR (S) — MATCH-TELEMETRY RECONCILIATION (window: $SINCE)" echo "==============================================================================" # ⚠️ PROOF-OF-EXECUTION (#467). `reconcile` MUST prove it RAN before its silence means anything. # This detector's whole purpose is to refuse to launder a vacuous empty into a clean — and it was # doing precisely that to ITSELF: the awk exit status was DISCARDED, so a crashed parse produced an # empty $LIVE, which fell straight through to "0 matches started -> UNMEASURED -> RC=0 (success)". # A CRASHED DETECTOR IS NOT A QUIET WINDOW. Capture the status; a non-zero is a LOUD ABORT. LIVE="$(reconcile "$SINCE" "$ROWS_CSV")"; RECONCILE_RC=$? printf 'matchId\troom\tterminal\tkills\trow?\tverdict\n' [[ -n "$LIVE" ]] && echo "$LIVE" if [[ "$RECONCILE_RC" -ne 0 ]]; then echo "------------------------------------------------------------------------------" echo "S1_VERDICT: ABORTED — the reconcile pass EXITED $RECONCILE_RC. It did not finish." echo " Its empty/partial output is MEANINGLESS. This is NOT 'UNMEASURED' and it" echo " is emphatically NOT a clean: a detector that could not run is not a" echo " detector that found nothing. (4b)'s verdict is UNVERIFIABLE this window." exit 1 fi STARTS=$(grep -c . <<<"$LIVE" 2>/dev/null || echo 0) [[ -z "$LIVE" ]] && STARTS=0 REGRESSIONS=$(grep -c 'REGRESSION' <<<"$LIVE" 2>/dev/null || true) : "${REGRESSIONS:=0}" PENDING=$(grep -c 'PENDING_IN_FLIGHT' <<<"$LIVE" 2>/dev/null || true) : "${PENDING:=0}" echo "------------------------------------------------------------------------------" if [[ "$STARTS" -eq 0 ]]; then echo "S1_VERDICT: UNMEASURED — 0 matches started in this window." echo " An empty (4b) here means NOTHING. Do NOT record it as a clean;" echo " there was no match for the producer to report on." RC=0 elif [[ "$REGRESSIONS" -gt 0 ]]; then echo "S1_VERDICT: REGRESSION — $REGRESSIONS match(es) tallied KILLS but landed NO telemetry." echo " The producer is DROPPING MATCHES. (4b) is BLIND for those matches;" echo " an alt-farmer in one of them is invisible. Do not trust (4b) until fixed." RC=1 else echo "S1_VERDICT: CLEAN — $STARTS match(es) started; every match with kills landed telemetry." echo " (4b)'s verdict is trustworthy for this window." [[ "$PENDING" -gt 0 ]] && \ echo " ($PENDING still IN FLIGHT — being played now, judged next sweep. Not an orphan.)" RC=0 fi # ───────────────────────────────────────────────────────────────────────────────────── # CANARIES — BOTH DIRECTIONS. A canary that only proves the detector still catches the bad # case, and never proves it still spares the good case, is HALF A CANARY. That half-canary # has now bitten this project SEVEN times (bobbyash -> N3 -> O4 -> P4 -> T4/T5 -> here). # S3a POSITIVE: the real #464 victim (orphaned WITH kills) must be flagged REGRESSION. # S3b NEGATIVE: a kill-less abandoned match must NOT be flagged (else every quiet # room teardown is a false P0 and the alarm gets ignored). # S3c POSITIVE: an ended match whose rows ARE in the DB must reconcile as MEASURED. # ───────────────────────────────────────────────────────────────────────────────────── echo echo "------------------------------------------------------------------------------" CAN="$(reconcile "$CANARY_SINCE" "$ROWS_CSV")" if [[ -z "$CAN" ]] || ! grep -q "$CANARY_ORPHAN_WITH_KILLS" <<<"$CAN"; then echo "S3_CANARY: UNAVAILABLE — the canary window ($CANARY_SINCE) is no longer in journal" echo " retention, so the controls could not be evaluated. This is NOT a pass." echo " Re-anchor the canary on a fresh known-positive match, or (S) is unverifiable." RC=1 else a_line="$(grep -P "^\Q$CANARY_ORPHAN_WITH_KILLS\E\t" <<<"$CAN")" b_line="$(grep -P "^\Q$CANARY_ABANDONED_NO_KILLS\E\t" <<<"$CAN")" a_ok=0; b_ok=0 grep -q 'REGRESSION_ORPHANED_WITH_KILLS' <<<"$a_line" && a_ok=1 grep -q 'OK_NO_KILLS_NO_ROW' <<<"$b_line" && b_ok=1 echo "S3a POSITIVE (orphan WITH kills = the real #464 victim $CANARY_ORPHAN_WITH_KILLS):" echo " $( [[ $a_ok == 1 ]] && echo 'PASS — flagged REGRESSION_ORPHANED_WITH_KILLS' || echo 'FAIL — NOT flagged. (S) is BLIND to the bug it exists for.' )" echo "S3b NEGATIVE (kill-less abandoned $CANARY_ABANDONED_NO_KILLS must NOT be a regression):" echo " $( [[ $b_ok == 1 ]] && echo 'PASS — correctly graded OK_NO_KILLS_NO_ROW' || echo 'FAIL — flagged as a regression. Every quiet teardown would cry P0.' )" if [[ $a_ok == 1 && $b_ok == 1 ]]; then echo "S3ab_CANARY: PASS — (S) still catches a real dropped match and spares a legitimately silent one." else echo "S3ab_CANARY: FAIL — do NOT act on (S)'s verdict above; the historical controls failed." RC=1 fi fi # S3c uses a synthetic landed-row fixture. The former historical match aged partially out of # journald retention between sweeps #617 and #618, turning a healthy detector into a false FAIL. # A structural canary must not depend on a historical log remaining intact forever. echo echo "------------------------------------------------------------------------------" FIX_MEASURED="$(mktemp)" _measured_now=$(date +%s) cat > "$FIX_MEASURED" < PENDING_IN_FLIGHT (spared: it is being played) # old (60 min old) -> REGRESSION_ORPHANED_WITH_KILLS (caught: it really was dropped) # If the second ever fails, the grace is eating real leads and (S) is a blindfold. # ───────────────────────────────────────────────────────────────────────────────────── echo echo "------------------------------------------------------------------------------" _now=$(date +%s) FIX="$(mktemp)" mk_fixture() { # $1 = age in seconds local t=$(( _now - $1 )) cat > "$FIX" < still being played young="$(JOURNAL_SRC="$FIX" NOW_OVERRIDE="$_now" GRACE_MIN="$GRACE_MIN" reconcile "" "$ROWS_CSV")" mk_fixture 3600 # 60 minutes old -> genuinely dropped old="$(JOURNAL_SRC="$FIX" NOW_OVERRIDE="$_now" GRACE_MIN="$GRACE_MIN" reconcile "" "$ROWS_CSV")" rm -f "$FIX" d1=0; d2=0 grep -q 'PENDING_IN_FLIGHT' <<<"$young" && d1=1 grep -q 'REGRESSION_ORPHANED_WITH_KILLS' <<<"$old" && d2=1 echo "S3d NEGATIVE (a match WITH KILLS started 1 min ago is being PLAYED, not dropped):" echo " $( [[ $d1 == 1 ]] && echo 'PASS — spared as PENDING_IN_FLIGHT' || echo 'FAIL — flagged a LIVE match as a dropped one. This is a fabricated P0 every sweep.' )" echo "S3d POSITIVE (the SAME match, 60 min old and still unterminated, really WAS dropped):" echo " $( [[ $d2 == 1 ]] && echo 'PASS — flagged REGRESSION_ORPHANED_WITH_KILLS' || echo 'FAIL — the grace period is SWALLOWING REAL DROPPED MATCHES. (S) is a blindfold.' )" if [[ $d1 == 1 && $d2 == 1 ]]; then echo "S3d_CANARY: PASS — the in-flight grace spares live matches WITHOUT eating real orphans." else echo "S3d_CANARY: FAIL — the grace period is miscalibrated. Do NOT trust (S)." RC=1 fi # ───────────────────────────────────────────────────────────────────────────────────── # S3e — THE WINDOW-STRADDLE CONTROL (added #467, after this exact case took (S) down live). # # EVERY OTHER CANARY HERE FEEDS A FIXTURE THAT BEGINS WITH A `START`. Real journals do not. # A sweep window opens mid-match, so the FIRST xp-match line is routinely a terminal # (END/ABANDONED) for a match that started BEFORE the window. On #467 that made gawk die # (`attempt to use array (null) in a scalar context`, exit 2) on the very first line — (S) # emitted nothing, and reported "UNMEASURED — 0 matches started" over a window with FIVE # real matches. The alarm was disarmed and the run still exited 0. # # The canaries all PASSED through it, because none of them exercised the LIVE-SHAPED input. # >>> A CANARY THAT ONLY EXERCISES A CURATED FIXTURE NEVER PROVES THE PRODUCTION PATH RUNS. <<< # (9th application of the half-a-canary law: bobbyash -> N3 -> O4 -> P4 -> T4/T5 -> S3d -> S3e.) # # Both directions, on one fixture whose first line is a straddling terminal: # POSITIVE — the real match that follows must still be SEEN and reconciled (no lead eaten). # NEGATIVE — the straddler must NOT crash the parse and must NOT be invented as a match. # ───────────────────────────────────────────────────────────────────────────────────── echo echo "------------------------------------------------------------------------------" FIX2="$(mktemp)" _t=$(( _now - 3600 )) cat > "$FIX2" <