Files
Sylpheed/docs/re/script-runtime-probe.md
Sylpheed RE agent e1922d446a re: the JIT context is in %rsi; but the re-run could not locate the mission
From Canary's own source (x64_emitter.cc:881) GetContextReg() returns rsi, so at
any JIT instruction %rsi is the PPCContext* -- which is also why the faulting
instruction read 0x110(%rsi), a guest register load. That is the way past the
watchpoint's ceiling: the guest register file is available at the write, and a
0x82xxxxxx word picked out of it resolves against sylpheed.db to name the caller.
trigger_watch.sh now dumps x/128wx  instead of a useless host backtrace.

The re-run then failed for an unrelated and unexplained reason: it reached
flight, the pilot bound, the guest was animating, and find_mission returned
NOTFOUND. Narrowed: the .ssb header is absent from guest memory (0 hits where
earlier runs hit immediately), ADN110 is absent too, but the manifest string
'Stage02.ssb' IS present at 0xBDA6C50B. So memory is readable and the manifest
is loaded while the script is not, in a mission that is flying.

No explanation offered. The cheap discriminator for next time is to poll for the
header from the moment flight starts and record when it appears, instead of
sampling once.
2026-08-25 19:03:33 +00:00

21 KiB
Raw Blame History

Reading the live script state — the real phase counter, and per-squadron liveness

Status: ScriptMission and ScriptPhase located in a running mission with no debugger, validated arithmetically; the true phase ordinal read live; 🟡 the per-unit state encoding needs care.

This unblocks mission-phase-membership, which was stuck because "38 enemies died" could not say whether the right ones did. Chasing craft→squadron was the wrong angle: the script VM already keeps that table, indexed by the .ssb symbol-table-2 index.

Tool: tools/re-capture/squadron_state.py.

Locating the objects, without gdb

  1. Find the .ssb header in guest memory — 20 bytes of version + code offset
    • the two symbol-table offsets, distinctive enough to hit once. For a Stage 02 run it sat at 0xAB840010.
  2. code base = file base + header code offset (0x24) → 0xAB840034.
  3. [ScriptMission+24] is that code base, so scan for a word equal to it.
  4. Validate arithmetically, not by eye: [ScriptMission+44] must equal file base + symtab1 offset + 4. Measured 0xAB874C94; predicted 0xAB840010 + 0x34C80 + 4 = 0xAB874C94. Exact.

That check is what makes this trustworthy — the candidate is confirmed against a number taken from the file on disc, not against "it looks like a pointer". A second candidate that also pointed at the code base failed it and was discarded.

ScriptMission 0xBC7A2A20
  +4  ScriptPhase*  = 0xBE14DD80      +20 state     = 1  ("phase running")
  +24 code base     = 0xAB840034      +28 pc        = 0xAB84007C
  +40 PHASE ORDINAL = 1               +44 symtab1   = 0xAB874C94  ✓
ScriptPhase 0xBE14DD80
  +196 finished = 0    +244 symtab1 = 0xAB874C94    +324 unit array = 0xBC43B560

ScriptPhase+324+4 → an array of per-unit records. It holds 122 records — exactly the size of Stage 02's symbol table 2, which is an independent confirmation that the index space is the one the bytecode uses.

The real phase counter reads 1 — the mirror was the wrong field

[ScriptMission+40] reads 1 in a phase-1 mission. The runtime mirror at [*(0x828F35F8)+236], which three earlier runs polled, reads 0 — because ChangePhase is only posted once the ordinal exceeds 1.

So the mirror is not a phase readout at all in phase 1, and +40 is. It is reachable from /dev/shm with no debugger, which is what made three runs of polling the wrong address avoidable in hindsight.

PINNED: state 1 = not yet deployed, state 2 = active — and arrivals are real

Watching [ScriptMission+40] and the three objective squadrons together across a live run (data/phase-watch-s02.txt):

[   1.8s] phase=1 finished=0 active= 24  ADN110:1  ADN111:1  ADN112:1
[  58.2s] phase=1 finished=0 active= 27  ADN110:1  ADN111:1  ADN112:1
[  90.7s] phase=1 finished=0 active= 30  ADN110:1  ADN111:1  ADN112:1
[ 120.8s] phase=1 finished=0 active= 29  ADN110:1  ADN111:1  ADN112:1
[ 143.4s] phase=1 finished=0 active= 32  ADN110:2  ADN111:2  ADN112:2   <-- arrive
[ 223.3s] phase=1 finished=0 active= 35  ADN110:2  ADN111:2  ADN112:2

All three flip 1 → 2 at ~143 s, and the count of records in state 2 climbs 24 → 35 over the same window. So for these squadrons state 1 is "not yet deployed", not "gone" — the built-in table's shorthand "1/3/4 = gone/dead/invalid" is incomplete, and reading state != 2 as "destroyed" would have been wrong in exactly the way flagged last iteration. Good that it was flagged rather than assumed.

This also answers a much older question: arrivals DO happen

mission-arrival-watch and the wave work recorded "0 confirmed arrivals" after many runs, measured by watching the craft population. The script's own unit table shows arrivals plainly: eleven more records enter state 2 within four minutes, three of them the phase-1 objective squadrons at a distinct moment.

The old negative was not wrong about what it measured — it was measuring the wrong structure. Craft counts conflate deployment with attrition; the per-unit state field does not.

⚠️ Both runs of this experiment froze — at ~70 s and ~253 s — so the window above is all that was observed, and no phase advance was reached. The freeze witness caught both immediately, which is the only reason the truncation is visible rather than silently producing a flat line.

🟡 The per-unit state encoding is not what the summary implies

For the three phase-1 objective squadrons, early in a fresh mission:

ADN110  idx=1  obj=True  state=1
ADN111  idx=2  obj=True  state=1
ADN112  idx=5  obj=True  state=1
records with state==2 (active): 27-29 of 122

The built-in table describes +16 as "2 = active; 1/3/4 = gone/dead/invalid". But these three have a live object pointer and state 1, in a mission that has barely started and where nothing has been shot. So either state 1 does not mean "gone", or it means "not yet deployed" — not settled, and worth pinning before any conclusion is drawn from it. Reading state != 2 as "destroyed" would be exactly the kind of plausible-but-wrong inference this corpus keeps catching.

What this makes possible

The decisive phase experiment is no longer blocked on attribution — and it has now partly run: the arrival of the three objective squadrons is directly observed. What is still missing is a run that survives long enough (no freeze) for them to be destroyed, which is when [ScriptMission+40] should step to 2. Two attempts froze first.

tools/re-capture/phase_watch.py is the harness: it samples the real counter and the watched squadrons together, witnesses the freeze every 60 s, and prints only on change.

2026-08-25 — the bounded scan fixes the freeze, and the state machine is confirmed live

The sweeps were the cost. Bounding the pointer scan to 0xBC0000000xBD000000 (with a full-sweep fallback) drops find_mission from a full ~371 MB walk to 0.7 s. The run then went 694 s with the probe attached and no freeze, against 3 of 3 frozen inside ~4 minutes with the unbounded version. n=1, but it is the first probe-attached run to survive past four minutes.

Full trace in data/phase-watch-s02-full.txt:

[   0.7s] phase=1 finished=0 active=24  ADN110:1 ADN111:1 ADN112:1
[ 113.8s] phase=1 finished=0 active=33  ADN110:2 ADN111:2 ADN112:2   <- arrive
[ 191.0s] phase=1 finished=0 active=36
[ 433.0s] phase=1 finished=0 active=30  ADN110:2 ADN111:4 ADN112:2   <- ADN111 destroyed
[ 631.7s] phase=1 finished=0 active=27
[ 694.9s] phase=1 finished=1 active=27                               <- phase ends

State 4 = destroyed — a squadron death caught in the act

ADN111 goes 2 → 4 at 433 s while the active count falls 36 → 27 over the same window. Together with the earlier 1 → 2 arrival this pins three points of the encoding: 1 = not yet deployed, 2 = active, 4 = destroyed.

The mission-over branch, observed exactly as disassembled

The phase ended at 694.9 s, but the ordinal did not advance — and the reason is the branch mission-phase-advance read out of sub_82260710:

if ([phase+300] == 2)  post 994 ; state = 0 ; MISSION OVER
else                   state = 5 ; [mission+40] += 1   NEXT PHASE

Measured at the end of the run:

field value meaning
[phase+300] 2 last-phase flag set (built-in 39)
[mission+20] 0 the mission-over state
[phase+196] 1 phase finished
[mission+40] 1 ordinal unchanged — correct for this branch

Every field matches the disassembled branch, on the live oracle. The static reading of the phase state machine is confirmed — for the mission-over half.

🔴 This was a LOSS, not a phase clear

screen_id shows the GAME OVER frame, the escort was down to 35.7 %, and the pilot logged DEAD at 676 s. So a lose path ran built-in 39 (MARK_LAST_PHASE) and then END_PHASE, which is why the mission ended instead of advancing.

Two of the three objective squadrons were still alive (ADN110 and ADN112 at state 2), so this says nothing about whether destroying all three clears phase 1 — that prediction is still untested. What it does establish is that the else branch is the only way to reach phase 2, and it requires [phase+300] != 2 at the moment the phase ends.

Still not observed: a phase ADVANCE. Five attempts. The obstacle is no longer the freeze or the instrument — it is keeping the escort alive long enough to win.

🔴 2026-08-25 — the "win the mission" route is not converging

Two more attempts, and the honest summary is that flying to a phase clear is the expensive way to test the prediction.

The pilot's gun-fire rate is 1.6 % — 81 fire frames in 4986 samples — but that is not the blocker it looks like. The nose gun is Power 15 unguided; the main mount is Power 200 guided, and the pilot fired ~70 missiles in ~500 s. The damage is coming from missiles, and fire= in the log only tracks the gun. Worth writing down because the log invites the wrong conclusion.

SYLPH_KILL_TURRETS=1 made things worse, not better. The idea was to align DEFEND with the objective by letting it kill turrets attacking the escort. Measured: 3387 of 11112 samples (30 %) chased a target more than 20 000 units away — turrets are static and spread across the map, so the pilot commits to distant ones and stops defending anything. The escort still fell to 48.5 %, and no additional objective squadron died. Refuted as an improvement.

Both runs ended the same way as before: ADN111 destroyed (again — it is evidently the one closest to the action), ADN110 and ADN112 untouched at state 2, no phase advance. Six attempts now.

🟡 The bounded scan delays freezes but does not remove them

bounded-scan run outcome
1 clean to 694 s, ended by the mission's own lose branch
2 froze at ~682 s

Against 3-of-3 frozen inside ~4 minutes with the unbounded sweep, that is still a large improvement — but "the sweeps were the cause" is too strong. They were a cost; something else also freezes runs at ~11 minutes.

The cheaper experiment to run instead

Stop trying to win. The prediction is that finished goes to 1 with [phase+300] != 2 when ADN110/111/112 all reach state 4. Guest memory is writable (tools/re-capture/gpoke.py), so set the two surviving squadrons' +16 to 4 directly and watch whether the phase ends and the ordinal steps to 2. That tests the condition in seconds rather than fighting a mission the autopilot is not good enough to win, and a wrong answer is as informative as a right one — if nothing happens, the condition is not what the bytecode reading says.

🔴 2026-08-25 — poking all three squadrons to "destroyed" does NOT end the phase

The direct test, run instead of a seventh attempt at winning. All three objective squadrons were live (state 2) when the poke went in.

ADN110 rec=0xBCA48BC0  +4=0x0000001A  +16=2
ADN111 rec=0xBCA48C60  +4=0x0000001B  +16=2
ADN112 rec=0xBCA48D00  +4=0x0000001C  +16=2
STICK TEST on ADN110 +16: was=2 wrote=4 after2s=4 -> STICKS
poked all 3
  [+ 5s .. +60s]  phase=1 finished=0  states={ADN110:4, ADN111:4, ADN112:4}

The write sticks — and nothing happens. Sixty seconds with all three reading state 4 (the value a naturally-destroyed squadron takes, measured earlier on ADN111), and [ScriptPhase+196] stayed 0 and the ordinal stayed 1.

So "phase 1 clears when ADN110/111/112 are destroyed" is not confirmed, and the simplest form of it is refuted. The bytecode reading — three unit_state polls then set_flag(8) — is solid; what does not follow is that flipping this field is equivalent to the kill.

🟡 Why it probably did nothing: the poll was not running

That the poke persisted for 60 s is itself the clue. Built-in 69 is documented as normalising +16 when it polls, so if the condition coroutine were running its unit_state polls, it should have overwritten the value within a frame. It did not — which points at the condition being evaluated only when a trigger fires, not on every frame. Poking state without firing the trigger changes a value nobody reads.

🔴 The per-unit record layout is not what the built-in summary says

Dumping ADN110's record contradicts "+4 live object (NULL = absent)":

+0  = 2          +12 = 0x42480000 (50.0f)     +20 = 9
+4  = 26         +16 = 4  (state)             +128 = 0x3F733333 (0.95f)

+4 is 26/27/28 for the three squadrons — small consecutive integers, not pointers (an undeployed squadron, ADN201, has +4 = 0 and +16 = 0). And +20 = 9 is exactly these squadrons' member count n, which the roster gives independently — so the record is per-squadron and carries its strength.

Earlier readings printed obj=yes because the probe tested that word for non-zero, not for pointer-ness. That is a reporting bug in my own tool, and it made a small index look like a live object.

Not settled: what +4 indexes (a route or symtab-1 index is the obvious guess, given the values), and how to make the condition actually re-evaluate. Firing the trigger — built-in 100 pushes onto [phase+272] — is the next thing to look at.

🔴 The corrected poke (rec+4 = 0) also does nothing — and I have no positive control

Built-in 69 reads rec+4, not rec+16 (see isl-builtins), so the corrected simulation of "this squadron is gone" is rec+4 = 0, which takes the handler's documented early exit. Ran it with all three squadrons active:

STICK TEST on ADN110 +4: was=26 wrote=0 after2s=0 -> STICKS
poked all 3
  [+5s .. +60s]  phase=1 finished=0  states={ADN110:2, ADN111:2, ADN112:2}

No phase end, and +16 never changed either — it stayed 2 for a full minute while the handle it is supposedly derived from read zero.

🟡 The leading explanation: the condition coroutine is not running

Both pokes persist untouched, and nothing recomputes +16. If the phase-1 condition were polling unit_state on these squadrons each frame, one of these writes should have provoked something. The consistent reading is that the polls at 0xF524 live in a coroutine that only runs when a trigger starts it (built-in 1 start_coroutine, fed from the queue at [phase+272]), so changing unit state without firing the trigger changes data nobody is reading.

🔴 The gap in this method: no positive control

Two pokes have now produced no observable effect, and I cannot distinguish "the game ignored the write" from "the write never reached the game". The stick test only proves the value persisted in the shared-memory file — it does not prove Canary's guest sees it.

That is a real hole, and it should have been closed before drawing conclusions from a null result. The control to run first: poke something with a visible effect — the player's hull, or a HUD counter — and confirm the change appears on screen. Until that passes, every "poking X did nothing" here is unfalsifiable rather than informative, and the two null results above must be read as inconclusive, not as evidence about the condition.

What still stands from these runs is only what was observed, not poked: the arrival transitions, the destruction of ADN111, and the mission-over branch.

🟡 The positive control ran — and is still inconclusive

tools/re-capture/poke_control.sh (self-retrying; succeeded on attempt 1, no freeze) poked the player's hull at position + 0x154 to 1, on the theory that the game visibly reacts to a dead player.

hull before: 0x447A0000        (= 1000.0f)
poke        0x447A0000 -> 0x00000001   OK
hull after : 0x447A0000        (12 s later -- the game put it back)
screen before: flight     screen after: flight

What it establishes: the hull word is continuously rewritten by the game, so a poke there cannot persist — unlike the unit-record fields, which held our value for 60 s untouched. That asymmetry is itself informative: it separates fields the game actively maintains from fields nobody is writing.

Why it is still not a control. I looked for a visible reaction and found a red WARNING banner in the after-frame — but the before-frame already shows MISSILE ALERT, i.e. the ship was under attack in both. The banner is not attributable to the poke, and I am not going to count it. A value being overwritten proves the game writes that address; it does not prove the game read ours.

New fact, and a correction: hull at pos + 0x154 reads 0x447A0000 — a float, 1000.0 — not the 1500 the pilot logs. The pilot's hull= is a different field or scale, and the two should not be conflated.

The refinement that would settle it

Poke in a tight loop for several seconds so the value is low whenever the game samples it, rather than once between two of its own writes. If hull is authoritative, the ship dies and the screen goes to GAME OVER — unambiguous. If it survives a sustained low hull, the field is a readout and the authoritative copy is elsewhere. Either answer is worth having.

The self-retrying harness works and is the reusable part of this iteration: boot → verify animating → locate → act, with a freeze at any step costing one retry instead of a whole iteration.

THE CONTROL PASSES — pokes reach the guest, and hull is authoritative

Hammering the write instead of doing it once settles it:

hull before: 0x44BB8000        (= 1500.0f)
hammered hull=1 for 15 s -- 944,387 writes
hull after : 0x00000001        (the game STOPPED rewriting it)
screen: flight -> other

The after-frame (captures/poke-control-kill.png) shows the flight HUD gone, the ship trailing fire, and a radio line: "I've lost contact with Rhino 3!" — Rhino 3 being the player's own callsign. The game read the poked value and killed the player.

So, established:

  • Writes to /dev/shm/xenia_memory_* do reach the running guest. The plumbing works.
  • Hull at player position + 0x154 is authoritative, not a readout.
  • A single write loses a race — the game rewrites hull continuously, so one poke lands between two of its own writes. Hammering wins; 15 s was ample.

This upgrades two earlier "inconclusive" results to genuine negatives

The poke experiments on the unit records were downgraded to inconclusive because I could not tell "the game ignored it" from "the write never arrived". The write arrives. And those pokes persisted untouched for 60 s — nothing overwrote them — so the game genuinely saw state = 4 and handle = 0 on all three objective squadrons and did nothing.

That is now real evidence for the standing explanation: the phase-1 condition coroutine is not polling during ordinary flight, and the polls at 0xF524 run only when a trigger starts them.

🔴 Withdrawn: "the pilot's hull= is a different field"

Last iteration I read 0x447A0000 (1000.0f) at pos + 0x154 and concluded it could not be the 1500 the pilot logs. Wrong. This run reads 0x44BB8000 = 1500.0f at the same offset. It is the same field; the value simply differs between runs (craft or loadout). The "different field or scale" note is retracted.

The JIT keeps the guest context in %rsi — from Canary's own source

The watchpoint's ceiling was that the writer is JIT code with no host symbols. The way past it is in the emulator's source, not the disassembly:

src/xenia/cpu/backend/x64/x64_emitter.cc:881
    Xbyak::Reg64 X64Emitter::GetContextReg() const { return rsi; }
    Xbyak::Reg64 X64Emitter::GetMembaseReg()  const { return rdi; }

So at any JIT instruction, %rsi is the PPCContext* — which is also why the faulting instruction read 0x110(%rsi): it was loading a guest register. The whole guest register file is available at the moment of the write, and a guest code address (0x82xxxxxx) picked out of it resolves against sylpheed.db to name the calling function.

trigger_watch.sh now dumps x/128wx $rsi at the hit rather than a useless host backtrace. ⚠️ Reading the LR by offset would need PPCContext's layout; scanning the dump for 0x82…-range words avoids parsing a 900-line struct and is what the script does.

🔴 The re-run could not locate the mission — unexplained

The run reached flight (readyroom at 18s, IN FLIGHT at 40s), the pilot bound, the guest was animating, and yet find_mission returned NOTFOUND. Narrowing it:

  • the .ssb header is not in guest memory — 0 hits for its 20-byte signature, where previous runs hit it immediately;
  • ADN110 is not in guest memory either — so the script's symbol table is not resident;
  • but Stage02.ssb (the manifest string) is present, at 0xBDA6C50B.

So guest memory is readable and the manifest is loaded, while the script itself is not — in a mission that is demonstrably flying. That contradicts four earlier runs where the header was found within seconds of flight.

I do not have an explanation, and I am not going to invent one. Candidates worth separating next time: the script is loaded later than I assumed and the earlier runs sampled later; the probe raced a load; or this run entered flight by a different path. The cheap discriminator is to poll for the header from the moment flight starts and record when it appears, rather than sampling once.