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.
This commit is contained in:
sylph-decoder
2026-09-12 12:02:53 +00:00
parent cefa90855b
commit 6f08999859
4 changed files with 326 additions and 0 deletions

View File

@@ -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.

View File

@@ -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⟩

View File

@@ -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/<XUID>/`. Script now resolves that XUID and passes
`--logged_profile_slot_0_xuid=<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.

View File

@@ -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()