funman300
bfb7876ed4
Three fixes, all found while closing out gate 7.
1. Frame count was wrong. It counted lines matching '^conn-', which also
matches the OPEN/CLOSE lifecycle markers, inflating the figure by one or
two. Compared against the capture's record count that looked like a
capture/trace divergence (89 vs 88) when there was none: read at the same
instant, both report 99. Evidence tooling that miscounts is exactly what
this project cannot afford.
2. The raw capture is now copied into the evidence bundle (0600), so a gate's
forensic bytes travel with its report.
3. FUT actions are now observed on the UTAS side. 'Known FUT action succeeded'
is a client-side fact, but FUT actions go over UTAS -- which is never
switched -- so the UTAS log confirms them independently of anyone's
recollection. Gate 7's pack open shows up as:
STORE: opened pack Special Players Pack -> 11 items
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
186 lines
7.9 KiB
Bash
Executable File
186 lines
7.9 KiB
Bash
Executable File
#!/usr/bin/env bash
|
|
# Capture evidence for one live-FIFA gate.
|
|
#
|
|
# gate-evidence.sh <gate-label> [outdir]
|
|
#
|
|
# Records what the system was configured to do AND what it observably did, and
|
|
# reports them separately.
|
|
#
|
|
# WHY BOTH
|
|
#
|
|
# `blaze-switch.sh status = ON` is an assertion produced by the same tooling
|
|
# that performs the switch. If that tooling is wrong — and it has been once
|
|
# already, reporting a rollback that had not happened — the assertion is
|
|
# worthless. The observed half comes from a different source entirely: the
|
|
# sidecar's own record of which peers connected to it. A remote peer appearing
|
|
# in the sidecar log is proof the client reached Rust that does not depend on
|
|
# reading an iptables rule correctly.
|
|
#
|
|
# Run it after each gate. It never modifies anything.
|
|
set -uo pipefail
|
|
|
|
HERE="$(cd "$(dirname "$(readlink -f "$0")")" && pwd)"
|
|
ROOT="$(cd "$HERE/.." && pwd)"
|
|
RUNDIR="${OPENFUT_SIDECAR_RUNDIR:-${TMPDIR:-/tmp}/openfut-sidecar}"
|
|
LOGFILE="${OPENFUT_SIDECAR_LOG:-$RUNDIR/sidecar.log}"
|
|
TRACE="${OPENFUT_BLAZE_TRACE:-}"
|
|
|
|
LABEL="${1:-}"
|
|
OUT="${2:-$ROOT/gate-evidence}"
|
|
[[ -n "$LABEL" ]] || { echo "usage: gate-evidence.sh <gate-label> [outdir]" >&2; exit 2; }
|
|
|
|
STAMP="$(date -u +%Y%m%dT%H%M%SZ)"
|
|
DEST="$OUT/${STAMP}-${LABEL}"
|
|
mkdir -p "$DEST"
|
|
|
|
say() { echo "$@"; }
|
|
both() { echo "$@" | tee -a "$DEST/summary.txt" >/dev/null; echo "$@"; }
|
|
|
|
both "=== gate evidence: $LABEL ($STAMP) ==="
|
|
both ""
|
|
|
|
# ---------------------------------------------------- configured (asserted)
|
|
both "--- CONFIGURED (asserted by tooling) ---"
|
|
{
|
|
"$HERE/blaze-switch.sh" status 2>&1
|
|
echo
|
|
"$HERE/sidecar.sh" status 2>&1
|
|
} > "$DEST/configured.txt"
|
|
sed 's/^/ /' "$DEST/configured.txt" | tee -a "$DEST/summary.txt"
|
|
|
|
# Raw rules, straight from the kernel, not via our parser.
|
|
{ sudo iptables -t nat -S 2>/dev/null || true; } > "$DEST/iptables-nat.txt"
|
|
both ""
|
|
|
|
# ------------------------------------------------------ observed (measured)
|
|
both "--- OBSERVED (measured from the sidecar's own record) ---"
|
|
|
|
if [[ ! -f "$LOGFILE" ]]; then
|
|
both " no sidecar log at $LOGFILE — nothing observed"
|
|
else
|
|
cp "$LOGFILE" "$DEST/sidecar.log" 2>/dev/null
|
|
|
|
banner="$(grep -m1 'openfut-blaze-host v' "$LOGFILE" 2>/dev/null || true)"
|
|
both " build: ${banner:-<none>}"
|
|
if grep -q 'tree=DIRTY' <<<"$banner"; then
|
|
both " !! DIRTY BUILD — this run is NOT parity evidence"
|
|
fi
|
|
|
|
conns="$(grep -c 'CONNECT from' "$LOGFILE" 2>/dev/null || echo 0)"
|
|
both " connections accepted: $conns"
|
|
|
|
# THE INDEPENDENT ASSERTION: which peers actually reached this process.
|
|
peers="$(grep -o 'CONNECT from [0-9.]*' "$LOGFILE" 2>/dev/null | awk '{print $3}' | sort -u || true)"
|
|
remote="$(grep -v '^127\.' <<<"$peers" | grep -v '^$' || true)"
|
|
both " peers: $(tr '\n' ' ' <<<"$peers")"
|
|
if [[ -n "$remote" ]]; then
|
|
both " REMOTE peer(s) reached the Rust sidecar: $(tr '\n' ' ' <<<"$remote")"
|
|
both " => the client's Blaze traffic observably landed on Rust"
|
|
else
|
|
both " no remote peer connected — only loopback (or nothing) reached Rust"
|
|
both " => a FIFA session did NOT land here"
|
|
fi
|
|
|
|
# Session shape, straight from the log.
|
|
logins="$(grep -c 'Authentication::login .*REPLY' "$LOGFILE" 2>/dev/null || echo 0)"
|
|
notifs="$(grep -c 'UserSessions::<' "$LOGFILE" 2>/dev/null || echo 0)"
|
|
both " login replies: $logins UserSessions notifications: $notifs"
|
|
both " close reasons:"
|
|
grep -o 'CLOSE after [0-9]* frame(s): .*' "$LOGFILE" 2>/dev/null \
|
|
| sort | uniq -c | sed 's/^/ /' | tee -a "$DEST/summary.txt" || true
|
|
|
|
# Anything that looks wrong.
|
|
probs="$(grep -E 'DECODE FAILED|REJECT|FAILED|absurd' "$LOGFILE" 2>/dev/null | head -20 || true)"
|
|
if [[ -n "$probs" ]]; then
|
|
both " ANOMALIES:"
|
|
sed 's/^/ /' <<<"$probs" | tee -a "$DEST/summary.txt"
|
|
else
|
|
both " no anomalies in the log"
|
|
fi
|
|
fi
|
|
|
|
# ------------------------------------------------------------------ trace
|
|
both ""
|
|
both "--- TRACE ---"
|
|
if [[ -n "$TRACE" && -f "$TRACE" ]]; then
|
|
cp "$TRACE" "$DEST/rust-blaze.trace"
|
|
# Count FRAME lines only. `^conn-` also matches the OPEN/CLOSE markers, and
|
|
# counting those inflated the figure by one or two — which then looked like a
|
|
# capture/trace divergence when compared against the capture's record count.
|
|
frames="$(grep -cE '^conn-[0-9]+ (RX|TX) ' "$TRACE" 2>/dev/null || echo 0)"
|
|
markers="$(grep -cE '^conn-[0-9]+ (OPEN|CLOSE)' "$TRACE" 2>/dev/null || echo 0)"
|
|
both " $TRACE -> $DEST/rust-blaze.trace ($frames traced frames, $markers lifecycle markers)"
|
|
# Capture and trace are written continuously; on a LIVE session they are only
|
|
# comparable if read at the same instant.
|
|
if [[ -n "${OPENFUT_BLAZE_CAPTURE:-}" && -f "${OPENFUT_BLAZE_CAPTURE}" ]]; then
|
|
cp "$OPENFUT_BLAZE_CAPTURE" "$DEST/raw.ofcap" 2>/dev/null && chmod 600 "$DEST/raw.ofcap"
|
|
both " raw capture -> $DEST/raw.ofcap (0600, NEVER commit)"
|
|
fi
|
|
both " routes seen:"
|
|
grep -o '^conn-[0-9]* \(RX\|TX\) [^ ]* [A-Za-z]*::[^ ]*' "$TRACE" 2>/dev/null \
|
|
| awk '{print $2, $4}' | sort | uniq -c | sort -rn | head -20 \
|
|
| sed 's/^/ /' | tee -a "$DEST/summary.txt" || true
|
|
else
|
|
both " no trace configured (set OPENFUT_BLAZE_TRACE before starting the sidecar)"
|
|
fi
|
|
|
|
# --------------------------------------------- python side (the other half)
|
|
#
|
|
# "Rust did not receive it" is weaker than "Python did". The redirector always
|
|
# runs on Python and is never switched, so it advertises the Blaze endpoint on
|
|
# every run; whether Python then receives the Blaze CONNECT it just advertised
|
|
# is the positive observation that says where the hop actually went.
|
|
both ""
|
|
both "--- PYTHON SIDE (positive/negative observation) ---"
|
|
PYLOG=/tmp/blaze_responder.log
|
|
if docker exec openfut-fut-backend test -f "$PYLOG" 2>/dev/null; then
|
|
docker exec openfut-fut-backend sh -c "grep -E 'REDIR SENT|BLAZE CONNECT from|closed' $PYLOG" \
|
|
> "$DEST/python-blaze.log" 2>/dev/null || true
|
|
CLIENT="${OPENFUT_CLIENT_IP:-10.10.0.105}"
|
|
redirs="$(grep -c "REDIR SENT ('$CLIENT'" "$DEST/python-blaze.log" 2>/dev/null || echo 0)"
|
|
blazes="$(grep -c "BLAZE CONNECT from ('$CLIENT'" "$DEST/python-blaze.log" 2>/dev/null || echo 0)"
|
|
both " client $CLIENT — redirector hops served by Python: $redirs"
|
|
both " client $CLIENT — Blaze connections received by Python: $blazes"
|
|
both " most recent:"
|
|
grep -E "\('$CLIENT'" "$DEST/python-blaze.log" 2>/dev/null | tail -4 | sed 's/^/ /' \
|
|
| tee -a "$DEST/summary.txt" || true
|
|
both ""
|
|
both " interpretation: a redirector hop with NO following Python Blaze CONNECT"
|
|
both " means the Blaze hop went elsewhere (the Rust sidecar). A Python Blaze"
|
|
both " CONNECT means it went to Python."
|
|
else
|
|
both " python blaze log not readable (container not running?)"
|
|
fi
|
|
|
|
# ------------------------------------------------- FUT actions (UTAS side)
|
|
#
|
|
# "Known FUT action succeeded" is a client-side fact, but it leaves an
|
|
# independent trace: FUT actions go over UTAS (Python, never switched), so the
|
|
# UTAS log confirms them without relying on anyone's recollection of what they
|
|
# clicked.
|
|
both ""
|
|
both "--- FUT ACTIONS (observed on UTAS, which is always Python) ---"
|
|
UTASLOG=/tmp/utas_server.log
|
|
if docker exec openfut-fut-backend test -f "$UTASLOG" 2>/dev/null; then
|
|
docker exec openfut-fut-backend sh -c "grep -E 'STORE:|SQUAD:|SBC:|TRADE:' $UTASLOG" \
|
|
> "$DEST/utas-actions.log" 2>/dev/null || true
|
|
packs="$(grep -c 'opened pack' "$DEST/utas-actions.log" 2>/dev/null || echo 0)"
|
|
both " pack opens recorded: $packs"
|
|
both " most recent actions:"
|
|
tail -5 "$DEST/utas-actions.log" 2>/dev/null | sed 's/^/ /' | tee -a "$DEST/summary.txt" || true
|
|
else
|
|
both " utas log not readable"
|
|
fi
|
|
|
|
# ----------------------------------------------------------- python health
|
|
both ""
|
|
both "--- PYTHON BACKEND (must stay healthy throughout) ---"
|
|
if contract="$(cd "$ROOT/fifa17-recon" && timeout 120 python3 tools/test_fut_contract.py 2>&1 | tail -1)"; then
|
|
both " contract suite: $contract"
|
|
else
|
|
both " contract suite: FAILED TO RUN"
|
|
fi
|
|
|
|
both ""
|
|
both "evidence bundle: $DEST"
|