From f92d60483a979e9c498323fcc496fcc03dcc5bb1 Mon Sep 17 00:00:00 2001 From: Sylpheed RE agent Date: Mon, 24 Aug 2026 16:13:04 +0000 Subject: [PATCH] =?UTF-8?q?re:=20confirmed=20=E2=80=94=20the=20probe=20was?= =?UTF-8?q?=20causing=20the=20guest=20stalls?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The control needed no new decoding: hunting pilot, keep-out 1400, 300 s, and no memory probe at all, judged only from the pilot's own log. It ran healthy the whole way -- 211, 257, 250, 241 and 200 distinct speed values in successive 60 s windows, with no decline in the last one -- against probed runs that stalled at roughly 27, 83 and 255 s and ended with a single distinct speed across 400 lines. So the instrument was degrading the thing it measured. AGENT.md warned that a full scan competes with the emulator for every core under lavapipe, and the probes grew heavier each iteration until wave6 was reading the entire 32 MB entity heap plus about 300 extra preads every 12 seconds while the game rendered. The control is n=1. The contrast is stark and the mechanism was predicted in advance, so this is recorded as confirmed enough to act on rather than proven; a second clean control would settle it. What it costs is worth stating plainly. Every "no arrival" result so far was collected while the probe was running, under conditions the game was struggling with and in some runs after it had frozen. That does not make them wrong -- the elimination test at t=163 s sits in a window the witness later showed was live -- but none of them is as strong as written, and the arrival question deserves re-running with cheap sampling before silence is read as evidence. wave7_probe.py is the fix: one full enumeration, then polling only the hull word at each known craft base, about 1.2 KB per sample instead of 32 MB, with a full rescan every 90 s to catch anything genuinely new. Three or four heavy scans per run instead of twenty-five. Implemented but not yet run, so the claim that it stops the stalling is untested and the next run must report the witness first. --- docs/re/BACKLOG.md | 14 +++- docs/re/guest-stalls.md | 54 +++++++++++++ tools/re-capture/control_session.sh | 18 +++++ tools/re-capture/wave7_probe.py | 115 ++++++++++++++++++++++++++++ tools/re-capture/wave7_session.sh | 16 ++++ 5 files changed, 214 insertions(+), 3 deletions(-) create mode 100755 tools/re-capture/control_session.sh create mode 100755 tools/re-capture/wave7_probe.py create mode 100755 tools/re-capture/wave7_session.sh diff --git a/docs/re/BACKLOG.md b/docs/re/BACKLOG.md index c8ed10e..c5e35ba 100644 --- a/docs/re/BACKLOG.md +++ b/docs/re/BACKLOG.md @@ -402,9 +402,17 @@ search cannot find a *schedule*. long runs stalled at ~255 s, 83 s and **~27 s**. 🟡 **Leading suspect: the probe itself** — it reads the whole 32 MB heap plus ~300 `pread`s every 12 s while lavapipe renders, and AGENT.md warns a full scan competes for every core. - **Next: run the pilot 300 s with NO probe**, judge from its log alone; if it - does not stall, the instrument is degrading what it measures and sampling must - get much cheaper. ❔ Multi-squadron threshold test did not run (zero losses). + ✅ **CONFIRMED (2026-08-24): the probe was causing the stalls.** The no-probe + control ran **300 s clean** — 211/257/250/241/200 distinct speeds per 60 s + window, no decline — against probed runs stalling at 27/83/255 s and ending on + **1** distinct speed. The instrument was degrading what it measured, exactly as + AGENT.md warned. Control is **n=1**: acted on, not proven. + ⚠️ **Consequence: every "no arrival" result was collected under a struggling or + frozen guest** — none is as strong as written, and the arrival question needs + re-running with cheap sampling before silence means anything. + ✅ Fix written: `wave7_probe.py` enumerates once then polls only the hull word + per known craft (~1.2 KB/sample vs 32 MB), full rescan every 90 s — **not yet + run**. ❔ Multi-squadron threshold test still not run (zero losses that run). ⚠️ The ~210 s title movie at boot is the binding constraint on observable game time per turn. Earlier framing: diff --git a/docs/re/guest-stalls.md b/docs/re/guest-stalls.md index ccbb6be..d08b071 100644 --- a/docs/re/guest-stalls.md +++ b/docs/re/guest-stalls.md @@ -71,3 +71,57 @@ only the craft bases already located rather than rescanning). The multi-squadron kill-threshold test did not run: the guest froze before the pilot destroyed anything, so there were zero losses and nothing to threshold. + +--- + +# ✅ Confirmed: the probe was causing the stalls (2026-08-24) + +The control needed no new decoding — hunting pilot, `SYLPH_KEEPOUT=1400`, 300 s, +and **no memory probe at all**, judged only from the pilot's own log. + +``` +last pilot timestamp: 299.4s + t= 0- 60s distinct speeds: 211 + t= 60-120s distinct speeds: 257 + t=120-180s distinct speeds: 250 + t=180-240s distinct speeds: 241 + t=240-300s distinct speeds: 200 +``` + +Healthy through the entire run, with no decline in the final window. Against the +probed runs, which stalled at ~255 s, ~83 s and ~27 s and ended with **1** distinct +speed value across 400 log lines. + +**The instrument was degrading the thing it measured.** `AGENT.md` warned about +exactly this — "the full scan competes with the emulator for every core under +lavapipe" — and the probes grew heavier each iteration until `wave6_probe` was +reading the entire 32 MB entity heap plus ~300 extra `pread`s every 12 seconds +while the game rendered. + +**Strength of the claim:** the contrast is stark and the mechanism was predicted +in advance, but the control is **n = 1**. It is recorded as confirmed-enough to +act on, not as proven; a second clean control would settle it. + +## What this costs + +Every "no arrival" result in +[mission-arrival-watch.md](mission-arrival-watch.md) was collected while the +probe was running, i.e. under conditions the game was struggling with, and in +some runs after it had frozen outright. That does not make them wrong — the +elimination test at t = 163 s happened in a window the witness later showed was +live — but it does mean **none of them is as strong as written**, and the whole +arrival question deserves re-running with cheap sampling before any conclusion +is drawn from silence. + +## The fix: sample ~4 orders of magnitude less + +The full rescan is nearly all waste. After the first scan the craft bases and +their roster links are already known, so a sample only needs the **hull word at +each known base** — 300 × 4 bytes ≈ 1.2 KB, against 32 MB. + +`wave7_probe.py` does that: one full enumeration at the start, then cheap hull +polling, with a full rescan only every ~90 s to catch anything genuinely new. +That is 3–4 heavy scans per run instead of 25. + +Implemented, **not yet run** — so the claim that it stops the stalling is +untested, and the next run must report the witness before anything else. diff --git a/tools/re-capture/control_session.sh b/tools/re-capture/control_session.sh new file mode 100755 index 0000000..cda9f6e --- /dev/null +++ b/tools/re-capture/control_session.sh @@ -0,0 +1,18 @@ +#!/usr/bin/env bash +# CONTROL: hunting pilot, NO memory probe at all. The only question is whether +# the guest still stalls when nothing is scanning /dev/shm alongside it. +set -u +export HOME=/sylph-home/re SDL_AUDIODRIVER=dummy DISPLAY=:98 +export PYTHONPATH=/sylph-home/.local/lib/python3.12/site-packages +SD="$(cd "$(dirname "$0")" && pwd)" +SECS="${1:-300}" +CFG=/tmp/nav-ctl.json +"$SD/launch_mission.sh" fly || { echo "BOOT FAILED"; exit 1; } +if python3 "$SD/entities2.py" self 0x130 "$CFG" >/dev/null 2>&1; then + SYLPH_HUNT=1 SYLPH_KILL_TURRETS=1 SYLPH_KEEPOUT=1400 \ + nohup python3 "$SD/pilot.py" "$CFG" "$SECS" /tmp/ctl-pilot.log 2>&1 & + PILOT=$!; echo "--- pilot only, no probe" +else echo "BIND FAILED"; exit 1; fi +python3 -c "import time,sys; time.sleep(int(sys.argv[1]))" "$SECS" +kill "$PILOT" 2>/dev/null +echo "CONTROL DONE" diff --git a/tools/re-capture/wave7_probe.py b/tools/re-capture/wave7_probe.py new file mode 100755 index 0000000..621237e --- /dev/null +++ b/tools/re-capture/wave7_probe.py @@ -0,0 +1,115 @@ +#!/usr/bin/env python3 +"""Cheap per-record watch: the heavy rescan was stalling the guest. + +A no-probe control ran 300 s clean while probed runs stalled at 27-255 s +(guest-stalls.md), so the 32 MB rescan every 12 s has to go. After one full +enumeration the craft bases and their roster links are known, and a sample only +needs the hull word at each base -- about 1.2 KB instead of 32 MB. A full rescan +runs only every RESCAN seconds to catch anything genuinely new. +""" +import os, sys, time, struct, collections, importlib.util +SD = __file__.rsplit('/', 1)[0] +sys.path.insert(0, SD) +import gmem, gworld, entities2 +_w3 = importlib.util.spec_from_file_location('w3', SD + '/wave3_probe.py') +wave3 = importlib.util.module_from_spec(_w3); _w3.loader.exec_module(wave3) + +ROSTER_VT = struct.pack('>I', 0x820AF030) +DELTA, WIN, LINK, HULL = 0x130, 0x400, 0x08, 0x154 +BASELINE, RESCAN = 116, 90 + +def scan_vt(fd, size, vt): + out = [] + for a, b in gmem.extents(fd, size): + pos = a + while pos < b: + m = min(1 << 24, b - pos) + blob = os.pread(fd, m, pos) + i = blob.find(vt) + while i != -1: + if (pos + i) % 4 == 0: out.append(pos + i) + i = blob.find(vt, i + 1) + pos += m + return sorted(out) + +def enumerate_craft(fd, defs, want): + """Heavy: full heap scan. Returns [(base, unit, roster_off)].""" + lo, hi = gmem.va_to_off(entities2.ENT_VA_LO), gmem.va_to_off(entities2.ENT_VA_HI) + out, pos = [], lo + while pos < hi: + m = min(1 << 24, hi - pos) + blob = os.pread(fd, m, pos) + for k in range(0, len(blob) - 3, 4): + nm = defs.get(blob[k:k+4]) + if not nm: continue + base = pos + k - DELTA + head = os.pread(fd, WIN, base) + own = None + for j in range(0, len(head) - 3, 4): + (p,) = struct.unpack_from('>I', head, j) + if p in want: own = want[p]; break + out.append((base, nm, own)) + pos += m + return out + +def alive(fd, base): + try: return struct.unpack('>f', os.pread(fd, 4, base + HULL))[0] > 0 + except Exception: return False + +def main(): + secs = int(sys.argv[1]) if len(sys.argv) > 1 else 300 + every = int(sys.argv[2]) if len(sys.argv) > 2 else 15 + w = gworld.World(); fd = w.fd + defs = entities2.definitions(w) + if not defs: print('NOT IN A MISSION'); return 2 + roster = scan_vt(fd, w.size, ROSTER_VT) + print('roster records: %d (baseline %d)' % (len(roster), BASELINE)) + if len(roster) != BASELINE: + print('DISCARD: not the reproduced baseline'); return 3 + f = os.fdopen(os.dup(fd), 'rb') + label, want = {}, {} + for o in roster: + va = gmem.primary_va(o) + if va is None: continue + label[o] = wave3.resolve_id(f, w.size, o)[0] or '?' + want[va + LINK] = o + + tick = None + lo = gmem.va_to_off(0xBC000000) + a = os.pread(fd, 1 << 20, lo); time.sleep(2.0); b = os.pread(fd, 1 << 20, lo) + for k in range(0, len(a) - 3, 4): + va, vb = struct.unpack_from('>I', a, k)[0], struct.unpack_from('>I', b, k)[0] + if va < vb and 5 < (vb - va) / 2.0 < 1 << 18: tick = lo + k; break + print('tick witness: %s' % (('%#x' % tick) if tick else 'NONE')) + last_tick = struct.unpack('>I', os.pread(fd, 4, tick))[0] if tick else 0 + + craft = enumerate_craft(fd, defs, want) + print('craft %d, linked %d' % (len(craft), sum(1 for c in craft if c[2]))) + prev = collections.Counter(c[2] for c in craft if c[2] and alive(fd, c[0])) + print('t= 0s deployed=%d strengths %s' + % (len(prev), sorted(collections.Counter(prev.values()).items())), flush=True) + t0 = time.time(); last_rescan = t0; arr = los = 0; stalls = 0 + while time.time() - t0 < secs: + time.sleep(every) + el = round(time.time() - t0) + if time.time() - last_rescan > RESCAN: + craft = enumerate_craft(fd, defs, want); last_rescan = time.time() + cur = collections.Counter(c[2] for c in craft if c[2] and alive(fd, c[0])) + st = '' + if tick: + now = struct.unpack('>I', os.pread(fd, 4, tick))[0] + if now <= last_tick: st = ' *** GUEST STALLED ***'; stalls += 1 + last_tick = now + a_ = [(o, cur[o]) for o in cur if prev.get(o, 0) == 0 < cur[o]] + l_ = [(o, prev[o], cur.get(o, 0)) for o in prev if cur.get(o, 0) < prev[o]] + arr += len(a_); los += len(l_) + print('t=%4ds deployed=%d ARRIVALS=%d losses=%d (cum %d/%d)%s' + % (el, len(cur), len(a_), len(l_), arr, los, st), flush=True) + for o, c in a_: print(' ARRIVAL %-30s 0 -> %d' % (label.get(o, '?'), c), flush=True) + for o, x, y in l_: print(' loss %-30s %d -> %d' % (label.get(o, '?'), x, y), flush=True) + prev = cur + print('\nTOTAL arrivals=%d losses=%d stalled samples=%d' % (arr, los, stalls)) + return 0 + +if __name__ == '__main__': + sys.exit(main()) diff --git a/tools/re-capture/wave7_session.sh b/tools/re-capture/wave7_session.sh new file mode 100755 index 0000000..579f3e2 --- /dev/null +++ b/tools/re-capture/wave7_session.sh @@ -0,0 +1,16 @@ +#!/usr/bin/env bash +set -u +export HOME=/sylph-home/re SDL_AUDIODRIVER=dummy DISPLAY=:98 +export PYTHONPATH=/sylph-home/.local/lib/python3.12/site-packages +SD="$(cd "$(dirname "$0")" && pwd)" +SECS="${1:-180}"; EVERY="${2:-10}"; HUNT="${3:-1}" +CFG=/tmp/nav-live.json +"$SD/launch_mission.sh" fly || { echo "BOOT FAILED"; exit 1; } +if python3 "$SD/entities2.py" self 0x130 "$CFG" >/dev/null 2>&1; then + SYLPH_HUNT="$HUNT" SYLPH_KILL_TURRETS=1 SYLPH_KEEPOUT="${SYLPH_KEEPOUT:-1400}" nohup python3 "$SD/pilot.py" "$CFG" "$SECS" \ + /tmp/live-pilot.log 2>&1 & + PILOT=$!; echo "--- pilot (SYLPH_HUNT=$HUNT)" +else PILOT=""; echo "--- BIND FAILED, no pilot"; fi +python3 "$SD/wave7_probe.py" "$SECS" "$EVERY"; rc=$? +[ -n "$PILOT" ] && kill "$PILOT" 2>/dev/null +echo "LIVENESS DONE rc=$rc"