Two findings, the second only visible because of the first.
1. The harness has always had kernel logging switched off. log_mask DISABLES
categories (Kernel=1, Apu=2, Cpu=4, Gpu=8), so the long-standing --log_mask=13
meant Kernel+Cpu+Gpu off; kernel calls also log at Debug while log_level
defaults to Info. Seeing one needs BOTH LOG_MASK=12 and LOG_LEVEL=3, and no
boot log this project has taken ever contained a kernel call. boot_menu.sh now
takes LOG_MASK / LOG_LEVEL / EXTRA_FLAGS. A whole boot at Debug with Kernel on
is 23 MB, so the default was costing far more than it saved.
2. With that on, a captured failure shows the (A) handler doing everything right:
XamUserGetXUID(0, 7, ...)
NtCreateEvent(...)
ExCreateThread(..., entry=821748F0, ..., 00000001)
ExCreateThread Active: Thread Initially Suspended,
XThreadF80000CC (1F) Stack: 70880000-70900000
NtResumeThread(F80000CC, ...)
and the thread then never executing. Measured two independent ways: it makes
ZERO kernel calls - it appears 13 times in the log and every one is as an
ARGUMENT, never as the calling thread, while five other threads make 31905
calls after the resume - and its host thread has 00:00:00 CPU time while the
process sits at 546% and has burned 37 minutes of CPU in 6:46 wall.
A spinning thread burns CPU. This one has not run at all.
So the chain is: press delivered -> handler runs -> thread created suspended ->
resumed -> never scheduled. Input, the cache-flush crash and the game's own logic
are all excluded. A lost resume is a race, which is the first explanation that
fits the ~1-in-3 success rate.
Not settled: where the resume is lost, and no successful boot has been captured
with kernel logging to compare against.
Chasing why (A) does not advance the title turned up four harness bugs, one real
root cause, and a refutation of that root cause as the explanation.
FIXED, each verified:
* boot_menu.sh sent the emulator stdout to /dev/null, which is why none of the
rest was visible. It now keeps a log and prints its path.
* skip_intro.sh probed pixel (625,618) for the green (A) glyph - a 1280x720
coordinate. screenshot returns the 1279x675 game surface, where that point
is on the copyright line and reads (8,17,31). Symptom: a 600s TIMEOUT with
the title on screen. Now classified with screen_id.py; next boot printed
"TITLE at 239s -> A".
* skip_intro.sh no longer taps through the movies. Making that press real (the
vgamepad fix) was a REGRESSION: the boot then reached the title in 90s and
that title accepted nothing. menu_draw_capture.sh records the same finding
independently.
* boot_menu.sh signs in whichever profile exists instead of a hard-coded XUID.
ROOT CAUSE FOUND: naming a XUID with no profile behind it opens a sign-in
dialog, xam_dialogs_shown_ goes to 1, and IsUIActive() then discards every
XamInputGetKeystrokeEx. Measured 8,388,601 swallowed calls in one boot with the
pad log showing presses arriving normally throughout. Only B13EBABEBABEBABE
exists on disc; the script asked for E0300000EFBEA3D4. Signing in the real
profile takes the swallow count 8,388,601 -> 0.
AND REFUTED: that is not why the title is stuck. With a valid profile and zero
swallowed keystrokes, a single (A) on the title that ends the boot still does
nothing. The dialog bug was real and worth fixing; it is not the explanation.
Next probe is specific: --log_mask=13 records no kernel calls, so it is not even
known whether the game polls at the title. A log on the SUCCESSFUL
XamInputGetKeystrokeEx return, mirroring the one already on the swallow path,
answers it in one boot.
Trying to read a third paint order off the running game turned up two bugs in
the capture harness, both of which fail in ways that look like the game
misbehaving rather than the script being wrong.
1. `--audio` is not a cvar in this tree, and eight boot scripts passed it.
Xenia calls ShowSimpleMessageBox from ParseLaunchArguments, BEFORE logging is
initialised, so the symptom is a 10x10 window, no log, no guest memory and a
dialog that blocks on XIfEvent forever - i.e. a hang deep in the emulator.
run-canary`s own header documents this exact trap; the scripts predate it.
Removed from all eight.
2. `vgamepad` no longer exists - the uinput pad was replaced by the --hid=file
driver and pad.py - but skip_intro.sh still called it. The script runs
without `set -e`, so the call failed silently and the title branch pressed
nothing while still exiting 0. A caller was told "TITLE -> A" with the game
sitting on the title screen. It now presses through pad.py and exits 6 if
that fails.
The first bug is fixed and verified: the boot now reaches the title screen with
PRESS (A) BUTTON. The second is fixed but does NOT unblock the title - see the
next commit.
Those three fields all hold 2, and "difficulty or stage, undecidable from one
save" has been the reading since the format was parsed. Writing saves makes it
decidable and the answer is neither.
boot_menu.sh boots to the title menu WITHOUT loading anything, and LOAD GAME's
slot list renders each slot's Details panel from that slot's payload. Extra
slots can be fabricated (copy the directory plus a gameNN.header with its
UTF-16BE display string and ASCII name patched), so four probes fit in one boot,
read-only.
Probed: +36 at 1/3/9, +52 and +56 at 1/9, and +0, +16, +32, +48, +28,
SHAB[0].a. Every one left the panel at STAGE 02 / EASY / At Standby /
Times Cleared 0.
The negative is meaningful because the panel does read each payload -- slot 02
shows 5% clear ratio against the others' 6%, and Points tracked +24 exactly.
Two controls: patching a slot header to "STAGE09 HARD" changed nothing (the
display is payload-driven, not header text), and the row date follows the
container FILETIME.
Remaining candidates: +12, +20, +40 (u64), +60, +64, or the phase string.
Also here: savegame_edit.py --slot for SHAB records, and boot_menu.sh itself --
nav_probe.sh's boot loads a save, which with probe slots on disc loads a probe,
and a dropped d-pad step there put A on TAKE OFF and spent a boot loading a
mission.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
