docs/re: the cache-flush throw — a 100-second trigger, and two withdrawals
Chasing the title-screen crash into the emulator's own diagnostics turned it from a mystery into a controlled experiment, and knocked over two things this corpus said yesterday. Withdrawn #1: "the fault address 0x1_0000000C is a pointer with a stale high word". The crash dump prints r25 = 0x0000000C, clean. Xenia maps the guest's 4 GiB at host 0x1_00000000, so that IS guest address 12. The guest dereferenced the small integer 12. Withdrawn #2: "with --mem_watch=false the crash does not happen at all", which named the crash-oracle handoff's suspect #1 as measured. It was confounded — every --mem_watch=false run had also had a warm cache. Held cold, the throw happens with the probe off (2 437 crash dumps). mem_watch is eliminated for this crash. What it actually is: the access violation is the guest's own `throw` RETURNING, because this build logs guest C++ exceptions and continues rather than unwinding. So the event is the throw, and with --cache_throw_diag=true the guest names it: std::out_of_range, from the cache-manager flush, with a deque of 38 entries (37 distinct, one duplicated) against a 37-key map, every one of them absent from the flush's snapshot but present in the live map — the TOCTOU race the logger's own message describes. And the new, useful part: the trigger is the on-disc cache. Complete cache, no throw (2 runs). Directory moved aside or half-rebuilt, throw ~100 s into the boot (3 runs, including one that threw with NO access violation behind it — which is why crash dialogs are the wrong thing to count). A suspect in that bisection plan now costs a `mv` and two minutes instead of a mission.
This commit is contained in:
Sylpheed RE agent
@@ -178,9 +178,14 @@ carries the reproduction and the fix for two of them.
|
||||
### 2026-08-18 (fourth pass) — the crash is named, and the code avenue is scoped
|
||||
|
||||
The crash PC resolves to an MSVC `std::map`/`set` erase that throws
|
||||
`'invalid map/set<T> iterator'` — a 40-second reproduction of the Ready-Room
|
||||
crash, in [`title-crash-stl-tree.md`](title-crash-stl-tree.md). That is a
|
||||
by-product of this item, and it belongs to whoever picks up the crash bisection.
|
||||
`std::out_of_range` from the game's cache-manager flush, and the trigger is now
|
||||
controlled: an **incomplete on-disc cache** throws ~100 s into a boot, a complete
|
||||
one never does. The access violation people have been chasing is only that throw
|
||||
*returning*, because this build does not unwind guest EH. And the handoff's
|
||||
suspect #1 is **eliminated** — cold cache with `--mem_watch=false` throws just
|
||||
the same, which withdraws a claim made here yesterday. See
|
||||
[`title-crash-stl-tree.md`](title-crash-stl-tree.md). That is a by-product of
|
||||
this item and belongs to whoever picks up the crash bisection.
|
||||
|
||||
For the ordering itself, three more negatives, all recorded in
|
||||
[`ui-title-paint-order-capture.md`](ui-title-paint-order-capture.md): the two
|
||||
|
||||
@@ -27,7 +27,7 @@ Promote to a prose `structures/…md` file when a format needs behavioural notes
|
||||
| UI screen layout (`.rat`) | ✅/🟡 | [ui-rat-layout](structures/ui-rat-layout.md) | One pak per UI screen; each RATC = one (context × language) build; every `<name>.t32` sprite has a `<name>.rat` **layout record** (BE u32; 1280×720 design space; scale/tint/X/Y, keyframes for animated elements, `opt ` link to the focused state). **The tutorial PAUSE menu and the title main menu both rebuild pixel-accurately from the disc.** `loop1.rat` is decoded — it is a **looping sprite animation**, not a composition. ⚠️ **DEMOTED 2026-08-18** — the declaration table is *not* the paint order: a per-draw capture of the running title screen ([ui-title-paint-order-capture](ui-title-paint-order-capture.md)) paints element 13 first and elements 0/1 late, and the visible screen composites two bundles. The rest of the table's reading stands. Previously claimed: the **screen's draw list is the RATC bundle's own declaration table** (elements in back-to-front order, including the `eff*`/`deli*`/`msg` sprites that have no `.rat`, and excluding focused button variants reached via `opt `); its entry also carries a **parent element index** at `+32`. **A screen is fully reconstructible from its bundle**: the placement region right after the declaration table gives every element a keyframe group (header = element index + keyframe count, then 40-byte blocks of scale/tint/X/Y), including the `.rat`-less sprites — verified 11/11 on the tutorial pause bundle, with `pgp_ttrl_btn10`'s inline (546,288) matching its own record exactly |
|
||||
| UI screen paint order | ✅/🟡 | [title paint order](ui-title-paint-order-capture.md) | **Measured from the guest's draw stream** (new Canary hook `log_ui_draws`, F10): the title screen paints 11 draws a frame through one sprite shader, and the submission order is background → `back2` glow → `ptlogo1`+`tm` → `ptlogo2` → `ptcopyright` → the `PRESS Ⓐ BUTTON` plate. That refutes declaration order, reverse order, keyframe-start order and resting-time order, and shows the screen composites **two bundles** (build 7 + the one-element build 2). 🟡 the rule that produces the order is still unknown |
|
||||
| Scripted input / profile traps | ✅/🔴 | [canary-scripted-input-traps](canary-scripted-input-traps.md) | Three reasons a scripted run "cannot press Ⓐ": **F10 opens the emulator menu bar**, which makes `IsUIActive()` true and zeroes every guest keystroke; the file-pad is not the problem (it delivers, and Ⓐ skips movies); and the title needs a **signed-in profile**, which the container cannot type into ImGui — hence Canary's new `--create_profile_if_none`. 🔴 Past that, Ⓐ crashes the guest with `--mem_watch=true` and stalls it with `--mem_watch=false` — a cheap second reproduction of the Ready-Room crash, 40 s from a cold boot |
|
||||
| Title-screen guest crash | ✅/🟡 | [title-crash-stl-tree](title-crash-stl-tree.md) | `0x82307128` is inside an MSVC `std::map`/`set` **erase** — the function builds and throws `'invalid map/set<T> iterator'`, and its node offsets (`_Left` 0, `_Right` 8, `_Isnil` 25) are the MSVC red-black node. It crashes on the first dereference after that check, at `0x1_0000000C` (a 32-bit value with bit 32 set). Two runs, ~40 s from a cold boot with `--mem_watch=true`; **none** with `--mem_watch=false` — so probably the Ready-Room crash, reproducible in seconds instead of a mission |
|
||||
| Title-screen guest crash | ✅ | [title-crash-stl-tree](title-crash-stl-tree.md) | The guest throws **`std::out_of_range`** from its cache-manager flush (`sub_823070B0`, an STL map/set erase that builds `'invalid map/set<T> iterator'`); the access violation after it is only the throw **returning**, because this build does not unwind guest EH. Trigger found and controlled: an **incomplete on-disc cache** (`~/.local/share/Xenia/cache/aab216c3`) throws ~100 s into a boot, a complete one never does — 2 runs each way. ❌ `mem_watch`, the handoff's suspect #1, is **eliminated**: cold cache + `--mem_watch=false` throws anyway |
|
||||
| Save file (`savedata`) | ✅/❔ | [savegame-format](structures/savegame-format.md) + [`tools/re-capture/savegame.py`](../../tools/re-capture/savegame.py) | `GDHA` container, zlib payload, chunk stream (`GDAA` / phase name / `GHAD` 122 B progress block / 16×20 B slot table / trailer). **Container and layout read off the title's own serializer `0x822C00E8` and verified by a byte-identical round-trip**; the whole save is 545 B. Payload offsets are also the live save object's offsets (`save+8` GHAD, `save+136` slots). A second save made in-game names **Points** (+24), **flight time in ms** (+4) and **clear ratio %** (+8) off the game's own Details panel; the payload is a **pure function of game state** (same state saved twice = byte-identical, only the header FILETIME and its uninitialised pointer padding move), and the 16 `SHAB` records are **not** the UI's 20 save slots. Difficulty vs stage is undecided — three fields hold 2. **A third save, taken after developing exactly one Arsenal weapon** (Light Machine Gun MG I, 4000 P), moves exactly three things: `+24` Points 4101→101 (which **separates it from `+28`**, that did not move), `+8` clear ratio 5→6 (so the ratio counts *collection*, not only stages), and two entries of the 54-byte blob — `2→4` for the item bought and `0→2` for the successor the game announced as newly developable, giving the blob its alphabet ✅ *0 locked / 2 developable / 4 developed* (only the `4`s are stored — `2` is re-derived at load). **Saves can also be written back**: three derived header fields (length at `+0x30`, payload length at `+0x8c`, `adler32` at `+0x8e`) are all that stand between a parse and a hand-written save that the title loads, and [`savegame_edit.py`](../../tools/re-capture/savegame_edit.py) re-wraps a real save byte-identically. That turned the blob's index space from blocked-on-story-progress into four probe saves — see the [economy note](arsenal-develop-economy.md) |
|
||||
|
||||
## Runtime / dynamic-capture technique
|
||||
|
||||
@@ -89,20 +89,19 @@ below. Two later attempts to reproduce it (open the panel, close it, press Ⓐ)
|
||||
produced neither a crash nor a transition. So it is one data point that Ⓐ *can*
|
||||
reach code the title does not otherwise run, and nothing more.
|
||||
|
||||
**The reproducible crash is the boot-time content path.** With the default
|
||||
`--mem_watch=true`, in two independent runs, the guest dies with an access
|
||||
violation reading `0x00000001_0000000C` at PC `0x82307128` on guest thread 9,
|
||||
right after `HostPathDevice::ResolvePath(\aab216c3\5\c10eae6)` and a
|
||||
`RtlRaiseException(E06D7363)` (a C++ throw). Xenia pauses itself and stacks up
|
||||
crash dialogs — 991 in one run. With `--mem_watch=false` that crash does not
|
||||
happen at all.
|
||||
**The reproducible crash is the cache flush, and it is not what it looked like.**
|
||||
With the default `--mem_watch=true`, in two runs, the guest died with an access
|
||||
violation at PC `0x82307128` right after `RtlRaiseException(E06D7363)`. Chasing
|
||||
that produced a correction and a cheap trigger, both in
|
||||
[`title-crash-stl-tree.md`](title-crash-stl-tree.md):
|
||||
|
||||
That pairing — crash with the memory-probe thread on, none with it off, both in a
|
||||
save/content path — matches the suspect ranked #1 in
|
||||
`xenia-canary/HANDOFF-crash-oracle-2026-07-16.md`, whose crash was also a guest
|
||||
C++ exception in a cache/save path. This is a second, far cheaper reproduction of
|
||||
it: at the **title screen**, ~40 s from a cold boot, instead of in the Ready Room
|
||||
after a mission.
|
||||
* the access violation is a **consequence** of the guest's own `throw` returning
|
||||
(this build does not unwind guest EH), so the event to study is the throw;
|
||||
* the throw is `std::out_of_range` from the game's **cache-manager flush**, and
|
||||
an **incomplete on-disc cache** triggers it ~100 s into a boot;
|
||||
* the observation that started this — "crash with `--mem_watch=true`, none with
|
||||
`--mem_watch=false`" — was **confounded** by cache warmth, and is withdrawn:
|
||||
cold cache with the probe off throws just the same.
|
||||
|
||||
**The first of those next steps is done**, and it moves the crash out of this
|
||||
entry into its own: `0x82307128` is inside an MSVC `std::map`/`set` **erase** —
|
||||
|
||||
33
docs/re/captures/cache-flush-throw-cold-cache.log
Normal file
33
docs/re/captures/cache-flush-throw-cold-cache.log
Normal file
@@ -0,0 +1,33 @@
|
||||
!> F800002C GUEST-THROW type=.?AVout_of_range@std@@ object=702DF950 lr=82612B50
|
||||
!> F800002C CACHE-DUMP deque_count=38 list_count=37 blockmap=BC79C900 map_size=24 start=0
|
||||
!> F800002C CACHE-RAW mgr+0x28 @828F4860: +0=00000000 +4=00000001 +8=00000000 +C=BC365140 +10=00000025 +14=00000000 +18=BC3651E0 +1C=00000000 +20=00000000 +24=BC79C900 +28=00000018 +2C=00000000 +30=00000026 +34=00000006 +38=00000000 +3C=F800002C
|
||||
!> F800002C CACHE-DUMP deque hashpairs: [0]D4EA4615:E46EE8CA [1]69D8E45C:E534FFEA [2]69D8E45C:9355F2F8 [3]AAB216C3:A2C8C185 [4]69D8E45C:939A9DCC [5]69D8E45C:973A5C0A [6]AAB216C3:5EE70E0A [7]69D8E45C:C295EAD8 [8]87719002:CDBA806E [9]87719002:CEC0A96E [10]87719002:A60FCB85 [11]87719002:285D8849 [12]87719002:A715F485 [13]87719002:CF2A8CCD [14]87719002:01A2DB9C [15]69D8E45C:D14BA3F8 [16]69D8E45C:56324AF0 [17]69D8E45C:AC9606F9 [18]69D8E45C:4EFAECD1 [19]69D8E45C:459FBFE8 [20]AAB216C3:5C10EAE6 [21]AAB216C3:AC7E701E [22]69D8E45C:105663C8 [23]D5FAA9DB:EB80B1A0 [24]D5FAA9DB:C9F11F8B [25]AAB216C3:B01F9A49 [26]69D8E45C:94A80EB4 [27]69D8E45C:28A7DD79 [28]69D8E45C:022C136C [29]69D8E45C:962BE231 [30]9C70C593:147A1A88 [31]9C70C593:A879E94D [32]69D8E45C:98DA564C [33]69D8E45C:2CDA2511 [34]69D8E45C:14E88533 [35]D9EF910D:473C5BA2 [36]AAB216C3:DA75435B [37]AAB216C3:A2C8C185
|
||||
!> F800002C CACHE-DUMP map_keys=37 deque_orphans=0 (deque keys NOT in map):
|
||||
!> F800002C CACHE-RAW snapshot@r31+104 @702DFA30: +0=FFFFFFFF +4=828F39D0 +8=FFFFFFFF +C=BC3660C0 +10=00000000 +14=702DFB20 +18=00000000 +1C=00000000 +20=00000000 +24=BC220000 +28=BC3660C0 +2C=820B57AC +30=702DFAD0 +34=820B57A4 +38=00000000 +3C=00000000
|
||||
K> F800009C XThread::Execute thid 18 (handle=F800009C, 'XThread1FFFF6C0 (F800009C)', native=1FFFF6C0)
|
||||
i> F800009C XThreadF80000A4 (13) Stack: 706A0000-706D0000
|
||||
K> F80000A4 XThread::Execute thid 19 (handle=F80000A4, 'XThread1EFFE6C0 (F80000A4)', native=1EFFE6C0)
|
||||
i> F800009C XThreadF80000A8 (14) Stack: 706F0000-70720000
|
||||
K> F80000A8 XThread::Execute thid 20 (handle=F80000A8, 'XThread1DFFD6C0 (F80000A8)', native=1DFFD6C0)
|
||||
F> F8000094 HostPathDevice::ResolvePath(\87719002\c\dba806e)
|
||||
F> F8000094 HostPathDevice::ResolvePath(\87719002\c)
|
||||
F> F8000094 HostPathDevice::ResolvePath(\87719002\c\ec0a96e)
|
||||
F> F8000094 HostPathDevice::ResolvePath(\87719002\c)
|
||||
F> F8000094 HostPathDevice::ResolvePath(\87719002\a\60fcb85)
|
||||
F> F8000094 HostPathDevice::ResolvePath(\87719002\a)
|
||||
F> F8000094 HostPathDevice::ResolvePath(\87719002\2\85d8849)
|
||||
F> F8000094 HostPathDevice::ResolvePath(\87719002\2)
|
||||
F> F800009C DiscImageDevice::ResolvePath(\hidden\Resource3D)
|
||||
F> F8000094 HostPathDevice::ResolvePath(\87719002\a\715f485)
|
||||
F> F8000094 HostPathDevice::ResolvePath(\87719002\a)
|
||||
F> F8000094 HostPathDevice::ResolvePath(\87719002\c\f2a8ccd)
|
||||
F> F8000094 HostPathDevice::ResolvePath(\87719002\c)
|
||||
F> F8000094 HostPathDevice::ResolvePath(\87719002\0\1a2db9c)
|
||||
F> F8000094 HostPathDevice::ResolvePath(\87719002\0)
|
||||
!> F800002C CACHE-DUMP flush_sp=702DF9D0 snapshot_keys=1 deque_NOT_in_snapshot=38 (these are what map::at throws on; in_live_map=1 => added during the flush's UNLOCKED window = the TOCTOU race): [0]D4EA4615:E46EE8CA(in_live_map=1) [1]69D8E45C:E534FFEA(in_live_map=1) [2]69D8E45C:9355F2F8(in_live_map=1) [3]AAB216C3:A2C8C185(in_live_map=1) [4]69D8E45C:939A9DCC(in_live_map=1) [5]69D8E45C:973A5C0A(in_live_map=1) [6]AAB216C3:5EE70E0A(in_live_map=1) [7]69D8E45C:C295EAD8(in_live_map=1) [8]87719002:CDBA806E(in_live_map=1) [9]87719002:CEC0A96E(in_live_map=1) [10]87719002:A60FCB85(in_live_map=1) [11]87719002:285D8849(in_live_map=1) [12]87719002:A715F485(in_live_map=1) [13]87719002:CF2A8CCD(in_live_map=1) [14]87719002:01A2DB9C(in_live_map=1) [15]69D8E45C:D14BA3F8(in_live_map=1) [16]69D8E45C:56324AF0(in_live_map=1) [17]69D8E45C:AC9606F9(in_live_map=1) [18]69D8E45C:4EFAECD1(in_live_map=1) [19]69D8E45C:459FBFE8(in_live_map=1) [20]AAB216C3:5C10EAE6(in_live_map=1) [21]AAB216C3:AC7E701E(in_live_map=1) [22]69D8E45C:105663C8(in_live_map=1) [23]D5FAA9DB:EB80B1A0(in_live_map=1) [24]D5FAA9DB:C9F11F8B(in_live_map=1) [25]AAB216C3:B01F9A49(in_live_map=1) [26]69D8E45C:94A80EB4(in_live_map=1) [27]69D8E45C:28A7DD79(in_live_map=1) [28]69D8E45C:022C136C(in_live_map=1) [29]69D8E45C:962BE231(in_live_map=1) [30]9C70C593:147A1A88(in_live_map=1) [31]9C70C593:A879E94D(in_live_map=1) [32]69D8E45C:98DA564C(in_live_map=1) [33]69D8E45C:2CDA2511(in_live_map=1) [34]69D8E45C:14E88533(in_live_map=1) [35]D9EF910D:473C5BA2(in_live_map=1) [36]AAB216C3:DA75435B(in_live_map=1) [37]AAB216C3:A2C8C185(in_live_map=1)
|
||||
!> F800002C GUEST-THROW regs: r3=702DF7F0 r4=702DF8C0 r5=0000000C r6=702DF810 r7=821173E0 r8=BFC92284 r9=BFC92328 r10=82612AE0 r11=00000003 r12=825F2444 r13=30031000 r14=00000000 r15=00000000 r16=00000000 r17=00000000 r18=FFFFFFFF r19=00000001 r20=820B57AC r21=820B57A4 r22=00000000 r23=702DFA24 r24=828F4868 r25=828F4838 r26=702DFA38 r27=828F39D0 r28=00000000 r29=828F4880 r30=702DF950 r31=821173E0
|
||||
!> F800002C GUEST-THROW guest stack: 825F2444 8230711C 8245A1BC 8245A86C 824AFFC4
|
||||
!> F800002C EH-INDEX built: 228 catch-bearing FuncInfos
|
||||
!> F800002C EH-WALK depth=0 SP_F=702DF850 pc=825F2444 fn=825F2444
|
||||
!> F800002C EH-WALK depth=1 SP_F=702DF8E0 pc=8230711C fn=8230711C
|
||||
!> F800002C EH-WALK depth=2 SP_F=702DF9D0 pc=8245A1BC fn=8245A1BC
|
||||
@@ -1,20 +1,34 @@
|
||||
# The title-screen crash is an STL `map`/`set` erase on a bad iterator
|
||||
|
||||
**Status:** ✅ `CONFIRMED` for the identification (the guest function is
|
||||
`std::_Tree::erase`-shaped, and it says so in its own diagnostic string).
|
||||
🟡 `PROBABLE` that this is the same defect as the Ready-Room crash the Canary
|
||||
handoff blames on the `mem_watch` probe. ❔ whether the bad pointer originates in
|
||||
the guest or in the emulator's 64-bit register handling.
|
||||
**Status:** ✅ `CONFIRMED` — the guest throws `std::out_of_range` from an STL
|
||||
`map`/`set` erase during its cache flush, and an **incomplete on-disc cache**
|
||||
triggers it about 100 s into a boot (4 runs, 2 each way). 🟡 `PROBABLE` that this
|
||||
is the same defect as the Ready-Room crash — same exception type, same
|
||||
subsystem, same TOCTOU shape — but ❌ **the `mem_watch` probe that handoff ranks
|
||||
as suspect #1 is eliminated here**: with the cache cold, the throw happens with
|
||||
the probe off. ⚠️
|
||||
**two readings in the first version of this note are withdrawn** (see the
|
||||
correction below): the fault address is not a corrupt pointer, and the access
|
||||
violation is not the bug.
|
||||
|
||||
Found while trying to get past the title screen for a second UI screen's paint
|
||||
order ([`canary-scripted-input-traps.md`](canary-scripted-input-traps.md)). It is
|
||||
worth a page of its own because it is a **40-second reproduction** of a crash the
|
||||
project has so far only seen after a whole mission.
|
||||
worth a page of its own because it turns a crash that cost a whole mission to
|
||||
reproduce into one that costs a `mv` and 100 seconds.
|
||||
|
||||
## The reproduction
|
||||
|
||||
Boot Canary on the disc with the default `--mem_watch=true` and a profile on
|
||||
disc. Roughly 40 s in — while the title screen is up — the guest dies:
|
||||
Move the game's cache directory aside and boot with `--cache_throw_diag=true`:
|
||||
|
||||
```bash
|
||||
mv ~/.local/share/Xenia/cache/aab216c3 /tmp/ # reversible; the game rebuilds it
|
||||
run-canary --mem_watch=true --cache_throw_diag=true \
|
||||
--logged_profile_slot_0_xuid=B13EBABEBABEBABE
|
||||
grep GUEST-THROW <log> # ~100 s in
|
||||
```
|
||||
|
||||
With the cache complete, the same boot produces no throw at all. The original
|
||||
symptom — what this note was opened for — looks like this:
|
||||
|
||||
```
|
||||
Access Violation: read at 0x000000010000000C
|
||||
@@ -24,8 +38,7 @@ PC: 0x82307128 guest thread 9
|
||||
"Guest attempted to throw a C++ exception!"
|
||||
```
|
||||
|
||||
Two runs, same PC, same fault address. With `--mem_watch=false` it does not
|
||||
happen at all. Xenia pauses itself and stacks crash dialogs — 991 in one run.
|
||||
Xenia pauses itself and stacks crash dialogs — 991 in one run, 2 437 in another.
|
||||
|
||||
## What the code is
|
||||
|
||||
@@ -49,30 +62,110 @@ red-black tree node, so this is a `std::map`/`std::set` **erase** (it validates
|
||||
the iterator, then walks the node). The crash is the very first dereference
|
||||
after the validation.
|
||||
|
||||
## What the fault address says
|
||||
## Correction: the fault address is not a corrupt pointer, and the AV is not the bug
|
||||
|
||||
The effective address is `r25 + 0`, so `r25 = 0x00000001_0000000C`. That is a
|
||||
32-bit value `0x0000000C` **with bit 32 set** — a pointer whose high word is
|
||||
garbage, not a wild 32-bit pointer. Two readings, and this note does not choose
|
||||
between them:
|
||||
The first version of this note read `0x00000001_0000000C` as "a 32-bit pointer
|
||||
with a stale high word" and offered an emulator register bug as one of two
|
||||
readings. **Both readings were wrong, and the crash dump itself says so** — it
|
||||
prints the registers, and
|
||||
|
||||
* the tree really is corrupt and the guest is erasing through a freed/racing
|
||||
node — which is what the
|
||||
[`crash-oracle handoff`](../../xenia-canary/HANDOFF-crash-oracle-2026-07-16.md)
|
||||
concluded for the Ready-Room crash (a concurrent cache-add landing inside an
|
||||
unlocked flush iteration), and it names the `mem_watch` polling thread as
|
||||
suspect #1 for perturbing that timing. The `--mem_watch=false` result here is
|
||||
consistent with that;
|
||||
* or a high-word extension bug on the emulator side leaves a stale 1 in the
|
||||
upper half of a 64-bit register. Canary is the *reference* emulator, so this is
|
||||
the less likely of the two, but `0x1_0000000C` is exactly the shape such a bug
|
||||
produces and nothing here rules it out.
|
||||
```
|
||||
r25 = 000000000000000C
|
||||
```
|
||||
|
||||
**What would separate them:** dump the tree's root and a few nodes from guest
|
||||
memory (`tools/re-capture/gmem.py`) at the moment of the throw, and check whether
|
||||
the parent node's `_Left` field on the guest heap really contains `0x0000000C` —
|
||||
if the guest memory holds a clean 32-bit value and only the register is wrong,
|
||||
it is the emulator.
|
||||
is clean. Xenia maps the 4 GiB guest address space at host `0x1_00000000`, so
|
||||
"read at `0x1_0000000C`" is the *host* address of guest address `0x0000000C`.
|
||||
The guest simply dereferenced the small integer **12**.
|
||||
|
||||
**And the access violation is a consequence of the throw, not an independent
|
||||
fault.** `sub_823070B0` validates the iterator, and on failure builds the string
|
||||
and calls the throw at `0x82307118`; a throw does not return — except here.
|
||||
`RtlRaiseException_entry` in this build handles `0xE06D7363` by logging
|
||||
"Guest attempted to throw a C++ exception!" and **returning** (guest EH is only
|
||||
dispatched under `--eh_dispatch`, which its own cvar help records as disproven
|
||||
for this crash). So execution falls out of the throw into the code that assumed
|
||||
it would never run:
|
||||
|
||||
```
|
||||
82307118 bl 0x825F23D8 ; throw std::out_of_range("invalid map/set<T> iterator")
|
||||
8230711C addi r3, r31, 276 ; <- execution RESUMES here, in this build
|
||||
82307120 or r25, r5, r5 ; r5 has been clobbered by the throw call: 0x0C
|
||||
82307124 bl 0x8244E2A8
|
||||
82307128 lwz r11, 0(r25) ; <- AV, on 12
|
||||
```
|
||||
|
||||
That means the 1 895 stacked crash dialogs are noise from one guest throw, and
|
||||
**the event to study is the throw**.
|
||||
|
||||
## The throw, with the guest's own diagnosis
|
||||
|
||||
Run with `--cache_throw_diag=true` (a cvar this fork already carries) and the
|
||||
guest says everything — the full record is committed as
|
||||
[`captures/cache-flush-throw-cold-cache.log`](captures/cache-flush-throw-cold-cache.log):
|
||||
|
||||
```
|
||||
GUEST-THROW type=.?AVout_of_range@std@@ object=702DF950 lr=82612B50
|
||||
GUEST-THROW guest stack: 825F2444 8230711C 8245A1BC 8245A86C 824AFFC4
|
||||
CACHE-DUMP deque_count=38 list_count=37 map_size=24
|
||||
CACHE-DUMP deque hashpairs: [0]D4EA4615:E46EE8CA [1]69D8E45C:E534FFEA … [37]AAB216C3:A2C8C185
|
||||
CACHE-DUMP flush_sp=702DF9D0 snapshot_keys=1 deque_NOT_in_snapshot=38
|
||||
(these are what map::at throws on; in_live_map=1 => added during the flush's
|
||||
UNLOCKED window = the TOCTOU race)
|
||||
```
|
||||
|
||||
* The thrown type is **`std::out_of_range`** — the same type the Ready-Room crash
|
||||
handoff names, from the same subsystem.
|
||||
* The stack is `throw ← sub_823070B0 ← sub_8245A098+0x124 ← sub_8245A5E0+0x28C ←
|
||||
sub_824AFF88+0x3C`.
|
||||
* The keys are `<container hash>:<entry hash>` pairs, and they are the on-disc
|
||||
cache files: `AAB216C3:5C10EAE6` is `\aab216c3\5\c10eae6`, the very path the
|
||||
log resolves one line before the crash.
|
||||
* **The deque holds a duplicate**: 38 entries, 37 distinct, with
|
||||
`AAB216C3:A2C8C185` twice, against a map of 37 keys.
|
||||
|
||||
The mechanism itself was already worked out by whoever wrote this logger — the
|
||||
flush snapshots the map, then walks a deque every entry of which is missing from
|
||||
the snapshot but present in the live map, i.e. added inside the flush's unlocked
|
||||
window. This note adds no new theory there.
|
||||
|
||||
## What is new: a 100-second, on-demand trigger
|
||||
|
||||
The throw is not random. It follows the state of the game's **on-disc cache**
|
||||
(`~/.local/share/Xenia/cache/<container>/…`, the `\aab216c3\…` device):
|
||||
|
||||
| run | cache state | `GUEST-THROW` | crash dumps |
|
||||
|---|---|---|---|
|
||||
| A | complete (6 files) | **0** | 0 |
|
||||
| B | directory moved aside — cold | **1** | 1 895 |
|
||||
| C | partially rebuilt (1 file + a `.tmp`) | **1** | 0 |
|
||||
| D | the original 6-file cache restored | **0** | 0 |
|
||||
| E | cold **and** `--mem_watch=false` | **1** | 2 437 |
|
||||
|
||||
All four reached the same boot stage (each resolves the same `87719002` /
|
||||
`aab216c3` cache entries; the warm runs went *further*, so this is not "warm runs
|
||||
stopped early"). Runs B and C throw at the same point in the boot, around 100 s
|
||||
in, long before anything a player would call gameplay.
|
||||
|
||||
Run E is the important one, and it **withdraws a claim this note made yesterday**.
|
||||
The earlier version said "with `--mem_watch=false` the crash does not happen at
|
||||
all", which named the handoff's suspect #1 as measured. That comparison was
|
||||
confounded: every `--mem_watch=false` run so far had also had a *warm* cache.
|
||||
Holding the cache cold and turning the probe off, the guest throws anyway — so
|
||||
**`mem_watch` is not the trigger for this crash**, and the variable that is, is
|
||||
the cache.
|
||||
|
||||
So a suspect in the handoff's bisection plan no longer costs "one build plus one
|
||||
Ready-Room run": move the cache directory aside and boot. Note run C — the throw
|
||||
happened with **no** access violation behind it, which is why counting crash
|
||||
dialogs is the wrong signal and `grep GUEST-THROW` is the right one.
|
||||
|
||||
**Stated as not settled:** n = 2 on the warm side, n = 3 on the incomplete side,
|
||||
one box, one build; and the elimination of `mem_watch` is for *this* throw, not
|
||||
necessarily for the Ready-Room one, which nothing here has re-run. And this says
|
||||
nothing about *why* the deque grows during the flush — whether that race is
|
||||
reachable on hardware or is an artifact of emulator timing (the handoff's
|
||||
position) is exactly the open question, and a cheap trigger is only a tool for
|
||||
answering it.
|
||||
|
||||
## The other crash PC, for completeness
|
||||
|
||||
|
||||
Reference in New Issue
Block a user