From 089aa8d7c22c46d0168dfcd5b57b83abb745491f Mon Sep 17 00:00:00 2001 From: sylph-decoder Date: Sat, 12 Sep 2026 12:02:53 +0000 Subject: [PATCH] re: F1 dynamic attempt -- harness debugged through four bugs, still no number Tried to close out issue #1 with an actual draw-log measurement this iteration: built f1_hold_capture.py to boot to the settled main menu via the proven glyph-gated route, arm the F10 UI-draw capture, hold a direction, and read cursor position per frame -- the instrument f1-menu-repeat-harness- built-not-answered.md already validated but never got to run against a reachable menu. Four bugs found across four boot attempts: 1. tap() shelled out to pad.py without this script's own env, so the press went to /tmp/xenia_pad.txt while Canary watched OUT/pad.txt -- an unobserved press indistinguishable from a dead pad. Fixed with an in-process tap() using the same pad() the hold uses; confirmed working the next run (title 154.5s, menu 163.0s). 2. ui_draw_capture_frames/max were persisted at 3/20000 from a prior session in xenia-canary.config.toml -- log_ui_draws is now a documented no-op (F10 arms unconditionally) and these two cvars didn't visibly respond to command-line overrides. Bumped to 600/400000 directly in the config. 3. The real blocker: this container has no signed-in profile (no content/ directory at all -- a fresh container after a restart, which every container is right after one). Without a profile the title's sign-in dialog sets IsUIActive() true, which reproduces structures/title-a-press-fault.md's already-diagnosed unbounded- keystroke-queue crash -- verified byte-for-byte against that page's own addresses (PC 0x868 past sub_82457038, 0x828F3xxx registers, identical host/guest address arithmetic), looping continuously from before F10 was ever pressed. Fixed by creating a profile (--create_profile_if_none) and signing in (--logged_profile_slot_0_xuid), matching boot_menu.sh, which already did this and so never hit it. Confirmed: zero crashes with the fix, dozens per run without it. 4. Found but not re-verified: no xsetroot blank before launch, so a stale X-root frame from a killed prior run gave a false "TITLE" read at 2.6s, before any real window existed -- skip_intro.sh already blanks the root for exactly this reason. Fixed in the script. Ran out of budget before a clean end-to-end run landed. Still no number for issue #1 -- the Port keeps -1.0. Flagged prominently (HANDOFF, REFUTED.md) because bug 3 will hit any bare run-canary invocation in any fresh container, not just this script. --- docs/port/HANDOFF.md | 14 ++ docs/re/REFUTED.md | 13 ++ docs/re/f1-hold-capture-harness-debugged.md | 107 +++++++++++ tools/re-capture/f1_hold_capture.py | 192 ++++++++++++++++++++ 4 files changed, 326 insertions(+) create mode 100644 docs/re/f1-hold-capture-harness-debugged.md create mode 100644 tools/re-capture/f1_hold_capture.py diff --git a/docs/port/HANDOFF.md b/docs/port/HANDOFF.md index 04d6b60f..2124136f 100644 --- a/docs/port/HANDOFF.md +++ b/docs/port/HANDOFF.md @@ -6593,3 +6593,17 @@ the coarse screen-diff detector undercounted" reading over the Keystroke/400-100ms one, though neither is confirmed yet and the actual producer still isn't found. Still no number β€” still don't take one from here. + +## πŸ”΄ F1 dynamic attempt this iteration β€” harness debugged through four bugs, still no number + +[`docs/re/f1-hold-capture-harness-debugged.md`](../re/f1-hold-capture-harness-debugged.md). +Tried to actually run the measurement this time. Found and fixed three real +bugs (an env mismatch that silently dropped a scripted press, a stale +persisted capture-window cvar, and β€” the big one β€” a fresh container with no +signed-in profile reproducing the already-documented +`structures/title-a-press-fault.md` crash in a loop) and found-but-didn't- +re-verify a fourth (a stale X-root frame giving a false-positive screen +read). Ran out of iteration budget before a clean end-to-end run. **Still no +number for you** β€” keep `-1.0`. The harness should work next attempt; +flagging for whoever's container hits the same profile-crash first, since +every fresh container starts with none. diff --git a/docs/re/REFUTED.md b/docs/re/REFUTED.md index caa38469..0d61e267 100644 --- a/docs/re/REFUTED.md +++ b/docs/re/REFUTED.md @@ -1094,3 +1094,16 @@ attached to a right direction; only the reason is refuted here. emulator needed β€” or re-run with a repeat-capable file driver and read cursor position off the draw log per frame, not a coarse screen-diff. [`f1-no-repeat-was-the-harness.md`](f1-no-repeat-was-the-harness.md) ⟨harness⟩ +* "F10-arming a UI draw capture is safe on any settled screen" β€” **implicit + in every prior use of it, and false in a fresh container.** A `run-canary` + launch with no signed-in profile (every container right after a restart β€” + no `content/` directory exists yet) reproduces + [`structures/title-a-press-fault.md`](structures/title-a-press-fault.md)'s + already-diagnosed `IsUIActive`/unbounded-keystroke-queue crash in a tight + loop, starting before F10 is ever pressed β€” it is the profile, not the + hotkey. Reproduced byte-for-byte against that page's own addresses (crash + PC `0x868` past `sub_82457038`, registers in the `0x828F3xxx` input-manager + range, `0x1701D0000`β†’`0x701D0000` host/guest arithmetic identical). + `boot_menu.sh` already signs in a profile; a bare `run-canary` call, like + `f1_hold_capture.py`'s first drafts, does not, and hits this every time in + a fresh container. [`f1-hold-capture-harness-debugged.md`](f1-hold-capture-harness-debugged.md) ⟨environment⟩ diff --git a/docs/re/f1-hold-capture-harness-debugged.md b/docs/re/f1-hold-capture-harness-debugged.md new file mode 100644 index 00000000..4087d161 --- /dev/null +++ b/docs/re/f1-hold-capture-harness-debugged.md @@ -0,0 +1,107 @@ +# F1 dynamic attempt β€” harness debugged through four bugs, no measurement yet + +**Status:** ❔ not answered. Built +[`tools/re-capture/f1_hold_capture.py`](../../tools/re-capture/f1_hold_capture.py) +to close out issue #1 with an actual draw-log measurement β€” boot to the +settled main menu (the proven glyph-gated route), arm the F10 UI-draw +capture, hold a direction, read the cursor's position per frame. Never +completed a clean end-to-end run this iteration; four real bugs found along +the way, three fixed and confirmed, one fixed but not re-verified. Same shape +as [`f1-menu-repeat-harness-built-not-answered.md`](f1-menu-repeat-harness-built-not-answered.md) β€” +the harness is closer, the number still isn't here. + +⚠️ **Container reset warning, read this if you are a fresh session:** bug 3 +below will hit *any* scripted `run-canary` invocation in a container that has +never signed in a profile β€” which is every container right after a restart, +per this project's own "your session is new each time" note. `boot_menu.sh` +already handles it; a bare `run-canary` call does not. + +## Bug 1 β€” `tap()` shelled out to `pad.py` with the wrong environment + +First attempt's "tap A" used `subprocess.run([sys.executable, PAD, ...])` +without passing this script's own `env` dict, so the subprocess inherited +`os.environ` instead β€” where `XENIA_PAD_FILE` was never set at the OS level, +only in the local dict. `pad.py` wrote its default `/tmp/xenia_pad.txt`; +Canary was watching `OUT/pad.txt`. The press never arrived: **an +unobserved press that looks identical to a dead pad**, and it cost one full +520 s boot before the mismatch was found (only one `[file-pad]` log line the +whole run β€” the initial clear). + +**Fixed:** an in-process `tap()` using the same `pad()` function the hold +uses, no subprocess. **Confirmed working** the very next run: title reached +at 154.5 s, tap delivered, menu reached at 163.0 s. + +## Bug 2 β€” the persisted `ui_draw_capture_frames` was 3, disc-wide default + +`ui_draw_capture_frames = 3` / `ui_draw_capture_max = 20000` sat in +`~/.local/share/Xenia/xenia-canary.config.toml` from a previous session β€” an +old capture's window, kept because `--log_ui_draws=true` (the flag most +existing scripts pass) is **now a documented no-op** (`command_processor.cc`: +*"OBSOLETE β€” the UI draw-order capture is armed by F10 unconditionally now"*). +Passing `--ui_draw_capture_frames=3000` on the command line did not visibly +change the value logged at startup, and this container's saved config wins +for these two cvars regardless of the flag. + +**Fixed:** edited the toml directly, `600` / `400000` β€” wide enough to cover +a multi-second hold at any plausible present rate. Confirmed applied (log +dump shows the new values) on the next run, though it wasn't the run that +also isolated bug 3, so it hasn't independently produced a capture yet. + +## Bug 3 β€” no signed-in profile, and it reproduces the documented crash + +The real blocker. This container had **no `content/` directory at all** β€” +a fresh container after a restart, exactly as the loop brief warns, and +`f1_hold_capture.py` (unlike `boot_menu.sh`) never checked. Without a +profile, the title shows a sign-in dialog, `IsUIActive()` goes true, and β€” +**this is the exact crash `structures/title-a-press-fault.md` already +diagnosed** β€” `XamInputGetKeystrokeEx` returns success with an empty +keystroke forever, the game's unbounded pump queues every empty result, and +it eventually crashes on a bad allocation. + +Reproduced, not just matched by description: the crash dump's PC +(`0x824578A0`) sits **0x868 past `sub_82457038`** (that doc's "keystroke +pump"), registers hold values in the `0x828F3xxx` range (the input-manager +singleton at `0x828F3888`), and the access violation address relationship β€” +`0x1701D0000` (host) β†’ `0x701D0000` (guest, `r9`) β€” matches that doc's own +worked arithmetic exactly. Without a profile the crash repeated in a tight +loop (one dump roughly every 200 log lines) for the entire run, starting +before F10 was ever pressed β€” this is not an F10 side effect, it is the +title's own boot path with no profile to sign into. + +**Fixed:** `run-canary --create_profile_if_none=F1Probe`, wait ~5 s, kill it +β€” creates `content//`. Script now resolves that XUID and passes +`--logged_profile_slot_0_xuid=`, matching `boot_menu.sh`. **Confirmed**: +zero crash dumps in the run that used it, against dozens per run before. + +## Bug 4 β€” no root-window blank before launch; found, not re-verified + +The run after fixing bug 3 detected "TITLE" at **2.6 s** β€” long before any +real window could exist β€” and never recovered. `skip_intro.sh`'s own header +explains why: *"The X root keeps the DEAD session's last frame, so a fresh +launch would be detected as already at the title."* The previous run's +killed window left stale pixels on the shared `:98` display; my script never +blanked it, unlike every proven boot script. + +**Fixed in the script** (`xsetroot -solid black` before each launch) but +**not re-run this iteration** β€” four bugs and roughly nine minutes of boot +time across four attempts is where this stopped rather than chasing a fifth. + +## What's left + +The harness should now be correct: env-safe input, a wide enough capture +window, a signed-in profile, a blanked root. The next run is the actual +measurement β€” hold a direction on the settled menu, read `read_draws.py`'s +per-frame quad positions, group by `(page, width, height)` shape (the +approach `menu_repeat_probe.sh`'s own notes call "track one quad shape's +position over time," the one that correctly reports no motion when there is +none), and report which shape-group's position changes, at what frame +spacing, at the achieved present rate. + +## Reach + +Everything here is ⟨harness⟩ / ⟨environment⟩ β€” about this container and this +tool, not about the game. Bug 3's crash mechanism is not new (already fully +diagnosed in `structures/title-a-press-fault.md`); what's new is the trigger +(a freshly-reset container with no profile) and that it reproduces +byte-for-byte against that page's own addresses. No claim about F1's actual +repeat rate is made or changed here. diff --git a/tools/re-capture/f1_hold_capture.py b/tools/re-capture/f1_hold_capture.py new file mode 100644 index 00000000..e3dbbd9d --- /dev/null +++ b/tools/re-capture/f1_hold_capture.py @@ -0,0 +1,192 @@ +#!/usr/bin/env python3 +"""F1 -- hold a direction on the SETTLED main menu, and read the cursor's +position PER FRAME off the draw log, not a coarse screen-diff. + +Why this instrument and not another pass of nav_repeat_and_b.py's screen-diff: +that detector grabs frames at ~4-5 fps (`ffmpeg -r 4`), and f1-no-repeat-was- +the-harness.md's 2026-09-12 update found C_PAD_RINGBUF carries analog-axis- +shaped fields, not a keystroke queue -- meaning the file driver's continuous +GetState() was always capable of driving a real repeat, and a coarse detector +could plausibly alias a fast one down to "one spike". The draw log has no such +ceiling: every submitted quad, every frame, at whatever rate the guest +presents. + +Reuses nav_repeat_and_b.py's proven boot-to-menu gate (glyph counting over a +live x11grab pipe) verbatim in spirit -- that gate is the part of this +apparatus already known to work -- and replaces its *measurement* half. + + f1_hold_capture.py OUTDIR [hold_secs] +""" +import os +import subprocess +import sys +import time + +import numpy as np + +OUT = sys.argv[1] +HOLD_S = float(sys.argv[2]) if len(sys.argv) > 2 else 2.5 +os.makedirs(OUT, exist_ok=True) +SD = os.path.dirname(os.path.abspath(__file__)) +PAD = os.path.join(SD, "pad.py") +W, H = 1280, 720 +NEED, CEIL, HOLD_N = 500, 2500, 12 +MENU_LO, MENU_HI, MENU_HOLD = 250, 420, 6 +WAIT_S = 520 + +env = dict(os.environ) +env["HOME"] = "/sylph-home/re" +env["SDL_AUDIODRIVER"] = "dummy" +env["DISPLAY"] = ":98" +env["XENIA_PAD_FILE"] = os.path.join(OUT, "pad.txt") + + +def pad(state): + tmp = env["XENIA_PAD_FILE"] + ".tmp" + with open(tmp, "w") as f: + f.write(state) + os.replace(tmp, env["XENIA_PAD_FILE"]) + + +def tap(button, secs=0.5): + # NOT a subprocess to pad.py: that spawns with os.environ, not this + # script's local `env` dict, so it would write /tmp/xenia_pad.txt while + # Canary watches OUT/pad.txt -- an unobserved press that looks identical + # to a dead pad. Cost one full 520s boot the first time this ran. + pad(f"press={button}") + time.sleep(secs) + pad("") + + +def _open(): + return subprocess.Popen( + ["ffmpeg", "-loglevel", "error", "-f", "x11grab", "-draw_mouse", "0", + "-video_size", f"{W}x{H}", "-i", ":98", "-r", "4", + "-f", "rawvideo", "-pix_fmt", "rgb24", "-"], + stdout=subprocess.PIPE, bufsize=W * H * 3 * 2) + + +def grab(p, n): + buf = p.stdout.read(n) + if len(buf) < n: + return None + return np.frombuffer(buf, np.uint8).reshape(H, W, 3).astype(float) + + +def glyph(a): + r, g, b = a[:, :, 0], a[:, :, 1], a[:, :, 2] + return int(((g > 130) & (g - r > 45) & (g - b > 45)).sum()) + + +def alive(): + out = subprocess.run(["ps", "-o", "pid=,stat=", "-C", "xenia_canary"], + capture_output=True, text=True).stdout + return [ln.split()[0] for ln in out.splitlines() if "Z" not in ln.split()[1]] if out.strip() else [] + + +def xdotool(*args): + return subprocess.run(["xdotool", *args], capture_output=True, text=True) + + +def arm_f10(): + r = xdotool("search", "--name", "Xenia-canary") + wins = [w for w in r.stdout.split() if w] + if not wins: + print("FATAL: no Xenia window to arm F10", flush=True) + return False + win = wins[-1] + xdotool("windowactivate", win) + xdotool("windowfocus", win) + xdotool("key", "--window", win, "F10") + xdotool("key", "F10") + print(f"armed F10 (win={win})", flush=True) + return True + + +def main(): + pad("") + # Not cosmetic: the X root keeps a DEAD session's last frame, so a fresh + # launch's first grabs can read a stale window from the previous run and + # falsely classify it as "title" before the new process has a window at + # all -- skip_intro.sh blanks the root for exactly this reason. Cost one + # full 520s run here (glyph matched at 2.6s, long before any real window + # could exist). + subprocess.run(["xsetroot", "-solid", "black"], env=env, check=False) + canary_log = open(os.path.join(OUT, "canary.stdout"), "w") + xuid = os.environ.get("SYLPH_XUID", "") + if not xuid: + content = "/sylph-home/re/.local/share/Xenia/content" + entries = os.listdir(content) if os.path.isdir(content) else [] + xuid = entries[0] if entries else "" + if not xuid: + print("FATAL: no profile signed in and none found under content/ -- " + "run: run-canary --create_profile_if_none=Tag, wait ~5s, kill it", + flush=True) + return + print(f"signing in profile {xuid}", flush=True) + proc = subprocess.Popen( + ["run-canary", f"--logged_profile_slot_0_xuid={xuid}"], + cwd=OUT, env=env, stdout=canary_log, stderr=subprocess.STDOUT) + print(f"canary pid={proc.pid}, waiting for window", flush=True) + + T0 = time.time() + p, n = _open(), W * H * 3 + seg = time.time() + phase, streak = "wait", 0 + result = {} + while True: + el = time.time() - T0 + if el > WAIT_S: + print(f"TIMEOUT in phase {phase} at {el:.1f}s", flush=True) + break + if time.time() - seg > 30: + p.kill(); p = _open(); seg = time.time() + a = grab(p, n) + if a is None: + p.kill(); p = _open(); seg = time.time() + continue + c = glyph(a) + if phase == "wait": + streak = streak + 1 if NEED <= c <= CEIL else 0 + if streak >= HOLD_N: + print(f"[{el:7.1f}s] TITLE (glyph {c})", flush=True) + tap("A", 0.5) + phase, streak = "tomenu", 0 + elif phase == "tomenu": + streak = streak + 1 if MENU_LO <= c <= MENU_HI else 0 + if streak >= MENU_HOLD: + print(f"[{el:7.1f}s] MENU (glyph {c}) -- settling 2s then arming", flush=True) + time.sleep(2.0) + if not arm_f10(): + result["error"] = "f10 arm failed" + break + pre_hold_ts = time.time() + print(f"[{time.time()-T0:7.1f}s] HOLDING DOWN for {HOLD_S}s", flush=True) + pad("press=DOWN") + time.sleep(HOLD_S) + pad("") + release_ts = time.time() + print(f"[{time.time()-T0:7.1f}s] RELEASED, waiting 2s tail", flush=True) + time.sleep(2.0) + result["hold_started_wall"] = pre_hold_ts + result["hold_released_wall"] = release_ts + phase = "done" + break + p.kill() + print(f"[{time.time()-T0:7.1f}s] killing emulator", flush=True) + proc.terminate() + try: + proc.wait(timeout=10) + except subprocess.TimeoutExpired: + proc.kill() + canary_log.close() + with open(os.path.join(OUT, "result.txt"), "w") as f: + for k, v in result.items(): + f.write(f"{k}\t{v}\n") + f.write(f"phase_at_exit\t{phase}\n") + logs = [f for f in os.listdir(OUT) if f.startswith("xenia_re_ui_draws_")] + print(f"done. phase={phase}, draw logs: {logs}", flush=True) + + +if __name__ == "__main__": + main()