KeWaitForSingleObject is kHighFrequency, so it is silent unless
--log_high_frequency_kernel_calls=true - which confirms the corpus's earlier
"kHighFrequency waits are simply unlogged" note. With the flag the calls do
appear (1944 lines in 40 s), but the emulator slows so far that after SEVENTEEN
minutes the screen was still black and skip_intro had not seen even the intro
movie, with 175 MB of log written. A 2400 s boot budget did not help; the boot
was not going to finish.
Recorded with the numbers so nobody pays them twice, along with the two cheaper
routes: a targeted Canary log line that fires only after a wait has timed out N
times on the same thread (self-selecting, free on a healthy run, one small patch
plus a build that is already configured), or digging the PPCContext out of a
stack frame under gdb - possible but fragile, since the Release binary has symtab
only and no DWARF.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PMRJjbxLqZtsb5Vb7KunPE
The gdb route works, and the recipe is written down: run-canary execs $XENIA_BIN,
so a wrapper that execs "gdb --args <real binary>" keeps the lockfile, the flags
and the process name (gdb forks and execs the real binary, so ps -C xenia_canary
still finds the inferior) while satisfying ptrace_scope=1 by being the parent.
The Release binary is not stripped - 26595 symtab entries - so frames have names.
The handle SIGSEGV/SIGBUS/SIG32-35 lines are mandatory: xenia uses SIGSEGV for
guest memory watches and the RT signals for thread suspend.
A run froze after ~4 minutes of flight, screen still "flight" rather than GAME
OVER, and all 79 threads had backtraces. EVERY ONE is in a wait - guest threads
in KeWaitForSingleObject / NtWaitForSingleObjectEx / SelfSuspend, the GPU command
processor parked idle, the main thread in poll().
It is nevertheless burning 1253 ticks per 10 s: 403 in the TimerQueue thread
(nanosleep inside TimerThreadMain) and 290 + 274 in two guest threads that the
backtrace shows blocked in KeWaitForSingleObject. A thread genuinely blocked
cannot burn 28% of a core, so those two are CYCLING - a timed wait that expires
and is re-entered - with the timer thread servicing them hot. Three samples
minutes apart show identical frames.
That refines the earlier "the guest is spinning, not deadlocked": the CPU burn is
real but it is in the WAIT PATH inside the kernel layer, not in guest code. The
shape is an event that never gets signalled.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PMRJjbxLqZtsb5Vb7KunPE
The freeze's named next step is more expensive than it looked, and the reasons
are recorded before anyone starts it: xenia's stack walker is a TWENTY-LINE STUB
on POSIX (Create logs "unimplemented" and returns nullptr), so
ThreadDebugInfo::guest_pc is never filled here; PPCContext carries no live PC
either. A reverse host->guest map is buildable - the code cache already learns
the mapping in OnCodePlaced - but that plus a way to sample another thread's RIP
is a real emulator feature, not a patch.
The cheap route that does exist: gdb is installed and ptrace_scope is 1, so
attaching to a running emulator is refused but launching it UNDER gdb is not -
run-canary execs $XENIA_BIN, so a wrapper that execs "gdb --args <real binary>"
keeps the lockfile and flags and makes gdb the parent. That would separate
"spinning in guest JIT code" from "spinning in a xenia loop", which is the fork
this is stuck on. Not attempted yet.
ob_bitflag now locates the counter itself from the three addresses measured so
far, instead of refusing when the default one is wrong. That costs no
transitions, and with roughly half of all runs ending early, transitions are the
scarce resource.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PMRJjbxLqZtsb5Vb7KunPE
ob_bitflag.py is the follow-on the word-level refutation named: for every 4-byte
offset in the window and every one of its 32 bits, count how many entities have
it set, keep the pairs whose count is exactly the counter, and require them to
match again after a transition. Both polarities, since an objective could be
marked by a bit that is CLEAR on it.
Three runs, no verification, and the reasons are recorded: run 1 gave 187 + 33
candidates at counter 4 and then reported "the counter never moved" for 700 s -
about a mission that had ENDED in GAME OVER partway through; run 2 hit the same
dead mission; run 3 had the counter at a different address (the guard refused,
correctly) and then froze after one filter.
The hole is closed. frozen() asks whether the guest is ANIMATING, and the GAME
OVER screen animates happily - mean colour (114,22,63) - so every liveness check
passed while the mission was over. frozen.in_flight() classifies the screen with
screen_id, and ob_hunt/ob_flag/ob_bitflag now abort with NO LONGER IN FLIGHT.
That is the second confident negative in this investigation that was really about
a dead world, so the rule is written down: before believing "X never happened",
show that the thing that would produce X was still running.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PMRJjbxLqZtsb5Vb7KunPE
With the pilot finally shooting, the experiment completed both halves. Sample A
at counter 12 over 120 entities gave 2 offsets where exactly 12 entities share a
value; the counter then went 12 -> 11 and NEITHER survived. So within +-0x400 of
an entity's position triple there is no 4-byte word whose shared-value population
tracks REMAINING OB.
The limits are recorded as part of the result, because they bound it: the test
asks which entities share an EXACT 32-bit value, so a single bit ORed into a word
that also carries health or a timer would never show up - a bit-level version of
the same differential is the follow-on. Anything outside the window, or on
entities that entities2 cannot see (it types by position CHANGING, so stationary
objectives are invisible), is untested too, and the populations differed a lot
between samples - 120 against 194.
Separately: REMAINING OB went 12 -> 11, the first decrement of this whole
investigation, while pilot.py logged 411 fire=1 samples and the HUD reached YOU
KILLED WARPLANES 0003. Stated carefully - it does NOT show the counter counts
kills, since an earlier run had the hostile population fall by a third with no
movement; it shows some kills close something the counter tracks.
Two robustness fixes: ob_flag retries an empty entity sample (one void run was
caused by exactly that), and Pad releases everything on interpreter exit - a
file-backed pad PERSISTS after its writer dies, so a tool killed mid-press would
leave a button held and the game would walk through menus on its own.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PMRJjbxLqZtsb5Vb7KunPE
Measured, not argued: command a 45-degree-off-the-nose error and watch whether it
shrinks, both axes, both sides, two pulse widths, with the opposite sign as a
control. Yaw's sign is correct (45 -> 11.3/32.7 at 0.6 s, 41.6/33.8 at 1.2 s).
Pitch's is inverted - the pilot's own sign GREW the error every time
(48.3/55.6/70.7/91.7) and the opposite shrank it every time (30.7/41.5/15.7/9.6).
A method artefact is recorded because it gave the opposite answer first: a 3 s
full-deflection pulse overshoots a 45-degree error so far that BOTH signs look
wrong (45 -> 164 and 45 -> 178). A long pulse cannot answer a sign question.
Verified against the game rather than by inspection. Before: fire=1 in 0 of 13521
samples, |aim yaw| pinned at 90.0, target 36-43 km away. After: 43 of 1732, aim
down to 2.3 degrees, range median 6.3 km, and the HUD's own ammunition counters
moving - NOSE BM 06000 -> 05723, MAIN MPM 00300 -> 00298.
Also fixed a leftover of the same FIFO era: pilot.py called pad.f.write("tap A
90") for the target-select double tap, which raised AttributeError once Pad
stopped having an `f`. Pad gained tap()/dpad(); ctrl_probe.py and target_probe.py
still use pad.f and now say so in place.
Still open: YOU KILLED is 0000 after 250 s of firing and REMAINING OB is still
012. The craft shoots, closes and selects; whether it destroys anything is next.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PMRJjbxLqZtsb5Vb7KunPE
The uinput pad was replaced on 2026-08-13 (canary cbfad1ab3), which is when
flight_probe.Pad stopped reaching the game. flight-controls-runtime.md predates
it (2026-07-30) and is safe; flight-speed-law.md was last touched on the same
day and cannot be placed from dates alone; anything after it measured a craft
that was not being flown.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PMRJjbxLqZtsb5Vb7KunPE
flight_probe.Pad opened /tmp/sylph-vgamepad.fifo, "the vgamepad server's FIFO".
That server was removed when the uinput pad was replaced by Canary's --hid=file
driver, because a uinput device is not namespaced and scripted presses leaked to
the host's desktop. The FIFO is now an ordinary 91-byte file nothing reads, and
/tmp/xenia_pad.txt - the file the emulator polls - was 0 bytes while the
"autopilot" was flying. So every axis, trigger and button from pilot.py,
autopilot3.py, aim_probe.py and flight_probe.py went nowhere, silently.
The corpus already carried this trap for the SHELL scripts
(canary-scripted-input-traps.md, "every call here failed silently"). This class
was missed, and every flight tool imports it.
Verified against the oracle rather than by inspection, on runs confirmed
animating at both ends of every phase: before, full stick produced 0.00 degrees
of heading change over 4 s while the ship travelled 350-735 units, and the
attitude matrix at pos-0x70 was byte-identical; after, LX=-1 turns 12.72 degrees
and LX=+1 swings the flight direction from [1,0,0] to [0.13,-0.14,-0.98], with
the matrix moving 0.44/0.31 under stick and 0.0000 at neutral.
That also REFUTES the "stale attitude matrix" suspicion from the earlier pass -
pos-0x70 is live and tracks the ship; it only looked dead because nothing was
turning the ship.
Still open and said plainly: with the pad fixed a 150 s pilot run still fires 0
times, with |aim yaw| still exactly 90.0 and the target 36-43 km away. Steering
works now, so what is left is the stick SIGN against the pilot's error convention
or a target selection that commits to something too far to close. Both are
finally testable.
findrot_global/findself/findspeed/selfstate still write to the dead FIFO and now
say so in place; they are not repaired because none has been re-run since.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PMRJjbxLqZtsb5Vb7KunPE
A frozen guest still changes ~30000 words a second (180952-235973 in 6 s, 0.2% of
the data) against 1863296 in 4 s (2.08%) while running. By region the frozen
activity concentrates in 0xbf900000/0xbfa00000, in 0xbe0-0xbe3 00000, and in the
0x704/0x705 pages that the boot log shows are guest thread STACKS - frame churn,
which is what a spinning thread looks like.
Stated plainly as not-yet-interpretable: there is no matched region breakdown for
the RUNNING case, because the control predates the summary. Those regions may
simply be the busiest ones at all times, and one run fixes that.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PMRJjbxLqZtsb5Vb7KunPE
fire=1 appears in 0 of 13521 samples. The gate that closes is measured rather
than guessed: over the 3004 samples that had a target, |aim yaw| is EXACTLY 90.0
degrees every time, which is the `if ez < 0` branch in sticks() - the target is
astern - with pitch near 180 and a range that grows 22km -> 49km and plateaus.
The craft flies away from what it is chasing for fifteen minutes and the turn
never completes.
What is NOT established is why, and the attempt is withdrawn rather than kept:
aim_probe.py reported the forward vector pinned at [-1,0,0] with 0.00 deg/s under
neutral, full-left and full-right stick, which looks like a stale attitude
matrix - but the guest had FROZEN partway through the probe, confirmed after the
fact by frozen.py and by the player position being identical across 3 s. A dead
world holds every matrix still. The probe is committed because it is the right
experiment; its numbers are not evidence.
One confusion resolved: today's entities2.py "0 moving triples" bind failures are
the freeze, not a tool defect - moving() types entities by position CHANGING, so
a frozen world yields nothing by construction.
live_delta.py gains a per-1MB-region summary; a flat list is useless at 236000
hits.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PMRJjbxLqZtsb5Vb7KunPE
A run that stayed animating for 25 minutes gave the first proper sample: 161
entities against a counter of 12, so "not a class head-count" is now confirmed on
a sample seven times larger than the frozen run's. Eleven candidate offsets, with
who they group recorded - and the two biggest groups look wrong for an objective
flag on inspection: seven consecutive floats shared by 12 of 32 attackers read
like one shared AI/weapon parameter block, and +0x0238 = 4 is shared by twelve
TURRETS, which do not fit an objective that says "shoot down all invading enemy
fighters". None of it is verified.
The reason it is not verified is itself the result: REMAINING OB held at 012 for
fifteen minutes of LIVE flight - not a frozen world this time - so there was no
second sample. And it held while the hostile population fell from 132 to 93 ADAN
entities. That is a much stronger version of the earlier head-count argument: the
counter is not "hostiles left".
Also recorded, because it weakens every kill-based experiment in the corpus:
pilot.py never fires. fire=1 appears in 0 of 13521 samples. It flies, chases and
evades, and the trigger is never pulled, so kills are the wingmen's.
Freeze frequency updated: 3 of the 7 runs that reached flight.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PMRJjbxLqZtsb5Vb7KunPE
The control this file never had: a run with the Kernel channel on, analysed WHILE
STILL FLYING, has 2738 refused resumes on one pair - more than the frozen run's
1171. The target's own lines show why. The game runs a self-suspending worker
(NtSuspendThread on itself, a manager thread resumes it, thousands of times), and
a self-suspended thread is not host-suspended, so the host Resume legitimately
returns false EVERY cycle: 3115 refusals against 3115 resumes.
The error is named rather than buried: the warning's commit says "~7 times in a
normal boot" and this file generalised that from boot to gameplay, where the
number is thousands. The 150x anomaly was an artefact of the baseline. The
zero-CPU threads go with it - the healthy run has four of those too.
What the instrumented reproduction DOES establish is sharper than the lead was.
The last kernel event in 690000 lines is "Thread F8000204 self-suspending", with
self-suspends 3116 against resumes 3115 - but the resumer never issues another
NtResumeThread at all, so nothing was dropped in flight; every thread stopped
together. And the guest is SPINNING, not deadlocked: over 10 s while frozen the
main thread is in state R gaining 409 ticks and guest threads gain ~680 in total
while making not one kernel call. So it is guest code waiting on something in
guest memory, and the next question is which guest PC.
Two corrections fall out: "the log stopped growing" is not a freeze detector (it
goes quiet for 25 s in normal flight), and 0xbdb59668 held the counter again -
4 of 6 runs now.
freeze_report.py makes the analysis repeatable, and refuses to answer "did this
thread ever run" when the Kernel channel was off rather than reporting a false NO.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PMRJjbxLqZtsb5Vb7KunPE
Two more attempts at the OB-flag experiment, both stopped by it: one froze before
the counter could move, the next had the counter at a different address (the
tool refused to run rather than report nonsense) and then froze as well.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PMRJjbxLqZtsb5Vb7KunPE
A Stage 02 run froze at TIME 01:02 with a radio line caught mid-word. The
emulator was alive at ~200% CPU with its main thread in state R, two screenshots
six seconds apart were byte-identical, and the log ended in a spin: 1171 of the
run's 1200 "host resume was refused" lines are the single pair F80002AC ->
F8000240, starting at the line immediately after F80002AC is created, and the log
never grows again. The commit that added that warning records what normal looks
like - about 7 in a whole boot - so this is a 150x anomaly on one pair rather
than noise. F8000240 itself appears exactly once outside the spin, at creation,
and calls nothing.
Eleven of the frozen process's 79 host threads have zero CPU, four of them
consecutive late-created guest threads - the same signature as the lost resume
that c1b57f93b fixed for the title screen. That fix IS in this build, so either
there is a second window in that race or this only looks alike.
The inference is named as one: nothing here maps a guest handle to a host tid, so
"the zero-CPU threads are the ones being resumed" is a reading of two consistent
observations. And the refusals could equally be the game's reaction to a worker
stuck for another reason - log_mask=13 has the Kernel channel disabled, so not
one of F8000240's waits is visible. The next experiment is written down
concretely: reproduce with LOG_MASK=12 LOG_LEVEL=3 and map the handle to a tid.
Also caps ob_hunt's survivor listing at 40 - an aborted run printed all 21482 and
buried the line that mattered.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PMRJjbxLqZtsb5Vb7KunPE
Three things from one Stage 02 run.
The address recurs a third time: HUD=4 RAM=4 at 0xbdb59668, so 3 of the 5 runs
measured put the counter exactly there.
The counter is NOT a live class head-count. With the counter at 4 the typed
entity list was 8 attackers, 7 friendly Delta Sabers, 7 turrets and the player -
no class has 4 members and no pair of them sums to 4. That sharpens the corpus's
existing "012 against 118 live ADAN" note from "not the hostile count" to "not
the count of any class this enumeration can see".
The flag experiment itself proves nothing, and why is the useful part. It found
20 offsets where exactly 4 of 23 entities agree, then reported "the counter never
moved" for 600 s. The guest had stopped advancing ten seconds into flight:
pilot.py logged 724 s of identical speed/yaw/pitch, and two screenshots six
seconds apart were byte-identical, max delta 0 over 863325 pixels - while
screen_id said "flight", the emulator burned 212% CPU and every liveness check
passed. So that was a fact about a dead world. Withdrawn along with it: the claim
in ob_session.sh that the counter climbs on its own in the first minutes, which
one advancing run supports and this one cannot.
frozen.py makes it a single call, checked in both directions (0 on the frozen
pair, 254 on two frames of a live run), and ob_hunt/ob_flag now say GUEST FROZEN
rather than waiting out their timeouts.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PMRJjbxLqZtsb5Vb7KunPE
Keeps the refutation next to the confirmation rather than replacing it, and
records the rule a future session actually needs: try 0xbdb59668, check it
against the HUD, re-scan when it reads 0.
What stays open under it is unchanged and is the part that matters for the
autopilot - what the counter counts, and whether an OB-badged entity carries a
flag in its entity object.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PMRJjbxLqZtsb5Vb7KunPE
One filter to select (004 -> 008, 35897 -> 7), a second on a transition it was
NOT selected by (008 -> 012, 7 -> 1), leaving exactly one address; then three
live paired readings, RAM/screenshot/RAM, all agreeing with the HUD.
The address is the same one run 1 reported. That does NOT reverse yesterday's
refutation and the entry says so explicitly: runs 2 and 3 read a hard 0 there on
an allocated page while the HUD counted, so "it is there in every run" stays
refuted. What is withdrawn is the stronger claim that the number was meaningless
- it recurs exactly, in 2 of the 4 runs measured, and run 3's amber candidate
0xbdb49668 sits one 64 KB page below it at the identical page offset 0x9668. The
practical rule is therefore: try 0xbdb59668, check it against the HUD, re-scan
when it reads 0.
Why run 3 failed and run 4 did not is also recorded, because it is a method
lesson rather than luck: the evidence was always in the first four minutes of the
stage, and the earlier runs simply could not look often enough - every HUD
reading cost a human round trip, so the 008 step went by between two of them.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PMRJjbxLqZtsb5Vb7KunPE
The launcher item closes: unattended boot to Stage 02 flight works again, and the
entry now names all three defects that were in the way, including the
wait_flight pixel that was outside the HUD.
The objective-counter item stays open but is sharper: a HUD-clean scan exists,
and the surviving candidate that is hard to dismiss is named with the odds
against it being chance. The blocker is now the pilot's survival, not the method.
Also withdraws yesterday's claim that the "Auto-Save is active. OK?" dialog does
not return - the run that appeared to show that was tapping A every six seconds
while it waited, so it cannot distinguish "absent" from "dismissed unseen".
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PMRJjbxLqZtsb5Vb7KunPE
With the launcher repaired the scan could be run the way the method asks: the HUD
was confirmed at 004 immediately before AND after the 0.9 s scan, and the filter
was taken at a confirmed 012. That leaves 17 candidates from 39596.
One of them is 0xbdb49668 - the run-1 address minus exactly 0x10000, at the same
page offset 0x9668. Checked rather than admired: of all 39596 words holding 4 at
scan time, exactly TWO sit at that page offset, so a survivor landing there by
chance is a ~5e-5 event. The reading it suggests is testable - the counter sits
at a fixed offset in an allocation whose base moves by whole 64 KB pages.
Recorded as amber, not green, and the reason is written down: the later sample
that killed 10 of the 17 was taken during the GAME OVER flash, with no HUD on
screen, so the seven survivors are unrefuted rather than confirmed. The mission
ended because the escorted ACROPOLIS was lost at ~13 min while pilot.py sat in
EVADE/RETIRE; REMAINING OB held at 012 for the ten minutes before that, so there
was no transition to verify against.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PMRJjbxLqZtsb5Vb7KunPE
Two separate reasons the scripted route stopped, both measured rather than guessed:
* LOAD -> READY ROOM is not 28 s. Both runs on 2026-08-23 overran it, so the next
press was eaten by the transition and the run ended up in OPTIONS once and
BRIEFINGS once. wait_screen.sh now waits for the screen, with an optional
--tap that clears a dialog the caller cannot know about (a freshly restored
profile inserts "Auto-Save is active. OK?" here).
* The READY ROOM is DRAWN long before it is USABLE: it comes up with a
"Preparing to Sortie" spinner and TAKE OFF greyed out. The two states differ by
1.7 units of blue whole-image, so screen_id.py cannot separate them and should
not try. take_off_armed.py tests the label instead: 0.0000 bright pixels while
preparing, 0.1633 once armed, on three captures from two runs. It carries its
own position check - the always-enabled BRIEFINGS label below reads 0.1027 in
all three, to four decimals, so if that reference is dark the boxes are off the
labels and the answer is "unknown", not a confident wrong one.
screen_id.py gains a "readyroom" class from the same measurements; nothing else
reclassifies.
Verified end to end and unattended: boot -> title -> LOAD GAME -> slot 01 ->
READY ROOM -> TAKE OFF -> "IN FLIGHT at 34s", pilot bound and engaging.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PMRJjbxLqZtsb5Vb7KunPE
0xbdb59668 reads 0 in two independent Stage 02 runs while the HUD counts
004 -> 008 -> 012. Not an unmapped read: SEEK_DATA at that offset returns the
offset itself and the next hole is 5 MB later, so it is an allocated,
zero-filled word. The address was a per-run artefact, exactly as that file
already suspected it might be; the method is the durable result.
Re-finding it in the new run also failed, and both failures are recorded because
they are the instructive part. Two candidates were produced and both died on the
corpus's own rule -- verify across a transition you did not select on:
0xbc2377dc went 12 -> 18 while the HUD stayed 012 and read 3 two minutes later,
and 0xbd295b04 was plain noise.
One correction to the method note in that file: the scan is not slow. Over the
live /dev/shm image it takes 0.9 s. The real trap is that REMAINING OB climbs
004 -> 012 within about four minutes as waves spawn, so a scan is only valid if
the HUD is confirmed to hold the same value immediately before AND after it --
which is why the earlier 4-then-8 intersection came back empty.
What blocked finishing: with pilot.py retired at hull 340/1500 nothing was
killing objectives and the counter sat at 012 for five minutes, so there was no
later transition to filter on. What the counter counts, and whether an OB-badged
entity carries a flag, is untouched.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PMRJjbxLqZtsb5Vb7KunPE
The baseline binary, the profile, the Stage 02 save and the caches all live
outside both repos and had been wiped, and sylph-doctor reports 'all good'
without them. This is the recipe, verified by driving it to Stage 02 flight
rather than by inspecting files.
Three things worth having found:
* the baseline is an INCREMENTAL build, not a scratch one -- auto/upstream-baseline
differs from the instrumented branch in 202 files and zero submodule gitlinks,
so checking it out in the shared tree and rebuilding into the existing build dir
takes ~9 min at -j4. git worktree prune first; a dead worktree still claims the
branch.
* the baseline CANNOT make a profile (--create_profile_if_none is one of our 50
commits) and the Sign In dialog cannot be typed into, so bootstrap the profile
with the instrumented binary once and run the baseline against it.
* the Xbox content .header is NOT needed -- ContentManager::ListContent falls back
to the directory name when ReadContentHeaderFile fails, checked in the source.
The LOAD GAME screen then shows date, difficulty, flight time and clear ratio
anyway, which proves those come out of savedata itself. No header was fabricated.
Trap paid for once: keep the file name xenia_canary. A copy saved as
xenia_canary.baseline-... survives every pkill -x in the toolkit and holds the
run-canary lockfile while ps -C xenia_canary shows nothing.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PMRJjbxLqZtsb5Vb7KunPE
The mission's objective counter is a big-endian u32 at guest VA 0xbdb59668 in a
Stage 02 run on the upstream baseline. It was selected on an 18->24 transition
and then tracked 24->23->22 against the HUD on its own - four readings, two
changes it was not filtered on.
That last point is the whole discipline here, because the first attempt failed it.
An earlier differential over 19->18 also produced exactly one candidate,
0xbc22e83c, which matched the transition it was selected on and was still wrong:
read live it held 26 while the HUD showed 017. One matching transition is not
evidence.
A second trap is recorded too: a three-snapshot filter requiring 19 -> 19 -> 18
left ZERO survivors, because the value moves between the memory copy and the
screenshot that reads it. Filtering on the next DISTINCT value instead found the
counter on the first try.
ob_scan.py carries the method: scan one snapshot, then filter the candidate set
against live /dev/shm/xenia_memory_* at each new value, so only the first pass
needs a 4.8 GB copy.
Stated plainly as unsettled: the ADDRESS is from one run and cross-run stability
is untested, so the durable result is the method rather than the number. And what
the counter counts - whether every OB-badged entity is one of them, and whether
that badge is a flag in the entity object - is the follow-on the pilot actually
needs to CHOOSE targets rather than just know how many remain.
Built upstream/canary_experimental (a5a18f5c7, 82 commits ahead of our merge
base) clean, to answer whether the 0x82307128 mission crash is ours or theirs.
Two tooling gaps found building it: version.h is never generated (upstream's
xenia-build.py writes it, build-canary does not invoke it, and our tree only
builds because a stale copy from an old sylpheed-re build sits in the build dir),
and build-canary reports exit 0 on a FAILED build - only the missing binary gave
it away.
Pure upstream cannot be driven at all: --hid=file is ours and there is no uinput
here. So the honest baseline is upstream plus those three pad commits. That
baseline reproduced the LOST RESUME on its second boot - black screen, guest at
522% CPU, newest host thread at 00:00:00 CPU, zero kernel calls from its handle -
and upstream's threading_posix.cc still has the two-lock-scope publish. So pure
upstream is not a stable state; it carries a bug we had already fixed.
Adding ONLY the threading fix on top - still none of the RE instrumentation -
reaches Stage 02 FLIGHT: TIME 05:03.75, wingman Rhino 103, radio dialogue, and
REMAINING OB 020 with OB badges on targets. The run ended in a legitimate GAME
OVER (the unattended craft was shot down, as autopilot-memory-driven.md warns),
not a crash. Crash dumps for the whole run: 0, against 384 on the instrumented
branch at the briefing alone.
So the mission crash is not upstream's. Whether it is in our 50 commits or fixed
among upstream's 82 this run does not separate; that needs a bisect.
REMAINING OB is visible and moves (020->019->018->017) but is NOT found. A
three-snapshot BE-u32 filter left 0 survivors; a differential across widths gave
exactly one candidate, 0xbc22e83c, and it is REFUTED - read live it held 26 while
the HUD showed 017. The empty u32 filter is itself informative: the counter is
not a plain persistent big-endian word.
Finding REMAINING OB in RAM means getting to the escort stage, and
launch_mission.sh exists for exactly that. It carried three of the dead patterns
this session has been clearing: six vgamepad calls (the command no longer exists,
so the entire scripted route pressed nothing), the XUID E0300000EFBEA3D4 which
has no profile behind it and therefore opens the sign-in dialog that swallows
every keystroke, and the emulator's stdout going to /dev/null. wait_flight.sh had
a fourth, in the tap that skips the launch cinematic.
Fixed, the route works far past where it used to stop: boot -> title -> LOAD GAME
-> slot 01 -> READY ROOM -> TAKE OFF -> the Stage 02 briefing map, with ACROPOLIS
labelled on it.
And it stops there: 384 dumps at PC 0x82307128 and no flight HUD within 300s. The
briefing is still animating (two shots a minute apart differ by RMSE 2986), so
the emulator is not frozen - flight simply never starts.
One discriminator worth recording: the TUTORIAL reaches flight and has run
completely crash-free, while this path crashes during the briefing, which is
where the stage content loads. That is consistent with the cache-flush shape the
crash has always had, and points at WHAT is being loaded rather than at how far
the navigation gets.
REMAINING OB is therefore still not found - the mission was never entered.
The autopilot doc's own problem #2 is that the pilot ignores the mission
objective - its 300s run took no damage, killed one fighter, and watched
REMAINING OB RISE from 004 to 011. So this surveys where that knowledge is.
GP_TUTORIAL.pak yields the game's own list of what a player can do: BASIC
CONTROLS, HEADS-UP DISPLAY, RADAR, SUPPLY AND SPECIAL MOVES, RADIO ORDERS,
ADVANCED CONTROLS, with descriptions. Worth stating against what the pilot
actually does: pilot.py and navigator.py use move and attack only. Resupply,
special moves, radio orders to wingmen and advanced maneuvers are all unused, and
two of them bear directly on open problems - resupply is the untested RETIRE
mode, radio orders is an escort lever that flying skill does not substitute for.
tables.pak is a name-resolved config seam: 79 IDXD objects, 6275 distinct field
names, including DLG_MISSION_OBJECTIVE and DLG_STAGE_TITLE01..16 (so 16 stages).
GP_MAIN_GAME_<lang>.pak holds 131 weapon\ tables, 113 unit\ and 64 message\ -
the weapon ones being what problem #1 wants for real projectile speed and range.
But the objective TEXT is not text: DLG_MISSION_OBJECTIVE = pdscr099.prt, a
screen part, and the message tables resolve to face textures. All human-readable
text in this game is rendered sprite art, which is why the UI work has been
reading pixels all along. A per-mission objective table is an OCR job, not a
table dump - so the cheaper and more actionable route is the runtime REMAINING OB
counter, which is on the HUD and therefore in RAM.
The previous commit framed the empty capture as "the 3D draws never reach
CaptureShipDrawForRE" and proposed a static comparison to find out why. The
comparison was done and it refutes the framing.
The discriminator for ship geometry is stride=24 prim=4 with a large vcount -
xbg7-mesh.md records a real one as stride=24 vcount=10891 indices=18 prim=4. Not
"positions outside the screen rectangle", which is what I used and is a bad test:
a UI sprite placed at (137,308) passes it.
By the correct test this run's capture has exactly one prim=4 draw, a 6-vertex
full-screen quad, and the 2.9 MB file I was comparing against has NO prim=4 draws
at all. That file is a UI capture: 1303 of its 1582 draws are stride=24 prim=13,
which two other docs in this corpus already identify as the UI sprite shader. The
"1300 3D draws" it appeared to contain were UI sprite coordinates counted by the
bad test.
So the capture recorded exactly what was on screen. The tutorial's opening is an
empty starfield, the player's own ship and a HUD - no capital ship. And
ship-placement-runtime-capture.md has always stated the procedure: play into the
mission, frame the ship side-on, press F10.
What remains is therefore not a code question but a gameplay one: reach a real
mission and frame a capital ship. Worth stating that the original capture was
taken interactively on HW Vulkan, and this container runs lavapipe.
ship_capture_window.sh polls for the flight screen and presses F10 the moment it
appears rather than after a fixed sleep. One run gave three results.
First, the mission ran with ZERO crashes through t+152s - the first clean mission
run, where the three before it ended at 13243 / 11898 / 11497 - and it renders
and plays: player ship, starfield, full HUD, no dialog.
Second, the capture armed and wrote its file, so the mechanism works in-mission.
Third, and against expectation, the file holds NO ship geometry. 329KB, 181
deduped draws: 180 of them share a single vertex shader, all stride=28 vcount=3
prim=8 at full-screen coordinates, plus one full-screen quad, and not one draw
has positions outside the 1280x720 rectangle. The budget is not the limit -
kShipCaptureBudget is 8000 and only 181 distinct (vbase, WVP) pairs were seen -
and the scene was definitely drawing. The known-good capture from an earlier
session is 2.9 MB.
Fourth, a correction to the previous commit. It said the cache is "REFUTED as the
cure". Too strong: this run used the IDENTICAL complete cache as tut4 and
produced 0 crashes against tut4's 11497. What four runs support is that a
complete cache is not SUFFICIENT to prevent the storm and that run-to-run
variance dominates a 3-run comparison - not that the cache does nothing.
Next step is static: compare this capture's shape against the known-good one to
find why the 3D draws never reach CaptureShipDrawForRE.
This page's own reproduction - move the cache aside, get a throw; restore it, get
none - made "the cache is incomplete" the obvious explanation for the mission
crash. Three tutorial runs say otherwise.
tut2 subdir 6 MISSING 641 crashes by t+24s 13243 total
tut3 missing -> gained 6 in-run 2 crashes to t+80s 11898 total
tut4 6 present from the start 2 crashes to t+56s 11497 total
The missing entry was real: \aab216c3\6 was requested and absent, and the game
wrote it during tut3 (11 -> 12 files). tut4 then ran with a complete cache and
stormed anyway. Every dump across all three runs is PC 0x82307128, one address,
no others. So the cache may gate the boot-time throw this page documents; it does
not gate the mission one.
What the runs did give is an opening. Both post-cache runs show the same shape -
exactly 2 crashes, then nothing, for 56-80 seconds of rendering, advancing
mission - where the first run was already at 641 by t+24s. That is where the
second capital-ship capture has to happen: F10 armed INSIDE the window. Not a
guarantee, since the storm began at t+24s, ~t+96s and ~t+56s across the three
runs, but two of three offered most of a minute.
The 1663 refused resumes on thread F80001D8 looked like a second lost resume of
the kind fixed earlier today. They are not.
That thread DID execute - the log carries its XThread::Execute line, guest entry
82FFE6C0 - and then 137000 lines of silence. The silence proves nothing:
KeWaitForSingleObject and NtWaitForSingleObjectEx are declared kBlocking,
kHighFrequency, and PrintKernelCall skips every kHighFrequency export unless
--log_high_frequency_kernel_calls=true, which defaults to false. A thread parked
in a wait is invisible in these logs.
So the boring reading is the right one: the guest kicks a worker that is blocked
ON AN OBJECT, and Resume returns false because the thread is not SUSPENDED. That
is what a refused resume means, exactly as suspected before the count made it
look interesting.
Method note kept in the doc, because it is the reason one conclusion survives and
the other does not: the title-loader finding rested on 00:00:00 host CPU time
from ps -L and on the fix changing behaviour 5/5 against 1/5 - not on log
silence. In this codebase log silence alone is never sufficient evidence that a
thread is idle.
Also records a grep error of mine that briefly produced "zero kernel calls,
ever": the pattern ^[dikwF!]> missed the K> kernel prefix. Caught before it was
written down, and it changed the conclusion.
The backlog has said a second capital-ship capture needs the 0x82307128 crash
dealt with first, because the run died at SELECT DATA before any mission
existed. That is no longer where it stops. With the Canary threading fix making
the menu dependable, tutorial_launch.sh drives boot -> title -> menu -> TUTORIAL
and the mission LOADS AND RENDERS: flight HUD, "Go to the box on your screen",
warship counters, controller diagram.
It then freezes. 13243 crash dumps, every one at PC 0x82307128, guest thread 9,
Access Violation read at 0x10000000C, preceded by exactly ONE
RtlRaiseException(E06D7363) right after a HostPathDevice::ResolvePath() with
empty arguments - the cache-flush shape. Two screenshots 6s apart are identical
(RMSE 0), no new dumps accumulate, and the process still burns 400% CPU.
So: reachable, renders, unusable for a capture. The blocker moved rather than
lifted, which is worth recording precisely because the entry's stated reason is
now wrong.
One new lead, deliberately not claimed as a cause: the resume-refused diagnostic
added with the threading fix fires 1671 times on this path and 1663 of them are
the SAME thread, F80001D8, with 152 before the first crash - against about 7 on
the menu path. Resuming a non-suspended thread legitimately returns false and
"Resume to kick a worker" would produce exactly this, so it is a lead, not a bug.
It is cheap to settle: check whether that thread makes kernel calls between
refusals.
Cheapest next test named: this page already shows a COMPLETE on-disc cache
produces no throw at all, and the cache is 40MB with .partial/.cold-rebuilt
leftovers beside it. One boot to warm, one to re-test.
The three orders the derived rule was built from all live in GP_TITLE.pak, so
they cannot confirm it - the rule was fitted to them. These two are from
GP_SAVE_LOAD.pak, read off the running game now that the Canary threading fix
makes the main menu dependable.
The 9-element slot-list header composites EXACTLY as the sort predicts, on all 6
instances of it, and nothing about this screen was fed into the rule:
measured 7 8 0 1 2 3 4 5 6
derived 7 8 0 1 2 3 4 5 6
including TWO tied groups (0xb102 x2 and 0xb210 x5) that both come out in
declaration order, and the unkeyed pfeff00.prm fade quad last.
The 13-element save/load frame differs in exactly the two open questions and no
new ones: two unkeyed pfbase.tbm backgrounds paint FIRST where the sort puts the
keyless last - the splash's palogo_eff0.prm behaviour in a different file type,
so implied_layer_key now covers it - and the 0xb100 group of four paints
10,11,8,12 where declaration order is 8,10,11,12.
That second point is a SECOND screen with a mis-ordered tie, which is what the
question needed, and it immediately kills a candidate: 10 and 11 are kind=0x2002
while 8 and 12 are 0x0000, so "descending kind then declaration index"
reproduces 10,11,8,12 exactly - and then fails both title groups, where every
element of 0x8083 is kind 0 and where 0x80a0 would predict 2,3,4,5,0,1,7 against
a measured 0,2,4,7,1,3,5. Seven candidates refuted now.
16 disc tests green.
resume_reliability.sh counts, per boot, whether the title's loader thread became
the CALLER of a kernel call. Counting boots where the press reached the title:
before the fix 1 of 5 ran the loader; after it, 5 of 5. Three of the post-fix
boots were driven far enough to classify the screen and all three reached the
MAIN MENU, each with the same shape - title at 216-252s, 40 kernel calls by the
loader, 6 ResolvePath reads. The failing boots before had zero of both, every
time.
Caveat kept in the doc: pre-fix runs were interleaved with compiles and a race is
load-sensitive, so the counts corroborate the mechanism rather than carry it.
Also fixes a self-inflicted confound. Two runs came back 'title_at_s=none' with
the emulator log ending in 'Killed', which I first read as the title detector
being too strict. It was not: an earlier copy of the script was still running
because 'pkill -f resume_reliability.sh' had matched the shell running it rather
than the script, and each of that copy's iterations kills the emulator BY NAME -
outside run-canary's lockfile. The harness now takes its own lockfile and refuses
a second copy, and the note records that pkill -f matches your own shell.
The stalled loader thread is a lost wakeup in Xenia's POSIX threading, fixed on
the canary branch as a60fe7d11 and written up here. A thread created suspended
publishes state_ and suspend_count_ in two separate lock scopes, and Resume()
waits only for state_ before testing suspend_count_ == 0 - so a resumer in the
gap drops the resume and the thread waits forever. The Linux XThread::Resume
discards that false, which is why the guest saw success.
On the first clean boot after the fix the loader thread is the CALLER on 20
kernel-call lines and issues 4 ResolvePath reads. Every failed boot before it had
exactly zero of both.
Stated plainly as not shown: that boots now reach the menu RELIABLY. One post-fix
boot, and it is confounded by the harness.
Which is the second half. skip_intro.sh's title test has now been wrong twice in
opposite directions: originally one absolute pixel (625,618) - a 1280x720
coordinate against the 1279x675 game surface, so it read the copyright line and
timed out with the title on screen - and then my replacement, screen_id.py, which
is too loose and called the SQUARE ENIX publisher logo "title" 151s into a boot,
spending the script's single press there. is_title.py now counts the green (A)
glyph over the whole frame: geometry-independent and specific, measured at 0
pixels on the logo and 1520 on a real title.
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.
"The title screen ignores (A)" is withdrawn. First-divergence across three boots
of the same binary says otherwise.
A slot-(1F) guest thread is spawned BY the press: exactly once per run,
immediately after the keydown, same stack base 70880000-70900000 in both runs
that got one, and never at all in the run that never accepted a press - which
rules out a periodic worker starting around the same time.
prm6, reached the menu: (A) at line 6498, (1F) at 6500, 6 ResolvePath after
opt2, stuck on the title: (A) at line 1287, (1F) at 1288, 0 ResolvePath after
opt, stalled before title: no (A) ever, no (1F) thread at all
In the successful run the loader immediately reads six paths out of the on-disc
cache and the menu appears. In the failed run the same thread starts and performs
no file I/O ever again. Total ResolvePath for the three boots is 90/84/78 - the
successful run's extra six are exactly the ones after the press, so the boots are
otherwise identical in I/O.
Refuted as the cause: the cache-flush std::out_of_range. All four of today's runs
have zero GUEST-THROW, zero CRASH DUMP and zero Access Violation, and the guest
stays alive throughout with its keystroke-poll counter climbing past 15000.
Next probe is neither input nor the crash: what the (1F) thread waits on.
The tie-break needs a fourth measured screen with a tied group, and OPTIONS is
three d-pad steps from the main menu, avoiding the NEW GAME hang. It was not
reached.
Advancing past the title is intermittent: 1 success in 3 attempts today with the
same binary, profile and procedure.
Attempt 1 stalled before the title existed. The guest was alive - RSS steady at
598MB and the keystroke poll counter climbing past 15000 - but the screen was
black and screen_children.py found ONLY the splash object resident. So that
failure is not a presentation problem: the game never constructed the title.
Being able to separate "stalled before building the screen" from "built but not
presenting" is new, and it is what the reader is for.
Attempt 2 reached the title at 265s and refused four presses - (A) at 0.25s,
0.25s and 0.5s, START at 0.3s - every one of them logged as DELIVERED to the
guest. Third independent confirmation that input delivery is fine and the game
simply does not act on the press. Waiting longer does not help either: presses
were spread from 10s to about 4 minutes after the title appeared, while the
earlier successful run's press landed within seconds.
Records the log as evidence and states the next probe: it has to be guest-side
now, on whatever consumes the keystroke, since the input path is excluded.
With the layer key and the primitives' implied keys in place, the tie-break -
how the game orders elements sharing a key - is all that is left between the
derived order and ground truth. Three measured screens now constrain it.
On the menu and the splash every tied group comes out in declaration order,
which is what the stable sort already gives. The title is the only screen that
discriminates, and nothing predicts it: 0x8083 x5 paints eff1, eff2, eff5, eff3,
eff4, and 0x80a0 x7 paints logo1 x3, tm, logo2 x3.
Refuted: declaration order; RATC child order; first keyframe time (52, 56, 62,
58, 60 - the measured order is not sorted by them); resting keyframe time;
resting X or Y (938, 938, 64, 788, 447); and T8aD header words +00, +04, +0c and
+10, which are either identical within a group or unsorted.
Child order is worth its own line: a strict improvement over declaration order
(7 misplaced positions on the title instead of 9, and it recovers the logo
grouping) and exactly right on the other two screens. NOT adopted, because on the
only screen that can tell them apart it is still wrong.
Adds a test that measures what the residual costs instead of assuming it. Of the
3 disagreeing pairs of drawn elements across all three screens, all 3 have
overlapping bounding boxes and 2 share opaque pixels: ptlogo_back2eff5 against
eff3 (22568 px) and eff4 (32395 px). The third pair, ptlogo2 vs ptlogo_tm,
overlaps by two columns and shares NO opaque pixel - the wordmark is transparent
there. A bounding-box test called that a defect; reading the alpha says it is
not, which is why the test reads pixels. The set is pinned, so a change that
makes it worse fails.
15 disc tests green.
