19 Commits

Author SHA1 Message Date
MechaCat02
7b6902e08f [WIP] Audio/threading fixes + crash investigation; NEW ORACLE: crash is ours not the game
Some checks failed
Orchestrator / Commit Message Validation (push) Has been skipped
Orchestrator / Lint (push) Failing after 1m34s
Orchestrator / Windows (x86-64) (push) Has been skipped
Orchestrator / Linux (x86-64) (push) Has been skipped
Orchestrator / Create Release (push) Has been skipped
Snapshot for handoff. Contains the mission-audio + threading fixes and the
crash-investigation instrumentation (all diagnostic cvars default-OFF).

Fixes (behavioral):
- threading_posix.cc: reap-once guard on PosixCondition<Thread>::post_execution
  (double pthread_join at mission teardown -> fault loop -> audio death + freeze).
- xma_decoder.cc: work_event_->Set() in Pause() so the idle XMA worker observes
  paused_ and signals pause_fence_ (Pause() deadlock -> permanent audio death).
- audio_system / xma_context_master / xboxkrnl_audio / apu_flags / alsa: mission
  audio keepalive + guest_audio_flags + watchdogs.

Instrumentation (additive, default-off): xboxkrnl_debug cache-throw diag +
guest-catch dispatcher, xex_module PE/PDATA/EH scans, kernel_state mem_watch
(NOTE: mem_watch DEFAULTS TRUE -- an always-on host poll thread; prime crash suspect).

NEW ORACLE (see HANDOFF-crash-oracle-2026-07-16.md): stock 6e5b8324f built with
our toolchain + zero custom code = NO crash, NO sound-stop, plays the Ready Room.
=> the Ready-Room out_of_range crash is introduced by THESE changes, not the game
and not the (LTO-broken) build chain. Bisection plan + suspect ranking in the note.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
2026-07-16 22:43:50 +02:00
MechaCat02
0aa3eadca7 [Kernel] Add null-safe XThread::TryGetCurrentThread() accessor
The additive event_log extraction tracer needs a current-thread lookup that
returns nullptr instead of asserting when called from boot code before any
XThread exists (GetCurrentThread asserts on non-guest threads). New read-only
static accessor over the thread-local; no behaviour change. Fixes the native
Linux build of the phase-a args/file.read tracer.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
2026-07-13 20:42:54 +02:00
MechaCat02
a40bc50159 [Phase A] Port args / file.read extraction tracing onto instrument-current
Bring the cvar-gated JSONL extraction tracer (event_log) forward from the
phase-a-tracing line so args/args_resolved + file.read events are
available alongside the GPU draw logging. Purely additive:

- src/xenia/kernel/event_log.{cc,h}: the tracer (auto-globbed into the
  kernel target). Tier 1 fills kernel.call args (raw r3..r10) +
  args_resolved.path under --phase_a_trace_args; Tier 2 resolves
  NtReadFile handle->path via the object table and emits file.read.
- cpu_flags: phase_a_event_log_path / _mem_writes / _trace_args /
  _hash_probe / kernel_emit_contention (all default-off).
- shim_utils.h: phase_a_bridge decl + EmitImportAndCallWithCtx/EmitReturn
  hooks in the active X::Trampoline, skipped when Enabled() is false.

Deliberately EXCLUDES the Tier-3 hash-probe HIR/emitter trap (the IPFB
name-hash was recovered statically, so the probe is moot). The
phase_a_hash_probe cvar is defined but inert.

Default-off => instrument-current behaviour byte-identical when unused.
Not yet compile-verified against instrument-current's toolchain.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
2026-07-13 19:13:36 +02:00
MechaCat02
f970a5173f [GPU] log_draws: also dump vertex positions for file correlation
Some checks failed
Orchestrator / Commit Message Validation (push) Has been skipped
Orchestrator / Lint (push) Failing after 1m57s
Orchestrator / Windows (x86-64) (push) Has been skipped
Orchestrator / Linux (x86-64) (push) Has been skipped
Orchestrator / Create Release (push) Has been skipped
Extend the RE draw-logger to dump the first few vertex POSITIONS (read
from guest memory) under each draw. The f32 position bytes are identical
between the guest buffer and the on-disc .xpr (only f16 pairs are
rearranged on load), so these values can be grep'd for in a resource file
to locate a mesh whose in-file offset is otherwise unknown.

Validated: world-space stage geometry byte-matches Stage_*.xpr at exact
offsets. (Load-time-transformed meshes like the player ship don't match,
which is itself a useful finding.)

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-07-12 19:09:08 +02:00
MechaCat02
25eb17b91d [GPU] Add log_draws: dump per-draw vertex declaration for RE
Reverse-engineering aid for decoding game mesh formats against GPU ground
truth. When the `log_draws` cvar is set, each distinct draw's primitive
type, index buffer (guest base / count / format / endianness), and full
per-stream vertex declaration (fetch-constant base + stride, and every
element's format + offset) is written to xenia_re_draws.log.

- command_processor.{h,cc}: CommandProcessor::LogDrawForRE(), no-op unless
  the cvar is set. De-dups by the vertex-declaration fingerprint (shader +
  primitive + element formats/offsets), so animated UI that redraws the
  same format into fresh buffers every frame collapses to one record --
  keeping it near-free (an earlier address-keyed de-dup flooded the log and
  stalled the GPU thread). Capped at 4096 distinct formats.
- pm4_command_processor_implement.h: call it from ExecutePacketType3Draw
  after IssueDraw (so the vertex shader has been analyzed). Backend-agnostic
  base path -- works for the Vulkan build.

Used to confirm Project Sylpheed's XBG7 mesh layout (triangle list, pos
f32x3 / normal f16x4 / uv f16x2, variable stride).

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-07-12 18:42:33 +02:00
MechaCat02
f10484834c [APU] Fix mission-audio silence: ALSA underrun keepalive + guest_audio_flags
Two Linux mission-audio fixes for Project Sylpheed (audio played in
intro/menu but died when a mission finished loading, never returning):

- alsa_audio_driver: when the guest stalls (mission "Preparing for Sortie"
  load) and the ring buffer empties, feed silence to keep the PCM alive
  instead of sleeping. Previously the small buffer drained, XRUN'd, and
  playback never recovered (matches the known "audio muted permanently").
- xconfig: make the guest speaker config a cvar (guest_audio_flags,
  default Digital Stereo) instead of hardcoded Dolby Digital surround.

(The practical fix on this box also needed log_mask=13 to stop kernel log
spam starving the audio pipeline during missions — config, not code.)

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-07-12 16:49:25 +02:00
MechaCat02
919e526fd8 [Fix] Screenshot: null-check presenter before use (fixes F12 crash)
TakeScreenshot() called GetGraphicsSystemPresenter()->CaptureGuestOutput()
and only tested the pointer for null AFTER dereferencing it, so taking a
screenshot with no live presenter dereferenced null and crashed. Check for
null first, and re-enable notifications on the capture-failure path too.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-07-12 15:44:11 +02:00
MechaCat02
2233fae235 [Build] Guard ThinLTO behind XENIA_ENABLE_LTO for memory-constrained hosts
Release enables -flto=thin unconditionally; the ThinLTO link spikes memory
past what a 15GB box can handle. Gate it behind an option (default ON, so
normal/CI builds are unchanged); pass -DXENIA_ENABLE_LTO=OFF to build
Release without the LTO memory spike.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-07-12 15:43:23 +02:00
MechaCat02
f81e90f03a audit: add poll-based arbitrary guest-VA memory-watch cvars
Adds audit_mem_watch_addr (comma-separated hex guest VAs) and
audit_mem_watch_size (1/2/4/8 bytes) to watch arbitrary guest memory
locations at runtime. Once per vblank, GraphicsSystem::MarkVblank()
reads each VA big-endian via Memory::TranslateVirtual and emits an
XELOGKERNEL "AUDIT-MEM-WATCH" line on every value change vs the prior
frame (same greppable log stream as AUDIT-HLC / AUDIT-MEM-READ).

Mechanism is poll / value-change: it captures WHEN a value changes
(vblank index) but NOT the writer guest-PC; pair with audit_jit_prolog_pc
on a suspected writer to recover the PC. Heap VAs vary per run/engine,
so they are supplied at runtime via cvar/CLI. Default empty => disabled
=> zero overhead and no emulation-behavior change.

Validated against the controller vsync "clock A" field (+0x58): the
watch fires once per change, advancing monotonically in lockstep with
vblanks. Game still boots and runs muted with the cvar unset.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-07-12 15:43:23 +02:00
MechaCat02
07f09f8fe0 [Audit] round 24: signal-path probes (XEvent::Set + IO + NtDuplicateObject)
Adds AUDIT-HLC probes for every path that signals an XEvent or duplicates
its handle, so the round-23 puzzle (waits completing without visible
NtSetEvent/KeSetEvent) can be cross-referenced by underlying X_KEVENT VA
and by primary handle.

  * NtCreateEvent_inner: always log kevent_va for handle/VA cross-ref
  * XEvent::Set: universal hook prints primary handle + kevent_va + LR;
    catches all paths into the event regardless of shim used
  * NtSetEvent: extended with PPC back-chain walk for caller's guest_lr
    (same idiom as the wait probe), so the signaler function is
    immediately identifiable
  * NtReadFile / NtReadFileScatter / NtWriteFile: log when signal_event
    path fires ev->Set() inline at IO completion (bypasses both
    NtSetEvent and KeSetEvent shims)
  * CompleteOverlappedEx (kernel_state.cc): log when overlapped event
    is signaled at completion
  * NtDuplicateObject: log src/dst handle pair (round-24 confirmed silph
    event is dup'd before signaling, explaining the handle-mismatch
    puzzle between NtSetEvent's `handle=` argument and XEvent::Set's
    primary handle())

Result: silph wait at sub_821CB030+0x1B0 on handle F80000A0 is signaled
via NtSetEvent on handle F80000A8 (the duplicate created by sub_8245D9D8
at lr=0x82450DF4 inside the worker chain sub_82450A28 ← 0xA68 ← 0xB68).
Verdict A confirmed: signaler exists and is reachable, but round-17.β
missed it because the search keyed on the wrong handle. No bypass path;
the worker chain is identical between canary and ours-impl, but ours
signals different handles (work-item queue divergence at sub_82452DC0).

Audit-only diagnostic. No semantic changes. Net delta +86 LOC across 7
files. All probes gated on the existing audit_handle_lifecycle cvar
(default off). Tested via Sylpheed boot (35 s, 4 MB log). Audit-handle-
lifecycle-probes branch, local-only.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
2026-07-12 15:43:23 +02:00
MechaCat02
4670afbeb5 [Audit] --audit-r3-dump-bytes: dump N bytes at r3 when probe fires
AUDIT-059 round 15 — diagnostic. New cvar `audit_jit_prolog_r3_bytes`
(default 64 = existing behaviour, capped at 256, rounded up to 16B
multiple) controls how many bytes are dumped at host(r3) when the
audit_jit_prolog_pc probe fires. Set to 80 to capture audit-051's
stack-local struct at sub_82452DC0's r31+96.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
2026-07-12 15:43:23 +02:00
MechaCat02
87e4a67b61 [Audit] JIT-prolog: optional audit_jit_prolog_mem_dump chain (3 levels)
Round-14 of AUDIT-2BF (singleton-dump). Pairs with xenia-rs'
--audit-mem-read-hex to emit one comparable XELOGKERNEL line resolving
the bctrl target at sub_822F1AA8+0x90 (PC 0x822F1B4C):

  [0x828E1F08]        -> singleton instance ptr
  [singleton+0]       -> vtable
  [vtable+0]          -> vtable[0]  (= first virtual method, bctrl tgt)
  [vtable+24]         -> vtable[24] (= slot 6, silph chain target)

Two complementary hooks:

1. src/xenia/cpu/backend/x64/x64_emitter.cc: extend
   AuditLogJitPrologArgs. New cvar `audit_jit_prolog_mem_dump` (uint32).
   When non-zero and an `audit_jit_prolog_pc` fire happens, the host
   side dereferences the VA 3 levels deep and emits one
   AUDIT-MEM-READ line in the same format ours emits. Defensive
   per-level null + VA-range checks.

2. src/xenia/kernel/kernel_state.cc: one-shot dump in
   EmulateCPInterruptDPC of the same chain (hard-coded to
   0x828E1F08). Useful when audit_jit_prolog_pc isn't set; fires the
   first time the CP interrupt path runs (after the singleton ctor
   has had time to populate).

Read-only. Both gates default-off; no impact when cvars unset.
~65 LOC total across the two files.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
2026-07-12 15:43:23 +02:00
MechaCat02
1517a63974 [Audit] round 12: ExCreateThread + XThread::Execute probes
Two cvar-gated AUDIT-HLC probes for thread-spawn lineage attribution:

1. ExCreateThread_entry shim logs (start_address, start_context, xapi,
   flags, kernel lr, guest_lr). guest_lr is recovered via the same
   one-frame-up PPC back-chain walk used by the NtWaitForSingleObjectEx
   probe (lr saved at [back2 - 8]).

2. XThread::Execute emits (tid, start_address, start_context, xapi) at
   the very top so each running thread can be matched back to its
   creating ExCreateThread entry by (start_address, start_context).

Gated on the existing cvars::audit_handle_lifecycle; no new cvar.
Pulled in xenia/kernel/kernel_flags.h from xthread.cc to expose the
cvar declaration there.

Used by audit-059 round 12 to enumerate the 23 thread spawns in
canary's 35 s boot, attribute each to its guest_lr caller, and cross-
reference against ours' 10 spawns to identify the 7 missing
spawner functions (including sub_824F7800 which spawns the 4 silph
PKEVENT workers at entry=0x82506528/58/88/B8 via guest_lr=0x824F7B24).

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
2026-07-12 15:43:23 +02:00
MechaCat02
81d3eb056b [Audit] round 9: generalize JIT-entry probe to PC-configurable cvar
Replace the round-7 hardcoded `current_guest_function_ == 0x824F7800`
gate with a runtime cvar `audit_jit_prolog_pc` (uint32, 0 = disabled).
The cvar names the guest entry PC at which the x64 emitter inserts a
CallNative to the prolog probe; the probe now dumps the active PC in
each log line so multiple instrumentation campaigns can share output.

Renames `audit_log_sub824F7800_args` (cvar) and `AuditLogSub824F7800Args`
(host function) — the round-7 sub_824F7800-specific cvar and function
are deleted, not left dormant. The `audit_handle_lifecycle` cvar and
its existing AUDIT-HLC probe sites in xboxkrnl_threading.cc /
kernel_state.cc are untouched.

Validated by audit-059 round 9: with `--audit_jit_prolog_pc=0x821B55D8`
the silph WorkerCtx-init chain entry fires 1× in canary at tid=6
lr=0x82172D8C (call site at sub_82172BA0+0x1E8 `bctrl`, the virtual
dispatch through vtable slot 6 that statically-blind xref-walkers
cannot enumerate).

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
2026-07-12 15:43:23 +02:00
MechaCat02
94115aba1c [Audit] round 7: JIT-entry probe for sub_824F7800 args
Adds cvar audit_log_sub824F7800_args (off by default). When set, the x64
JIT emits one CallNative to AuditLogSub824F7800Args at the start of the
JIT-compiled body of guest function 0x824F7800 (silph::WorkerCtx ctor's
immediate caller per audit-058). The hook reads r3..r10, LR, and 64
bytes at host(r3) from PPCContext and writes them to XELOGKERNEL.

The hook is placed *after* the JIT prolog (stack push, GUEST_RET_ADDR /
GUEST_CALL_RET_ADDR setup, optional trace-functions block) and *before*
the first HIR body instruction, so r3..r10 and lr in PPCContext still
reflect the caller's args (no LOAD/STORE_CONTEXT has executed yet inside
the callee). The compile-time gate `current_guest_function_ == 0x824F7800`
makes this a zero-cost no-op for all other functions and a single extra
CallNative for the one target.

Audit-059 round 7 probe captures r3..r10 + LR for a-prime synthetic
replay of sub_824F7800 from a host hook in xenia-rs. Run with:
--audit_handle_lifecycle=true --audit_log_sub824F7800_args=true

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
2026-07-12 15:43:23 +02:00
MechaCat02
35f58b147f [Audit] handle-lifecycle: one-shot silph::WorkerCtx hexdump on first KeSetEvent
Adds a 41-LOC cvar-gated probe (audit_handle_lifecycle) that emits a one-shot
0x300-byte hexdump of the silph::WorkerCtx context the first time KeSetEvent
fires into the silph UI PKEVENT cluster (0xBCE25200..0xBCE25300 in current
builds). Recovers ctx_base by anchoring on the canonical layout (events at
ctx+0x54/+0x64/+0x74/+0x84 with 16-byte stride; ctx_base = ev_addr - (ev_addr
- 0xBCE251C0)). Also emits an explicit per-slot summary of the 8 candidate
KEVENT headers at +0x54..+0xC4 for sanity.

Produces 48 DUMP rows + 8 slot rows in canary.log on the first triggering
KeSetEvent. Guarded by std::atomic_bool so subsequent fires are silent. Used
by iterate 2.BF context-replication in ours: we need the live [ctx+0] vtable
pointer and the 4 quiet/4 active KEVENT slot config to synthesize a matching
WorkerCtx and spawn the four sub_82506xxx entries.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
2026-07-12 15:43:23 +02:00
MechaCat02
3c7aa73512 [Audit] handle-lifecycle: include guest LR + one-frame stack-walk on waits
Extend the AUDIT-HLC probes with guest LR capture:
  - NtCreateEvent, NtSetEvent, KeSetEvent: log immediate guest LR
    (cpu::ThreadState::Get()->context()->lr) so callers can be
    attributed to specific guest functions.
  - NtWaitForSingleObjectEx entry + _done: also walk one PPC stack
    frame up to recover the guest_lr of the wait wrapper's caller
    (Xbox 360 EABI: saved LR at [prev_sp - 8], see xenia-rs's
    walk_guest_back_chain). lr_enter alone gives only the kernel
    wait wrapper return address (e.g. 0x824AC578); guest_lr surfaces
    the actual call site.

Still cvar-gated on audit_handle_lifecycle. Used in audit-059 round 4
to map canary handles F8000xxx to ours' 0x12xx wedges via guest LR
matching against silph::UImpl/GamePart cluster.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
2026-07-12 15:43:22 +02:00
MechaCat02
fea4ef31ec [Audit] handle-lifecycle XELOGKERNEL probes (cvar-gated)
New cvar `audit_handle_lifecycle` (Auditing group, default false).
When enabled, emits one-line XELOGKERNEL traces tagged AUDIT-HLC at:
  NtCreateEvent return, NtSetEvent entry, KeSetEvent entry,
  NtWaitForSingleObjectEx entry + completion,
  EmulateCPInterruptDPC entry.

Observation-only: zero-overhead when cvar off (single branch + flag
read). Intended for handle disambiguation between xenia-rs and
canary under the Wine cross-build oracle.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
2026-07-12 15:43:22 +02:00
MechaCat02
ce67514572 [Build] Linux→Windows cross-compile toolchain (clang-cl + xwin)
New CMake preset `cross-win-clangcl` for Ninja Multi-Config on
non-Windows hosts. Toolchain: clang-cl (MSVC-ABI), lld-link, xwin SDK/CRT
splat. Shader compilation routes through wine fxc.exe with FXC_PATH
env forwarding and unix→Windows path translation via `winepath -w`.
Plus per-file build fixes (constexpr→const, llvm-rc forward-slash,
zlib-ng AVX guard, /RTCsu MSVC-only). third_party/snappy bumped to
fabi/sylpheed-crossbuild for the target-aware POSIX-gate header.

Produces `xenia_canary.exe` (Debug MSVC) suitable for use as the
audit oracle under Wine for xenia-rs work. See
docs/CROSS_BUILD_SETUP.md for the full reproduction recipe.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
2026-07-12 15:43:22 +02:00
51 changed files with 3440 additions and 27 deletions

1
.gitignore vendored
View File

@@ -94,6 +94,7 @@ node_modules/.bin/
/build/
/build-arm64/
/build-x64/
/build-cross/
# ==============================================================================
# Local-only paths

View File

@@ -82,6 +82,23 @@ file(MAKE_DIRECTORY "${PROJECT_SOURCE_DIR}/scratch")
# Python for shader compilation scripts
find_package(Python3 REQUIRED COMPONENTS Interpreter)
# Generate build-tree version.h via xenia-build.py's generate_version_h()
# (normally invoked by `xb premake`/`xb build`; CMake-direct flows need it too).
execute_process(
COMMAND ${Python3_EXECUTABLE} -c
"import importlib.util,sys; \
spec=importlib.util.spec_from_file_location('xb',r'${PROJECT_SOURCE_DIR}/xenia-build.py'); \
m=importlib.util.module_from_spec(spec); spec.loader.exec_module(m); \
m.generate_version_h(r'${CMAKE_BINARY_DIR}')"
WORKING_DIRECTORY "${PROJECT_SOURCE_DIR}"
RESULT_VARIABLE _xenia_version_rc
)
if(NOT _xenia_version_rc EQUAL 0)
message(WARNING "version.h generation failed (rc=${_xenia_version_rc}); writing stub.")
file(WRITE "${CMAKE_BINARY_DIR}/version.h"
"#ifndef GENERATED_VERSION_H_\n#define GENERATED_VERSION_H_\n#define XE_BUILD_BRANCH \"unknown\"\n#define XE_BUILD_COMMIT \"unknown\"\n#define XE_BUILD_COMMIT_SHORT \"unknown\"\n#define XE_BUILD_DATE __DATE__\n#endif\n")
endif()
# Include helpers
include(cmake/XeniaHelpers.cmake)
@@ -146,8 +163,14 @@ if(MSVC)
# --- Per-configuration MSVC flags ---
# Checked
string(APPEND CMAKE_C_FLAGS_CHECKED " /RTCsu /fsanitize=address")
string(APPEND CMAKE_CXX_FLAGS_CHECKED " /RTCsu /fsanitize=address")
if(CMAKE_CXX_COMPILER_FRONTEND_VARIANT STREQUAL "MSVC"
AND NOT CMAKE_CXX_COMPILER_ID STREQUAL "Clang")
string(APPEND CMAKE_C_FLAGS_CHECKED " /RTCsu /fsanitize=address")
string(APPEND CMAKE_CXX_FLAGS_CHECKED " /RTCsu /fsanitize=address")
else()
string(APPEND CMAKE_C_FLAGS_CHECKED " /fsanitize=address")
string(APPEND CMAKE_CXX_FLAGS_CHECKED " /fsanitize=address")
endif()
string(APPEND CMAKE_EXE_LINKER_FLAGS_CHECKED " /INCREMENTAL:NO")
add_compile_definitions($<$<CONFIG:Checked>:DEBUG>)
@@ -291,9 +314,14 @@ else()
)
add_compile_options($<$<CONFIG:Release>:-O3>)
# Link-time optimization (use lld and llvm-ar/ranlib to avoid system
# linker/archiver LTO plugin version mismatch with clang's bitcode)
add_compile_options($<$<CONFIG:Release>:-flto=thin>)
add_link_options($<$<CONFIG:Release>:-flto=thin>)
# linker/archiver LTO plugin version mismatch with clang's bitcode).
# Guarded so memory-constrained hosts can build Release without the
# ThinLTO link-time memory spike: pass -DXENIA_ENABLE_LTO=OFF.
option(XENIA_ENABLE_LTO "Enable ThinLTO for Release builds" ON)
if(XENIA_ENABLE_LTO)
add_compile_options($<$<CONFIG:Release>:-flto=thin>)
add_link_options($<$<CONFIG:Release>:-flto=thin>)
endif()
add_link_options($<$<CONFIG:Release>:-fuse-ld=lld>)
find_program(LLVM_AR NAMES llvm-ar)
find_program(LLVM_RANLIB NAMES llvm-ranlib)

View File

@@ -39,6 +39,22 @@
"cacheVariables": {
"CMAKE_SYSTEM_PROCESSOR": "ARM64"
}
},
{
"name": "cross-win-clangcl",
"displayName": "Cross (Linux→Win MSVC) clang-cl + xwin",
"generator": "Ninja Multi-Config",
"binaryDir": "${sourceDir}/build-cross",
"toolchainFile": "${sourceDir}/cmake/toolchains/linux-to-win-msvc.cmake",
"condition": {
"type": "notEquals",
"lhs": "${hostSystemName}",
"rhs": "Windows"
},
"cacheVariables": {
"XWIN_DIR": "$env{HOME}/.xwin/splat",
"FXC_PATH": "$env{HOME}/.local/share/xenia-cross/fxc/fxc.exe"
}
}
],
"buildPresets": [
@@ -89,6 +105,9 @@
"name": "vs-arm64-checked",
"configurePreset": "vs-arm64",
"configuration": "Checked"
}
},
{ "name": "cross-debug", "configurePreset": "cross-win-clangcl", "configuration": "Debug" },
{ "name": "cross-release", "configurePreset": "cross-win-clangcl", "configuration": "Release" },
{ "name": "cross-checked", "configurePreset": "cross-win-clangcl", "configuration": "Checked" }
]
}

View File

@@ -0,0 +1,93 @@
# HANDOFF — Ready-Room crash: NEW ORACLE says it's OUR code, not the game (2026-07-16)
## TL;DR
The mid-game **crash** (guest `std::out_of_range` from the cache-manager flush, seen in the
**Ready Room** after a mission) is **introduced by our own changes**, not by the game and not by the
build toolchain. A clean bisection of our 19 commits + uncommitted working tree will find it.
## The new oracle (this is the key result)
We built **stock upstream `6e5b8324f` `[APU] Pace audio subsystem`** with our own toolchain and
**zero custom code** (0 custom cvars in the binary — verified). The user ran it:
> **Stock `6e5b8324f` → NO crash, NO sound-stop, played through the Ready Room fine.**
This kills two earlier hypotheses and re-frames the whole problem:
| Hypothesis | Verdict |
|---|---|
| "Genuine game data race, unfixable without masking" | **WRONG.** Stock game code is stable. |
| "Our build chain miscompiles (broken LTO) → crash" | **WRONG.** Same toolchain, stock source, no crash. |
| "The crash is in OUR 19 commits + 16 working-tree files" | **This is where it is.** Bisect it. |
The out_of_range race is real, but it's **our timing changes** that push a concurrent cache-add into
the flush's unlocked iteration window. Stock timing never lands there.
### Reproduce the oracle
```bash
cd "/home/fabi/RE - Project Sylpheed/xenia-canary-native"
git stash push -u
git checkout 6e5b8324f4101464de0f8c2334edb03cac8826c4
git submodule update --init third_party/DirectXShaderCompiler third_party/snappy # sync to stock pins
cmake --build build --config Release --target xenia_canary -j16 # reuses object cache
# copy bin/Linux/Release/xenia_canary aside, then restore:
git checkout <this-branch>
git -C third_party/DirectXShaderCompiler checkout dc3e6c48d
git -C third_party/snappy checkout 77c78fad
git stash pop
```
A prebuilt stock binary from this session is at `../stock-oracle/xenia_canary_STOCK_6e5b832`
(see "Artifacts" below). Run any binary through the launcher with `CANARY_BIN=<path> ./run-canary-native.sh`.
## Build-chain note (real, but NOT the crash cause)
Our LTO is silently disabled: `clang++` is **LLVM 18.1.3** but the linker's gold LTO plugin is
**LLVM 17.0.6**, so the plugin rejects clang-18 bitcode —
`failed to create LTO module: Unknown attribute kind (91)` **×420** (≈ every TU). ThinLTO is not
applied; our codegen differs from the fully-LTO'd official AppImage. Harmless for the crash (proven by
the oracle) but worth fixing for release parity: install/point at a matching `LLVMgold.so` (llvm-18),
or build `ld.lld`+`-fuse-ld=lld` which handles LTO in-tree, or disable LTO explicitly.
## Bisection plan (suspects ranked by how much they perturb guest thread timing)
Each test = one build + one Ready-Room run. Do them in order; stop at the first that removes the crash.
1. **`mem_watch` polling thread — FREE, no rebuild.** `kernel_state.cc` adds a detached host thread
(default **`--mem_watch=true`**) that wakes every 3 s and *reads the guest cache-manager memory*
the exact struct the crash is about. Test: run our binary with `--mem_watch=false`.
→ no crash = default it off / remove it; keep every real fix. **Best case.**
2. **Threading edits (uncommitted, load-bearing).** `threading_posix.cc` reap-once double-join fix +
`xma_decoder.cc work_event_->Set()` in `Pause()`. These *cure* the mission-teardown freeze +
permanent audio-death (see `project_audio_stall_freeze_diagnostics_2026_07_14`). Rebuild with them
reverted to stock; test. → **If these are the trigger, it's a real trade-off** (crash vs
freeze/audio-death) and needs a smarter fix, e.g. make the guest cache-flush loop
(PC `0x8245A154..0x8245A1CC`) atomic w.r.t. other guest threads instead of reverting the reap fix.
3. Other audio-fix files: `audio_system.cc` (+218), `xma_context_master.cc` (+44),
`xboxkrnl_audio.cc`, `apu_flags.*`, `alsa_audio_driver.cc`.
4. Committed audio fix `f10484834 [APU] Fix mission-audio silence`.
5. event_log Phase-A trampoline per-export overhead (`shim_utils.h`, committed).
Faster alternative to 25: `git stash` the uncommitted tree and test the committed HEAD alone — splits
"uncommitted working changes" from "the 19 commits" in one run (caveat: without the threading fixes the
mission-teardown freeze may hit before you reach the Ready Room; if it freezes instead of crashing,
that itself localizes the reap fix as load-bearing).
## Crash mechanism (already characterized — for context)
Guest cache manager (VA `0x828F4838`). Flush `sub_8245A098` snapshots the block deque under a critsec,
releases the lock, then iterates the ~654-entry deque **unlocked** doing `map::at` (`0x823070B0`,
throws at `0x8230711C`). A concurrent locked cache-add lands in the µs window → new deque key absent
from the frozen snapshot → `out_of_range`. Cascade count = 1 (a clean single-add TOCTOU). xenia never
dispatches the guest C++ throw, so it just crashes. Diagnostics for this live behind `--cache_throw_diag`
(default off) in `xboxkrnl_debug.cc`.
## Current repo state
- Branch **`phase-a-args-fileread`** (fork remote `git.mc02.dev/fabi/Xenia-Canary.git`).
- This commit = WIP snapshot of all audio/threading fixes + investigation instrumentation (all diag
cvars default-OFF). 1139 insertions / 16 src files + 2 new headers + DXC submodule bump.
- `build/` currently holds **stock** objects (we built the oracle there). To get OUR binary back:
`cmake --build build --config Release --target xenia_canary -j16` (~148 TU).
- Cleanup owed before release: strip/gate the diagnostic instrumentation
(`LogGuestThrow`/`DumpCacheManagerOnThrow`/`DispatchGuestCatch` in `xboxkrnl_debug.cc`, the
`xex_module.cc` PE/PDATA/EH scans, `kernel_state.cc` mem_watch). The broken tree-walk node layout in
`DumpCacheManagerOnThrow` (finds 117 of 654 nodes) is only used by the moot orphan diag — low prio.
## Artifacts (this session, scratchpad — EPHEMERAL, copy out if needed)
- `xenia_canary_OURS` — our full build (the crashing one)
- `xenia_canary_STOCK_6e5b832` — stock oracle (the stable one)

View File

@@ -192,6 +192,12 @@ function(xe_shader_rules_dxbc target shader_dir)
set(_valid_stages vs hs ds gs ps cs)
set(_commands)
set(_bytecode_dir "${shader_dir}/bytecode/d3d12_5_1")
# Propagate FXC_PATH from the configure-time env so ninja-spawned python
# subprocesses can find fxc.exe (CMake `set(ENV{...})` doesn't reach build).
set(_env_prefix "")
if(DEFINED ENV{FXC_PATH})
set(_env_prefix ${CMAKE_COMMAND} -E env "FXC_PATH=$ENV{FXC_PATH}")
endif()
list(APPEND _commands COMMAND ${CMAKE_COMMAND} -E make_directory "${_bytecode_dir}")
foreach(src ${_sources})
get_filename_component(_name ${src} NAME)
@@ -206,7 +212,7 @@ function(xe_shader_rules_dxbc target shader_dir)
if(NOT _stage IN_LIST _valid_stages)
continue()
endif()
list(APPEND _commands COMMAND ${Python3_EXECUTABLE} "${_script}" "${src}" "${_bytecode_dir}/${_id}.h")
list(APPEND _commands COMMAND ${_env_prefix} ${Python3_EXECUTABLE} "${_script}" "${src}" "${_bytecode_dir}/${_id}.h")
endforeach()
add_custom_command(
OUTPUT "${_stamp}"

View File

@@ -0,0 +1,119 @@
# cmake/toolchains/linux-to-win-msvc.cmake
# Linux host -> Windows MSVC-ABI cross toolchain using clang-cl + lld-link
# + xwin-supplied Win10 SDK/CRT. Driven by Ninja Multi-Config.
set(CMAKE_SYSTEM_NAME Windows)
set(CMAKE_SYSTEM_PROCESSOR x86_64)
if(NOT DEFINED XWIN_DIR)
if(DEFINED ENV{XWIN_DIR})
set(XWIN_DIR "$ENV{XWIN_DIR}")
else()
set(XWIN_DIR "$ENV{HOME}/.xwin/splat")
endif()
endif()
set(XWIN_DIR "${XWIN_DIR}" CACHE PATH "xwin splat root (contains crt/ and sdk/)")
if(NOT EXISTS "${XWIN_DIR}/crt/include")
message(FATAL_ERROR "XWIN_DIR=${XWIN_DIR} missing crt/include - run xwin splat.")
endif()
set(CMAKE_C_COMPILER clang-cl)
set(CMAKE_CXX_COMPILER clang-cl)
set(CMAKE_LINKER lld-link)
set(CMAKE_RC_COMPILER llvm-rc)
set(CMAKE_AR llvm-lib)
set(CMAKE_MT llvm-mt)
set(CMAKE_C_COMPILER_TARGET x86_64-pc-windows-msvc)
set(CMAKE_CXX_COMPILER_TARGET x86_64-pc-windows-msvc)
set(CMAKE_TRY_COMPILE_TARGET_TYPE STATIC_LIBRARY)
# Force /MD (release CRT) for every config. xenia's CMakeLists.txt does a
# `string(REPLACE "/MDd" "/MD" ...)` on CMAKE_CXX_FLAGS_DEBUG, but with
# clang-cl, the runtime selection comes from CMAKE_MSVC_RUNTIME_LIBRARY
# (which expands to -MDd in dash form), so the substitution misses.
# Pinning the policy here avoids the need for non-redistributable debug
# CRT DLLs (MSVCP140D.dll etc) at runtime, which xwin doesn't ship.
cmake_policy(SET CMP0091 NEW)
set(CMAKE_MSVC_RUNTIME_LIBRARY "MultiThreadedDLL")
# xwin's default splat is a flat layout (crt/include, sdk/include/{ucrt,um,shared,...}),
# which clang-cl's /winsysroot does NOT understand. Use explicit -imsvc + -libpath:
# instead. Re-running `xwin splat --use-winsysroot-style` would also work but
# requires re-downloading ~600 MB.
# Use SHELL: prefix so CMake doesn't deduplicate repeated -imsvc tokens.
add_compile_options(
"SHELL:-imsvc \"${XWIN_DIR}/crt/include\""
"SHELL:-imsvc \"${XWIN_DIR}/sdk/include/ucrt\""
"SHELL:-imsvc \"${XWIN_DIR}/sdk/include/um\""
"SHELL:-imsvc \"${XWIN_DIR}/sdk/include/shared\""
"SHELL:-imsvc \"${XWIN_DIR}/sdk/include/winrt\""
)
add_link_options(
"/libpath:${XWIN_DIR}/crt/lib/x86_64"
"/libpath:${XWIN_DIR}/sdk/lib/ucrt/x86_64"
"/libpath:${XWIN_DIR}/sdk/lib/um/x86_64"
)
# xwin pulls the latest MSVC STL which now hard-asserts Clang >= 19. Our host
# has Clang 18, which works fine in practice — opt out of the version check.
# (See yvals_core.h STL1000 in $XWIN_DIR/crt/include.)
add_compile_definitions(_ALLOW_COMPILER_AND_STL_VERSION_MISMATCH)
# llvm-rc needs SDK headers explicitly + the resource file's own dir so the
# RC's relative ICON path (../../../assets/icon/icon.ico) resolves.
get_filename_component(_toolchain_dir "${CMAKE_CURRENT_LIST_FILE}" DIRECTORY)
get_filename_component(_xenia_root "${_toolchain_dir}/../.." ABSOLUTE)
set(CMAKE_RC_FLAGS_INIT
"/I \"${XWIN_DIR}/sdk/include/um\" /I \"${XWIN_DIR}/sdk/include/shared\" /I \"${_xenia_root}/src/xenia/app\"")
# Quiet MSVC-STL false positives and xenia-specific warnings that clang-cl
# emits but cl.exe doesn't (treated as errors under /WX).
add_compile_options(
-Wno-microsoft-include
-Wno-unused-command-line-argument
-Wno-ignored-pragma-intrinsic
-Wno-nonportable-include-path
-Wno-pragma-pack
-Wno-tautological-pointer-compare
-Wno-microsoft-cast
-Wno-deprecated-declarations
# These are silenced for native Linux Clang in CMakeLists.txt's else() branch,
# but the if(MSVC) branch fires under clang-cl and skips them — so re-add.
-Wno-switch
-Wno-attributes
-Wno-deprecated-register
-Wno-deprecated-volatile
-Wno-deprecated-enum-enum-conversion
# cl.exe accepts __pragma(optimize("s",on)); clang-cl only knows the empty
# argument form. xenia gates XE_MSVC_OPTIMIZE_SMALL on _MSC_VER so the
# rejected pragma still emits from the clang-cl path. Treat as no-op.
-Wno-ignored-pragmas
# xenia decorates several `virtual` methods with XE_FORCEINLINE; clang-cl
# then complains that the inline body isn't visible in includer TUs
# (definitions live in command_processor.cc). cl.exe accepts this silently.
-Wno-undefined-inline
-Wno-sizeof-pointer-memaccess
# `'ZM'` (PE magic, stored little-endian as "MZ" in the binary) — cl.exe
# accepts the multi-char constant silently; clang-cl errors under /WX.
-Wno-multichar
)
# _mm_cvtsi64x_si128 is an MSVC-only alias for the standard _mm_cvtsi64_si128.
# Used (gated on XE_PLATFORM_WIN32) in xenia/gpu/draw_util.cc.
add_compile_definitions(_mm_cvtsi64x_si128=_mm_cvtsi64_si128)
# Plumb FXC for tools/build/compile_shader_dxbc.py (wine fxc auto-prepend).
# Use real Win10 SDK fxc.exe 10.x (supports SM 5_1, produces vkd3d-proton-
# acceptable DXBC).
if(DEFINED ENV{FXC_PATH})
set(ENV_FXC "$ENV{FXC_PATH}")
else()
set(ENV_FXC "$ENV{HOME}/.local/share/xenia-cross/fxc/fxc.exe")
endif()
set(ENV{FXC_PATH} "${ENV_FXC}")
set(CMAKE_FIND_ROOT_PATH "${XWIN_DIR}")
set(CMAKE_FIND_ROOT_PATH_MODE_PROGRAM NEVER)
set(CMAKE_FIND_ROOT_PATH_MODE_LIBRARY ONLY)
set(CMAKE_FIND_ROOT_PATH_MODE_INCLUDE ONLY)
set(CMAKE_FIND_ROOT_PATH_MODE_PACKAGE ONLY)

View File

@@ -0,0 +1,55 @@
#!/usr/bin/env python3
"""Scan xenia source for #include <...> directives and ensure case-aliases
exist in xwin's flat SDK/CRT include dirs. Idempotent — safe to re-run."""
from __future__ import annotations
import os, re, sys
from pathlib import Path
INCLUDE_RE = re.compile(r'^\s*#\s*include\s*<([A-Za-z][A-Za-z0-9_/.\-]*\.h)>',
re.MULTILINE)
SOURCE_ROOTS = ["src", "third_party/SDL2/src", "third_party/SDL2/include",
"third_party/discord-rpc/src", "third_party/fmt",
"third_party/imgui"]
SOURCE_EXTS = {".h", ".hpp", ".inc", ".c", ".cc", ".cpp", ".cxx"}
def collect_includes(repo_root: Path) -> set[str]:
seen: set[str] = set()
for root in SOURCE_ROOTS:
base = repo_root / root
if not base.exists(): continue
for path in base.rglob("*"):
if path.suffix.lower() not in SOURCE_EXTS: continue
try: txt = path.read_text(encoding="utf-8", errors="ignore")
except OSError: continue
for m in INCLUDE_RE.finditer(txt):
seen.add(m.group(1))
return seen
def fix_dir(target_dir: Path, want: set[str]) -> int:
if not target_dir.is_dir(): return 0
idx = {e.name.lower(): e.name for e in target_dir.iterdir()}
created = 0
for name in want:
if "/" in name: continue
actual = idx.get(name.lower())
if actual is None or actual == name: continue
link = target_dir / name
if link.exists() or link.is_symlink(): continue
try:
link.symlink_to(actual)
created += 1
except OSError: pass
return created
if __name__ == "__main__":
if len(sys.argv) != 3:
sys.exit("usage: xwin-case-symlinks.py <xenia-canary-root> <xwin-splat-dir>")
repo = Path(sys.argv[1]).resolve()
xwin = Path(sys.argv[2]).resolve()
want = collect_includes(repo)
total = 0
for d in (xwin/"crt/include", xwin/"sdk/include/ucrt",
xwin/"sdk/include/um", xwin/"sdk/include/shared",
xwin/"sdk/include/winrt"):
total += fix_dir(d, want)
print(f"Created {total} case-symlinks across {len(want)} unique includes.")

100
docs/CROSS_BUILD_SETUP.md Normal file
View File

@@ -0,0 +1,100 @@
# Building and Running Xenia Canary Windows Debug from Linux
## What we built and why
A Windows-MSVC debug `xenia_canary.exe` cross-compiled on Linux, runnable under Wine. This serves as the audit oracle for the xenia-rs Rust port: the Linux-native canary build stalls before the front-end UI, so all audit comparisons (memory entries audit_044audit_059) need the Wine-targeted debug binary as the ground-truth reference engine.
## Phase 1 — Host setup (run in your terminal)
sudo apt install -y clang-18 lld-18 llvm-18 # clang-cl driver mode + lld-link + binutils
sudo ln -s /usr/bin/clang-18 /usr/bin/clang-cl # activates MSVC-compatible driver mode
xwin --accept-license --arch x86_64 splat --include-debug-libs --output ~/.xwin/splat
# ~807 MB Win10 SDK + MSVC CRT sysroot
curl ... linkid=2361406 -o ~/winsdk.iso # Win10 SDK ISO for real fxc.exe (SM 5_1)
winetricks -q vkd3d # vkd3d-proton d3d12core.dll (5.96 MB)
winetricks -q dxvk # DXVK dxgi.dll (2.95 MB)
Ubuntu's clang-18 / lld-18 apt packages ship binutils suffixed (llvm-lib-18, lld-link-18, etc.); the toolchain expects unsuffixed names on PATH. Create 4 symlinks in `~/.local/bin/` (no sudo needed since it was already on PATH).
## Phase 2 — In-tree edits
### 8 build-fix patches (compile-time only; zero runtime semantics changes)
| § | File | What changed |
|---|---|---|
| 7.1 | `src/xenia/base/mapped_memory_win.cc:30` | `constexpr``const` for `kFileHandleInvalid` (clang-cl rejects `reinterpret_cast` in constant expressions) |
| 7.2 | `src/xenia/app/main_resources.rc:3` | `..\\..\\..\\assets\\icon\\icon.ico` → forward slashes (llvm-rc backslash literalism) |
| 7.3 | `third_party/snappy/snappy-stubs-public.h` | Already in place via the `fabi/sylpheed-crossbuild` snappy fork submodule |
| 7.4 | `third_party/zlib-ng/zconf-ng.h:113` | `#if 1``#if !defined(_WIN32)` for `Z_HAVE_UNISTD_H` (header was pre-generated on Linux) |
| 7.5 | `third_party/CMakeLists.txt:335` | Extended `if(NOT MSVC)``if(NOT MSVC OR CMAKE_CXX_COMPILER_ID STREQUAL "Clang")` for zlib-ng AVX flags |
| 7.6a | `CMakeLists.txt` | Wrapped `/RTCsu` appends in `CMAKE_CXX_COMPILER_FRONTEND_VARIANT STREQUAL "MSVC" AND NOT … "Clang"` |
| 7.6b | `CMakeLists.txt:85-101` | Inserted `execute_process` block invoking `xenia-build.py:generate_version_h()` so CMake-direct flow produces `version.h` |
| 7.7 | `cmake/XeniaHelpers.cmake` | Added `_env_prefix` to wrap per-shader commands in `cmake -E env FXC_PATH=…` (`cmake set(ENV{…})` doesn't survive ninja's subprocess spawn) |
| 7.8 | `tools/build/compile_shader_dxbc.py:74` | Added `_wineify()` helper translating unix paths via `winepath -w` before fxc sees them (fxc parses `/home/…` as a `/h` switch) |
### 3 new cross-compile config files
| File | Purpose |
|---|---|
| `cmake/toolchains/linux-to-win-msvc.cmake` | clang-cl + lld-link + xwin sysroot driver. Forces `MultiThreadedDLL` runtime (no debug-CRT DLLs needed), feeds `-imsvc` flags via `SHELL:` prefix, suppresses 15+ clang-cl-specific warnings, defines `_mm_cvtsi64x_si128` alias, opts out of MSVC STL's Clang≥19 assertion, plumbs `FXC_PATH` |
| `cmake/toolchains/xwin-case-symlinks.py` | Scans xenia includes for mixed-case Windows headers and creates the missing case-aliases in xwin's flat splat (5 needed: `ObjBase.h`, `Psapi.h`, etc.) |
| `CMakePresets.json` | Added `cross-win-clangcl` configure preset + `cross-debug` / `cross-release` / `cross-checked` build presets, gated on `${hostSystemName}` ≠ Windows |
## Phase 3 — Configure + build
python3 cmake/toolchains/xwin-case-symlinks.py "$PWD" "$HOME/.xwin/splat"
# Created 5 case-symlinks across 556 unique includes
cmake --preset cross-win-clangcl
# Generates build-cross/ with build-Debug.ninja + auto-generated version.h
cmake --build build-cross --preset cross-debug --target xenia-app -j6
# 936 ninja targets. -j6 not -j12 because host RAM is tight (~3.4 GiB free at start)
# Wall time ~25 min total
Final output: `xenia_canary.exe` (27 MB PE32+ GUI x86-64) + `xenia_canary.pdb` (116 MB CodeView).
## Phase 4 — Running the game
cd "/home/fabi/RE Project Sylpheed/xenia-canary/build-cross/bin/Windows/Debug"
WINEDEBUG=-all wine ./xenia_canary.exe --mute=true \
"/home/fabi/RE Project Sylpheed/Project Sylpheed - Arc of Deception (USA, Europe) (En,Ja).iso"
Kill after the boot phase completes (the audit workflow only needs ~30 s of trajectory):
sleep 30
wineserver -k
### Expected boot signals in `xenia.log`
| Signal | Value | Meaning |
|---|---|---|
| Total log lines | 1091 | Healthy boot (≥1000 = passes) |
| `^x>` fatals | 0 | No `xe::FatalError()` triggered |
| `^!>` errors | 28 | Non-fatal (occasional pipeline misses — normal) |
| `^w>` warnings | 28 | Normal startup |
| `i> Setup: Initializing chain` | Memory → Exports → Processor → Audio → Graphics → HID → VFS → Kernel | All eight subsystems came up |
| `i> Setup: Starting graphics_system + Starting audio_system` | present | Threads spawned cleanly |
| DXGI adapter | NVIDIA GeForce GTX 1070 Ti | vkd3d-proton + DXVK loaded |
| `K> XThread::Execute thid N count` | 29 | Guest threads spawned (game is past `XexLoadImage`) |
| `Skipping draw - pipeline not ready: VS … PS …` repeating | yes | D3D12 backend is async-compiling pipelines — expected on cold boot |
| `F>` channel | 321 lines | VFS is mounting and walking the disc image |
| `K>` channel | 29 lines | Kernel dispatching XThread creation |
## Audit-workflow integration
The cross-build is now the sole canary oracle. The Linux-native `xenia-canary/build/bin/Linux/Debug/xenia_canary` is deprecated for audits.
All canary launches must include `--mute=true` (project policy 2026-05-12). XAudio2 still initializes — same code paths, silent output. Do not substitute `--apu=nop`; that switches backend entirely.
Point logs at `audit-runs` with `--log_file=`:
LOG="$XENIA_RS_ROOT/xenia-rs/audit-runs/audit_NN/canary.log" \
WINEDEBUG=-all wine xenia_canary.exe \
--mute=true --log_file="$LOG" \
--audit_NN_my_probe=true \
"$ISO_PATH"
Add new audit instrumentation as cvars in `cpu_flags.h` / `gpu_flags.h` / `kernel_flags.h`, guard with `if (cvars::audit_NN_my_probe)`, emit `XELOGI("AUDIT-NN-EVENT …")`. Rebuild incrementally — only the touched TU recompiles, ≤60 s.
The build is observation-only: cvars + `XELOG*()` + `#if`-gated diagnostic blocks are permitted; changing control flow, return values, struct layouts, or timing is forbidden, since that would invalidate every downstream audit comparison.

View File

@@ -1134,10 +1134,20 @@ void EmulatorWindow::OnMouseUp(const ui::MouseEvent& e) {
void EmulatorWindow::TakeScreenshot() {
xe::ui::RawImage image;
// Null-check the presenter BEFORE dereferencing it. The original condition
// called CaptureGuestOutput() on the pointer and only tested it for null
// afterwards, so pressing the screenshot key before/without a live presenter
// dereferenced a null pointer and crashed.
auto* presenter = GetGraphicsSystemPresenter();
if (presenter == nullptr) {
XELOGE("No graphics presenter available for screenshot");
return;
}
imgui_drawer_->EnableNotifications(false);
if (!GetGraphicsSystemPresenter()->CaptureGuestOutput(image) ||
GetGraphicsSystemPresenter() == nullptr) {
if (!presenter->CaptureGuestOutput(image)) {
imgui_drawer_->EnableNotifications(true);
XELOGE("Failed to capture guest output for screenshot");
return;
}

View File

@@ -1,3 +1,3 @@
//{{NO_DEPENDENCIES}}
MAINICON ICON "..\\..\\..\\assets\\icon\\icon.ico"
MAINICON ICON "../../../assets/icon/icon.ico"

View File

@@ -20,6 +20,7 @@
#endif
#include "xenia/apu/apu_flags.h"
#include "xenia/apu/audio_watchdog.h"
#include "xenia/apu/conversion.h"
#include "xenia/base/assert.h"
#include "xenia/base/clock.h"
@@ -315,6 +316,8 @@ void ALSAAudioDriver::WorkerThread() {
snd_pcm_writei(pcm_handle_, silence.get(), silence_frames);
while (running_) {
watchdog::alsa_state.store(static_cast<int>(snd_pcm_state(pcm_handle_)),
std::memory_order_relaxed);
if (paused_) {
snd_pcm_drop(pcm_handle_);
std::this_thread::sleep_for(std::chrono::milliseconds(10));
@@ -336,8 +339,32 @@ void ALSAAudioDriver::WorkerThread() {
size_t current_write = write_index_.load(std::memory_order_acquire);
if (current_read == current_write) {
// No data available, sleep and try again
std::this_thread::sleep_for(std::chrono::milliseconds(5));
// No guest audio available. During long guest stalls (e.g. a mission
// "Preparing for Sortie" load) the game stops submitting frames; if we
// merely sleep, ALSA drains its small buffer, XRUNs, and playback never
// recovers (the game's audio is silent for the rest of the session).
// Keep the PCM alive by topping it up with silence whenever the queued
// audio runs low, so real audio resumes seamlessly once the stall ends.
snd_pcm_sframes_t avail = snd_pcm_avail_update(pcm_handle_);
if (avail < 0) {
if (!RecoverFromUnderrun(avail)) {
running_ = false;
}
continue;
}
snd_pcm_uframes_t queued =
(buffer_size_ > (snd_pcm_uframes_t)avail) ? buffer_size_ - avail : 0;
if (queued < period_size_ * 2) {
snd_pcm_sframes_t w =
snd_pcm_writei(pcm_handle_, silence.get(), period_size_);
if (w < 0) {
RecoverFromUnderrun(w);
} else {
watchdog::alsa_silence.fetch_add(1, std::memory_order_relaxed);
}
} else {
std::this_thread::sleep_for(std::chrono::milliseconds(2));
}
continue;
}
@@ -429,6 +456,7 @@ void ALSAAudioDriver::WorkerThread() {
} else if (written != (snd_pcm_sframes_t)frames_to_write) {
XELOGW("Partial write: {} of {} frames", written, frames_to_write);
}
watchdog::alsa_writes.fetch_add(1, std::memory_order_relaxed);
// Move to next frame in ring buffer
// Use release semantics so writer thread sees this update
@@ -448,6 +476,7 @@ void ALSAAudioDriver::WorkerThread() {
}
bool ALSAAudioDriver::RecoverFromUnderrun(int err) {
watchdog::alsa_xruns.fetch_add(1, std::memory_order_relaxed);
if (err == -EPIPE) {
// Underrun occurred
XELOGW("ALSA underrun detected, recovering...");

View File

@@ -10,3 +10,9 @@
#include "xenia/apu/apu_flags.h"
DEFINE_bool(mute, false, "Mutes all audio output.", "APU")
DEFINE_bool(audio_watchdog, false,
"Report which stage of the audio pipeline stopped when audio dies "
"(guest callback / XMA decode / frame submit / ALSA write). "
"Diagnostics only.",
"APU")

View File

@@ -12,5 +12,6 @@
#include "xenia/base/cvar.h"
DECLARE_bool(mute)
DECLARE_bool(audio_watchdog)
#endif // XENIA_APU_APU_FLAGS_H_

View File

@@ -13,6 +13,7 @@
#include "xenia/apu/apu_flags.h"
#include "xenia/apu/audio_driver.h"
#include "xenia/apu/audio_watchdog.h"
#include "xenia/apu/xma_decoder.h"
#include "xenia/base/assert.h"
#include "xenia/base/byte_stream.h"
@@ -66,12 +67,173 @@ AudioSystem::~AudioSystem() {
}
}
namespace {
// --- audio watchdog (diagnostics, --audio_watchdog, default off) -------------
// Samples the pipeline-stage counters in audio_watchdog.h once a second and
// reports which stage stopped when audio dies. Deliberately near-silent while
// healthy: log spam of its own would starve the very pipeline it watches.
std::atomic<bool> watchdog_running_{false};
std::thread watchdog_thread_;
uint64_t WatchdogNowUs() {
return static_cast<uint64_t>(
std::chrono::duration_cast<std::chrono::microseconds>(
std::chrono::steady_clock::now().time_since_epoch())
.count());
}
const char* AlsaStateName(int state) {
// snd_pcm_state_t, kept as an int so we need no ALSA header here.
static const char* kNames[] = {"OPEN", "SETUP", "PREPARED",
"RUNNING", "XRUN", "DRAINING",
"PAUSED", "SUSPENDED", "DISCONNECTED"};
if (state < 0 || state >= static_cast<int>(xe::countof(kNames))) {
return "?";
}
return kNames[state];
}
void AudioWatchdogMain() {
xe::threading::set_name("Audio Watchdog");
uint64_t last_pumps = 0, last_submits = 0, last_xma = 0;
uint64_t last_writes = 0, last_silence = 0, last_xruns = 0;
uint64_t last_loops = 0, last_skips = 0;
bool was_alive = true;
bool ever_alive = false;
uint64_t dead_ticks = 0;
while (watchdog_running_) {
std::this_thread::sleep_for(std::chrono::seconds(1));
if (!watchdog_running_) {
break;
}
using namespace xe::apu::watchdog;
const uint64_t pumps = guest_pumps.load(std::memory_order_relaxed);
const uint64_t submits = frames_submitted.load(std::memory_order_relaxed);
const uint64_t xma = xma_works.load(std::memory_order_relaxed);
const uint64_t writes = alsa_writes.load(std::memory_order_relaxed);
const uint64_t silence = alsa_silence.load(std::memory_order_relaxed);
const uint64_t xruns = alsa_xruns.load(std::memory_order_relaxed);
const uint64_t d_pumps = pumps - last_pumps;
const uint64_t d_submits = submits - last_submits;
const uint64_t d_xma = xma - last_xma;
const uint64_t d_writes = writes - last_writes;
const uint64_t d_silence = silence - last_silence;
const uint64_t d_xruns = xruns - last_xruns;
last_pumps = pumps;
last_submits = submits;
last_xma = xma;
last_writes = writes;
last_silence = silence;
last_xruns = xruns;
// How long has the APU worker been stuck inside guest code? The guest
// callback runs on the pump thread, so a guest block here kills audio
// permanently -- this is the prime suspect for "sound never comes back".
const uint64_t in_guest_since =
in_guest_callback_since_us.load(std::memory_order_relaxed);
const double stuck_s =
in_guest_since ? (WatchdogNowUs() - in_guest_since) / 1000000.0 : 0.0;
// "Alive" = the guest is still producing audio. Prefer real frames reaching
// the device, but fall back to pumps so this also works under --apu=nop
// (silent stress runs, where there is no host device to write to).
const bool alive = d_writes > 0 || d_pumps > 0;
const uint64_t loops = worker_loops.load(std::memory_order_relaxed);
const uint64_t skips = pump_skips.load(std::memory_order_relaxed);
const int clients = clients_in_use.load(std::memory_order_relaxed);
const uint64_t regs = register_calls.load(std::memory_order_relaxed);
const uint64_t unregs = unregister_calls.load(std::memory_order_relaxed);
const uint64_t d_loops = loops - last_loops;
const uint64_t d_skips = skips - last_skips;
last_loops = loops;
last_skips = skips;
const auto phase = worker_phase.load(std::memory_order_relaxed);
// Name the culprit stage, walking the pipeline from the guest outward. The
// worker's own recorded phase beats any inference we could make from the
// outside, so trust it first.
const char* culprit = "";
if (!alive) {
if (stuck_s >= 1.0) {
culprit = "guest audio callback BLOCKED (pump thread stuck in guest)";
} else if (d_loops == 0 &&
phase == WorkerPhase::kAcquiringGlobalLock) {
culprit =
"APU worker BLOCKED on the kernel global lock (someone else holds "
"it)";
} else if (d_loops == 0 && phase == WorkerPhase::kParkedNoClient) {
culprit =
"NO AUDIO CLIENT: guest unregistered it and never re-registered";
} else if (d_pumps == 0 && d_loops == 0) {
culprit = "worker stalled -- see phase=";
} else if (d_pumps == 0 && d_skips > 0) {
culprit = "worker looping but never gets a free output slot (semaphore)";
} else if (d_pumps == 0) {
culprit = "APU worker not pumping the guest callback";
} else if (d_submits == 0) {
culprit = "guest pumping but submitting no frames (starved upstream)";
} else if (d_xma == 0 && xma > 0) {
culprit = "XMA decoder stopped doing work";
} else {
culprit = "frames submitted but host driver is not writing them";
}
}
if (!alive) {
dead_ticks++;
}
if (alive) {
ever_alive = true;
}
// Stay quiet until audio has actually played once: silence during boot /
// menus is not the bug. Then log every transition and once a second while
// dead -- "it was playing and then it stopped" is precisely the event.
if (!ever_alive) {
was_alive = alive;
continue;
}
if (alive != was_alive || !alive) {
XELOGW(
"AUDIO-WD [{}] +pumps={} +submits={} +xma={} +writes={} "
"+silence={} +xruns={} +loops={} +skips={} clients={} reg={} "
"unreg={} phase={} pcm={} guest_cb_stuck={:.1f}s dead={}s {}",
alive ? "OK" : "DEAD", d_pumps, d_submits, d_xma, d_writes, d_silence,
d_xruns, d_loops, d_skips, clients, regs, unregs,
WorkerPhaseName(phase),
AlsaStateName(alsa_state.load(std::memory_order_relaxed)), stuck_s,
dead_ticks, culprit);
}
if (alive) {
dead_ticks = 0;
}
was_alive = alive;
}
}
} // namespace
X_STATUS AudioSystem::Setup(kernel::KernelState* kernel_state) {
X_STATUS result = xma_decoder_->Setup(kernel_state);
if (result) {
return result;
}
if (cvars::audio_watchdog && !watchdog_running_) {
watchdog_running_ = true;
watchdog_thread_ = std::thread(AudioWatchdogMain);
XELOGW("AUDIO-WD watchdog armed (reports the stage that stops on silence)");
}
worker_running_ = true;
worker_thread_ =
kernel::object_ref<kernel::XHostThread>(new kernel::XHostThread(
@@ -102,6 +264,8 @@ void AudioSystem::WorkerThreadMain() {
// a host output slot is free, otherwise it is dropped (the host queue
// is full, so it is already well buffered).
while (worker_running_) {
watchdog::worker_loops.fetch_add(1, std::memory_order_relaxed);
const uint64_t now = static_cast<uint64_t>(
std::chrono::duration_cast<std::chrono::microseconds>(
std::chrono::steady_clock::now().time_since_epoch())
@@ -112,9 +276,17 @@ void AudioSystem::WorkerThreadMain() {
uint32_t client_callback = 0;
uint32_t client_callback_arg = 0;
{
watchdog::worker_phase.store(watchdog::WorkerPhase::kAcquiringGlobalLock,
std::memory_order_relaxed);
auto global_lock = global_critical_region_.Acquire();
watchdog::worker_phase.store(watchdog::WorkerPhase::kStart,
std::memory_order_relaxed);
int in_use_count = 0;
for (size_t i = 0; i < kMaximumClientCount; ++i) {
if (clients_[i].in_use) {
++in_use_count;
}
if (!clients_[i].in_use ||
clients_[i].next_pump_us >= earliest_pump_us) {
continue;
@@ -122,6 +294,7 @@ void AudioSystem::WorkerThreadMain() {
earliest_pump_us = clients_[i].next_pump_us;
client_index = i;
}
watchdog::clients_in_use.store(in_use_count, std::memory_order_relaxed);
if (client_index != kMaximumClientCount) {
client_callback = clients_[client_index].callback;
@@ -138,6 +311,8 @@ void AudioSystem::WorkerThreadMain() {
// No clients yet: park until one registers or we're told to stop.
if (client_index == kMaximumClientCount) {
watchdog::worker_phase.store(watchdog::WorkerPhase::kParkedNoClient,
std::memory_order_relaxed);
xe::threading::Wait(pending_work_event_.get(), true);
if (paused_) {
pause_fence_.Signal();
@@ -151,6 +326,8 @@ void AudioSystem::WorkerThreadMain() {
? earliest_pump_us - kAudioIntervalSlack
: 0;
if (wake_target_us > now) {
watchdog::worker_phase.store(watchdog::WorkerPhase::kPacingSleep,
std::memory_order_relaxed);
const std::chrono::milliseconds timeout((wake_target_us - now) / 1000);
auto result =
xe::threading::Wait(pending_work_event_.get(), true, timeout);
@@ -172,14 +349,30 @@ void AudioSystem::WorkerThreadMain() {
}
// Submit only if the host has a free output slot;
if (client_callback &&
const bool have_slot =
client_callback &&
xe::threading::Wait(client_semaphores_[client_index].get(), false,
std::chrono::milliseconds(0)) ==
xe::threading::WaitResult::kSuccess) {
xe::threading::WaitResult::kSuccess;
if (!have_slot) {
watchdog::pump_skips.fetch_add(1, std::memory_order_relaxed);
}
if (have_slot) {
SCOPE_profile_cpu_i("apu", "xe::apu::AudioSystem->client_callback");
uint64_t args[] = {client_callback_arg};
// The guest callback runs in-line on this pump thread: if it blocks, the
// pump stops forever and audio never recovers. Bracket it so the
// watchdog can see (and name) that case.
watchdog::in_guest_callback_since_us.store(WatchdogNowUs(),
std::memory_order_relaxed);
watchdog::worker_phase.store(watchdog::WorkerPhase::kInGuestCallback,
std::memory_order_relaxed);
processor_->Execute(worker_thread_->thread_state(), client_callback, args,
xe::countof(args));
watchdog::worker_phase.store(watchdog::WorkerPhase::kStart,
std::memory_order_relaxed);
watchdog::in_guest_callback_since_us.store(0, std::memory_order_relaxed);
watchdog::guest_pumps.fetch_add(1, std::memory_order_relaxed);
}
}
worker_running_ = false;
@@ -201,6 +394,13 @@ int AudioSystem::FindFreeClient() {
void AudioSystem::Initialize() {}
void AudioSystem::Shutdown() {
if (watchdog_running_) {
watchdog_running_ = false;
if (watchdog_thread_.joinable()) {
watchdog_thread_.join();
}
}
worker_running_ = false;
pending_work_event_->Set();
if (worker_thread_) {
@@ -261,6 +461,12 @@ X_STATUS AudioSystem::RegisterClient(uint32_t callback, uint32_t callback_arg,
clients_[index].wrapped_callback_arg = ptr;
clients_[index].in_use = true;
watchdog::register_calls.fetch_add(1, std::memory_order_relaxed);
if (cvars::audio_watchdog) {
XELOGW("AUDIO-WD RegisterClient(index={}) callback={:08X} -- audio client back",
index, callback);
}
// Wake the worker so it re-scans and starts pacing this client immediately.
pending_work_event_->Set();
@@ -277,6 +483,8 @@ X_STATUS AudioSystem::RegisterClient(uint32_t callback, uint32_t callback_arg,
void AudioSystem::SubmitFrame(size_t index, float* samples) {
SCOPE_profile_cpu_f("apu");
watchdog::frames_submitted.fetch_add(1, std::memory_order_relaxed);
auto global_lock = global_critical_region_.Acquire();
assert_true(index < kMaximumClientCount);
if (index >= kMaximumClientCount || !clients_[index].in_use ||
@@ -302,6 +510,12 @@ void AudioSystem::SubmitFrame(size_t index, float* samples) {
void AudioSystem::UnregisterClient(size_t index) {
SCOPE_profile_cpu_f("apu");
watchdog::unregister_calls.fetch_add(1, std::memory_order_relaxed);
if (cvars::audio_watchdog) {
XELOGW("AUDIO-WD UnregisterClient(index={}) -- guest dropped its audio client",
index);
}
auto global_lock = global_critical_region_.Acquire();
assert_true(index < kMaximumClientCount);
DestroyDriver(clients_[index].driver);

View File

@@ -0,0 +1,104 @@
/**
******************************************************************************
* Xenia : Xbox 360 Emulator Research Project *
******************************************************************************
* Copyright 2026 Ben Vanik. All rights reserved. *
* Released under the BSD license - see LICENSE in the root for more details. *
******************************************************************************
*/
#ifndef XENIA_APU_AUDIO_WATCHDOG_H_
#define XENIA_APU_AUDIO_WATCHDOG_H_
#include <atomic>
#include <cstdint>
// Read-only diagnostics for "audio stops mid-mission and never recovers".
//
// The audio pipeline has four stages, each of which can die independently:
//
// guest XAudio callback -> SubmitFrame -> ring buffer -> ALSA write
// (guest_pumps) (frames_submitted) (alsa_writes)
// XMA decoding feeds the guest (xma_works)
//
// Each stage bumps a counter here. The watchdog thread in audio_system.cc
// samples them once a second and, when audio dies, reports which stage stopped
// advancing -- turning "no sound" into a named culprit.
//
// Note the APU worker runs the guest's audio callback IN-LINE
// (AudioSystem::WorkerThreadMain -> processor_->Execute). If that guest call
// ever blocks, pumping stops forever and audio can never recover, so we also
// track how long we have been inside guest code.
//
// Everything here is counters only: cvar-gated (--audio_watchdog), no
// behaviour change.
namespace xe {
namespace apu {
namespace watchdog {
// Pumps of the guest XAudio callback (AudioSystem worker).
inline std::atomic<uint64_t> guest_pumps{0};
// steady_clock microseconds at which the worker entered guest code; 0 = not
// currently inside the guest callback.
inline std::atomic<uint64_t> in_guest_callback_since_us{0};
// Frames the guest handed to the driver (AudioSystem::SubmitFrame).
inline std::atomic<uint64_t> frames_submitted{0};
// XMA decoder Work() calls that actually decoded something.
inline std::atomic<uint64_t> xma_works{0};
// ALSA: periods of real guest audio written, silence keepalive periods
// written, and underruns recovered.
inline std::atomic<uint64_t> alsa_writes{0};
inline std::atomic<uint64_t> alsa_silence{0};
inline std::atomic<uint64_t> alsa_xruns{0};
// Last observed snd_pcm_state_t (-1 = unknown / driver not ALSA).
inline std::atomic<int> alsa_state{-1};
// Why is the APU worker not pumping? Three very different causes look the same
// from outside the process, so distinguish them here:
// worker_loops == 0 && clients_in_use == 0 -> no client (guest unregistered)
// worker_loops == 0 && clients_in_use > 0 -> parked despite a client (pacing)
// worker_loops > 0 && pump_skips > 0 -> looping, but no free output slot
inline std::atomic<uint64_t> worker_loops{0};
inline std::atomic<uint64_t> pump_skips{0};
inline std::atomic<int> clients_in_use{-1};
inline std::atomic<uint64_t> register_calls{0};
inline std::atomic<uint64_t> unregister_calls{0};
// Exactly where the APU worker thread is sitting. A parked worker and a worker
// blocked on the kernel global lock are indistinguishable from outside the
// process (both are futex waits with zero context switches), so record it.
enum class WorkerPhase : int {
kStart = 0,
kAcquiringGlobalLock, // blocked here => a kernel lock is held elsewhere
kParkedNoClient, // blocked here => guest has no audio client
kPacingSleep, // normal: waiting for the next 5.33ms deadline
kInGuestCallback, // normal: running the game's mixer
kSubmitting,
};
inline std::atomic<WorkerPhase> worker_phase{WorkerPhase::kStart};
inline const char* WorkerPhaseName(WorkerPhase p) {
switch (p) {
case WorkerPhase::kStart:
return "start";
case WorkerPhase::kAcquiringGlobalLock:
return "ACQUIRING-GLOBAL-LOCK";
case WorkerPhase::kParkedNoClient:
return "PARKED-NO-CLIENT";
case WorkerPhase::kPacingSleep:
return "pacing";
case WorkerPhase::kInGuestCallback:
return "in-guest-callback";
case WorkerPhase::kSubmitting:
return "submitting";
default:
return "?";
}
}
} // namespace watchdog
} // namespace apu
} // namespace xe
#endif // XENIA_APU_AUDIO_WATCHDOG_H_

View File

@@ -9,7 +9,18 @@
#include "xenia/apu/xma_context_master.h"
#include <cstdio>
#include <cstring>
#include <mutex>
#include <set>
#include "xenia/base/cvar.h"
// [Phase-A / audio RE] Log each XMA stream's true params (channels/sample rate)
// + head bytes so raw sound.pak entries can be matched to real decode params.
DEFINE_bool(xma_param_probe, false,
"Log XMA per-stream params (channels/rate/head bytes) for audio RE.",
"APU");
#include "xenia/apu/xma_decoder.h"
#include "xenia/apu/xma_helpers.h"
@@ -317,6 +328,39 @@ void XmaContextMaster::Decode(XMA_CONTEXT_DATA* data) {
: nullptr;
uint8_t* current_input_buffer = data->current_buffer ? in1 : in0;
// [Phase-A / audio RE] Additive, cvar-gated probe: capture the true XMA
// per-stream parameters (channels + sample rate) the game supplies, keyed by
// the stream's head bytes so they can be matched back to a sound.pak entry
// offline. One line per unique stream (deduped on the first 8 bytes). No
// behaviour change — read-only, default-off.
if (cvars::xma_param_probe && in0 && data->input_buffer_0_valid &&
data->input_buffer_0_packet_count) {
static std::mutex xma_probe_mu;
static std::set<uint64_t> xma_probe_seen;
uint64_t key;
std::memcpy(&key, in0, sizeof(key));
bool fresh;
{
std::lock_guard<std::mutex> lock(xma_probe_mu);
fresh = xma_probe_seen.insert(key).second;
}
if (fresh) {
char head[65];
for (int i = 0; i < 32; ++i) {
std::snprintf(head + i * 2, 3, "%02x", in0[i]);
}
// Warning level so it surfaces even at the audio-safe --log_level=1 the
// interactive runner uses (Info/Debug would starve the audio thread).
XELOGW(
"XMA-PARAM stereo={} channels={} rate_id={} rate={} packets={} "
"head={}",
static_cast<uint32_t>(data->is_stereo),
data->is_stereo ? 2 : 1, static_cast<uint32_t>(data->sample_rate),
GetSampleRate(data->sample_rate),
static_cast<uint32_t>(data->input_buffer_0_packet_count), head);
}
}
// XELOGAPU("Processing context {} (offset {}, buffer {}, ptr {:p})", id(),
// data->input_buffer_read_offset, data->current_buffer,
// current_input_buffer);

View File

@@ -9,6 +9,7 @@
#include "xenia/apu/xma_decoder.h"
#include "xenia/apu/audio_watchdog.h"
#include "xenia/apu/xma_context.h"
#include "xenia/apu/xma_context_fake.h"
#include "xenia/apu/xma_context_master.h"
@@ -199,6 +200,7 @@ void XmaDecoder::WorkerThreadMain() {
for (uint32_t n = 0; n < kContextCount; n++) {
bool worked = contexts_[n]->Work();
if (worked) {
watchdog::xma_works.fetch_add(1, std::memory_order_relaxed);
contexts_[n]->SignalWorkDone();
}
did_work = did_work || worked;
@@ -409,6 +411,13 @@ void XmaDecoder::Pause() {
}
paused_ = true;
// Wake the worker so it actually observes paused_. When no context is
// decoding, the worker sleeps in an infinite Wait(work_event_) and would
// never re-check the flag, never signal pause_fence_, and this would block
// forever -- deadlocking whoever paused us (e.g. the crash handler), which
// left audio permanently dead while the game kept running.
work_event_->Set();
pause_fence_.Wait();
}

View File

@@ -0,0 +1,35 @@
/**
******************************************************************************
* Xenia : Xbox 360 Emulator Research Project *
******************************************************************************
* Copyright 2026 Ben Vanik. All rights reserved. *
* Released under the BSD license - see LICENSE in the root for more details. *
******************************************************************************
*/
#ifndef XENIA_BASE_GUEST_LIVENESS_H_
#define XENIA_BASE_GUEST_LIVENESS_H_
#include <atomic>
#include <cstdint>
// Guest-progress signal for the hang watchdog (--hang_watchdog_secs).
//
// A frozen guest is not the same as a frozen host: in the Project Sylpheed
// tutorial->menu freeze the host is fine (threads scheduled, GPU idle) while
// the guest main thread spins at 100% CPU on a memory flag that never changes.
// The cheapest honest "the game is still alive" signal is the guest presenting
// frames, i.e. calling VdSwap. If that stops, the game has stopped rendering.
//
// Counter only; no behaviour change.
namespace xe {
namespace liveness {
// Bumped by VdSwap (xboxkrnl_video.cc) -- the guest asking to present a frame.
inline std::atomic<uint64_t> guest_swaps{0};
} // namespace liveness
} // namespace xe
#endif // XENIA_BASE_GUEST_LIVENESS_H_

View File

@@ -26,8 +26,9 @@ namespace xe {
class Win32MappedMemory : public MappedMemory {
public:
// CreateFile returns INVALID_HANDLE_VALUE in case of failure.
// chrispy: made inline const to get around clang error
static inline constexpr HANDLE kFileHandleInvalid = INVALID_HANDLE_VALUE;
// INVALID_HANDLE_VALUE expands to a reinterpret_cast which MSVC accepts
// in constexpr as an extension; clang-cl rejects it per C++ standard.
static inline const HANDLE kFileHandleInvalid = INVALID_HANDLE_VALUE;
// CreateFileMapping returns nullptr in case of failure.
static constexpr HANDLE kMappingHandleInvalid = nullptr;

View File

@@ -14,6 +14,7 @@
#include "xenia/base/platform.h"
#include "xenia/base/threading_timer_queue.h"
#include <atomic>
#include <pthread.h>
#include <sched.h>
#include <semaphore.h>
@@ -981,11 +982,22 @@ class PosixCondition<Thread> final : public PosixConditionBase {
static void* ThreadStartRoutine(void* parameter);
bool signaled() const override { return signaled_; }
void post_execution() override {
// Reap exactly once. post_execution() runs on EVERY successful Wait(), and
// a thread object stays signaled forever once it has exited -- so every
// later wait on the same handle would pthread_join() a pthread_t that the
// first join already reaped and freed, faulting inside pthread_join. The
// guest does exactly this at mission teardown (several waiters on one
// thread handle), which crashed the waiting guest thread in a permanent
// fault loop: audio died and the game froze.
if (reaped_.exchange(true)) {
return;
}
if (thread_) {
pthread_join(thread_, nullptr);
}
sem_destroy(&suspend_sem_);
}
std::atomic<bool> reaped_{false};
pthread_t thread_;
pid_t tid_ = 0; // Kernel TID for setpriority() fallback
mutable bool fifo_failed_ = false; // True after SCHED_FIFO was rejected

View File

@@ -41,6 +41,30 @@
DEFINE_bool(debugprint_trap_log, false,
"Log debugprint traps to the active debugger", "CPU");
DEFINE_uint32(audit_jit_prolog_pc, 0,
"Guest function entry PC at which to emit one XELOGKERNEL line "
"per JIT-compiled entry. When non-zero, the x64 emitter inserts "
"a CallNative to AuditLogJitPrologArgs at the start of the JIT "
"body of the matching guest function. Dumps r3..r10, LR, and 64 "
"bytes at host(r3). Zero (default) disables the probe. Audit-059 "
"round 7+ JIT-prolog probe — generic PC-configurable variant.",
"Auditing");
DEFINE_uint32(audit_jit_prolog_mem_dump, 0,
"Audit-059 round 14 — paired memory-dump VA. When non-zero "
"AND audit_jit_prolog_pc fires, dereference the guest VA 3 "
"levels deep and emit one XELOGKERNEL line: addr -> val "
"(singleton instance), val -> vtable, vtable -> vtable[0] / "
"vtable[24]. Reads the singleton at [0x828E1F08], its vtable, "
"and its vtable[0] (first virtual method = bctrl target at "
"sub_822F1AA8+0x90). Zero (default) disables.",
"Auditing");
DEFINE_uint32(audit_jit_prolog_r3_bytes, 0x40,
"Audit-052 — number of bytes to dump from host(r3) on every "
"audit_jit_prolog_pc fire (capped at 256, 16-byte aligned). "
"Default 64 (existing behaviour). Set to 80 to capture the "
"audit-051 stack-local struct at sub_82452DC0's r31+96 "
"(probe sub_8245B000 entry where r3 IS the struct ptr).",
"Auditing");
DEFINE_bool(ignore_undefined_externs, true,
"Don't exit when an undefined extern is called.", "CPU");
DEFINE_bool(emit_source_annotations, false,
@@ -270,6 +294,17 @@ bool X64Emitter::Emit(HIRBuilder* builder, EmitFunctionInfo& func_info) {
count on no other code modifying it. mov(GetMembaseReg(),
qword[GetContextReg() + offsetof(ppc::PPCContext, virtual_membase)]);
*/
// Audit-059: PC-configurable JIT-prolog probe. Runtime-gated on the cvar
// audit_jit_prolog_pc (uint32; 0 disables). When non-zero and the current
// guest function's entry PC matches, emit a single CallNative to
// AuditLogJitPrologArgs that dumps r3..r10, LR, and 64 bytes at host(r3).
// Emits *before* any body instruction runs, so r3..r10 / LR in PPCContext
// still reflect the caller's args (no LOAD/STORE_CONTEXT has executed yet).
if (cvars::audit_jit_prolog_pc != 0u &&
current_guest_function_ == cvars::audit_jit_prolog_pc) {
extern uint64_t AuditLogJitPrologArgs(void* raw_context, uint64_t arg0);
CallNative(AuditLogJitPrologArgs, 0);
}
// Body.
auto block = builder->first_block();
synchronize_stack_on_next_instruction_ = false;
@@ -438,6 +473,82 @@ uint64_t TrapDebugBreak(void* raw_context, uint64_t address) {
return 0;
}
// Audit-059 JIT-prolog probe: dump r3..r10, LR, and 64 bytes at host(r3)
// when the guest hits the JIT-compiled entry of the function whose entry PC
// matches cvars::audit_jit_prolog_pc. Generic PC-configurable variant of the
// round-7 sub_824F7800 hook. The hook logs the current guest PC so multiple
// instrumentation campaigns can share log output.
uint64_t AuditLogJitPrologArgs(void* raw_context, uint64_t /*unused*/) {
auto* ctx = reinterpret_cast<ppc::PPCContext_s*>(raw_context);
uint32_t pc = static_cast<uint32_t>(cvars::audit_jit_prolog_pc);
uint32_t r3 = static_cast<uint32_t>(ctx->r[3]);
uint32_t r4 = static_cast<uint32_t>(ctx->r[4]);
uint32_t r5 = static_cast<uint32_t>(ctx->r[5]);
uint32_t r6 = static_cast<uint32_t>(ctx->r[6]);
uint32_t r7 = static_cast<uint32_t>(ctx->r[7]);
uint32_t r8 = static_cast<uint32_t>(ctx->r[8]);
uint32_t r9 = static_cast<uint32_t>(ctx->r[9]);
uint32_t r10 = static_cast<uint32_t>(ctx->r[10]);
uint32_t lr = static_cast<uint32_t>(ctx->lr);
uint32_t tid = ctx->thread_state ? ctx->thread_state->thread_id() : 0u;
XELOGKERNEL(
"AUDIT-HLC JitProlog pc={:08X} tid={:08X} r3={:08X} r4={:08X} r5={:08X} "
"r6={:08X} r7={:08X} r8={:08X} r9={:08X} r10={:08X} lr={:08X}",
pc, tid, r3, r4, r5, r6, r7, r8, r9, r10, lr);
// Dump N bytes at host(r3) if r3 looks like a plausible guest VA.
// N comes from cvar `audit_jit_prolog_r3_bytes` (default 64 = existing
// behaviour). Round up to a 16-byte multiple; cap at 256.
uint32_t r3_dump_bytes = static_cast<uint32_t>(cvars::audit_jit_prolog_r3_bytes);
if (r3_dump_bytes > 256) r3_dump_bytes = 256;
r3_dump_bytes = (r3_dump_bytes + 15) & ~15u;
if (r3 >= 0x10000 && r3 < 0xE0000000) {
uint8_t* host = ctx->TranslateVirtual(r3);
if (host) {
for (uint32_t off = 0; off < r3_dump_bytes; off += 16) {
uint32_t d0 = xe::load_and_swap<uint32_t>(host + off + 0);
uint32_t d1 = xe::load_and_swap<uint32_t>(host + off + 4);
uint32_t d2 = xe::load_and_swap<uint32_t>(host + off + 8);
uint32_t d3 = xe::load_and_swap<uint32_t>(host + off + 12);
XELOGKERNEL(
"AUDIT-HLC JitProlog pc={:08X} r3+{:02X}: {:08X} {:08X} {:08X} "
"{:08X}",
pc, off, d0, d1, d2, d3);
}
} else {
XELOGKERNEL("AUDIT-HLC JitProlog pc={:08X} r3 translate failed", pc);
}
} else {
XELOGKERNEL("AUDIT-HLC JitProlog pc={:08X} r3 out of VA range, skipping dump",
pc);
}
// Audit-059 round 14 — paired 3-level dereference. When
// `audit_jit_prolog_mem_dump` is set, read the singleton at that VA,
// its vtable, vtable[0] (first virtual method = bctrl target), and
// vtable[24] (slot 6 = silph chain method per round 9).
uint32_t mem_addr = static_cast<uint32_t>(cvars::audit_jit_prolog_mem_dump);
if (mem_addr != 0u && mem_addr >= 0x10000 && mem_addr < 0xE0000000) {
auto load_be32 = [&](uint32_t va) -> uint32_t {
if (va < 0x10000 || va >= 0xE0000000) return 0u;
uint8_t* h = ctx->TranslateVirtual(va);
if (!h) return 0u;
return xe::load_and_swap<uint32_t>(h);
};
uint32_t val = load_be32(mem_addr);
uint32_t vtable = val != 0u ? load_be32(val) : 0u;
uint32_t m0 = vtable != 0u ? load_be32(vtable) : 0u;
uint32_t m6 = vtable != 0u ? load_be32(vtable + 24u) : 0u;
XELOGKERNEL(
"AUDIT-MEM-READ addr={:08X} val={:08X} vtable={:08X} vtable[0]={:08X} "
"vtable[24]={:08X} pc={:08X} tid={:08X}",
mem_addr, val, vtable, m0, m6, pc, tid);
}
return 0;
}
void X64Emitter::Trap(uint16_t trap_type) {
switch (trap_type) {
case 20:

View File

@@ -57,3 +57,28 @@ DEFINE_bool(break_condition_truncate, true, "truncate value to 32-bits", "CPU");
DEFINE_bool(break_on_debugbreak, true, "int3 on JITed __debugbreak requests.",
"CPU");
// Phase A — expansive extraction tracing (game-data RE); see kernel/event_log.h.
// All default-off so instrument-current behaviour is unchanged when unused.
DEFINE_string(phase_a_event_log_path, "",
"Phase A: write schema-v1 JSONL event log to this path. "
"Empty (default) = disabled.",
"Audit");
DEFINE_bool(phase_a_event_log_mem_writes, false,
"Phase A: include mem.write events in the JSONL log. RESERVED — "
"not wired in this phase. Default false.",
"Audit");
DEFINE_bool(phase_a_trace_args, false,
"Phase A extraction: populate the kernel.call args (raw r3..r10) and "
"args_resolved (file I/O path/offset/length/buffer, alloc size, "
"handle names) fields, and emit file.read events. Default false.",
"Audit");
DEFINE_string(phase_a_hash_probe, "",
"Phase A extraction: CSV of guest PCs — RESERVED (the HIR/emitter "
"trap that drives it is not ported to instrument-current). Inert. "
"Default empty (off).",
"Audit");
DEFINE_bool(kernel_emit_contention, false,
"Phase D Stage 1: emit `contention.observed` events. Default false "
"(zero cost when disabled). Requires --phase_a_event_log_path.",
"Audit");

View File

@@ -35,4 +35,11 @@ DECLARE_bool(break_condition_truncate);
DECLARE_bool(break_on_debugbreak);
// Phase A — expansive extraction tracing; see kernel/event_log.h.
DECLARE_string(phase_a_event_log_path);
DECLARE_bool(phase_a_event_log_mem_writes);
DECLARE_bool(phase_a_trace_args);
DECLARE_string(phase_a_hash_probe);
DECLARE_bool(kernel_emit_contention);
#endif // XENIA_CPU_CPU_FLAGS_H_

View File

@@ -1568,18 +1568,101 @@ std::vector<uint32_t> XexModule::PreanalyzeCode() {
}
}
for (auto&& sec : pe_sections_) {
XELOGE("PESEC name={} addr={:08X} size={}", sec.name, sec.address,
sec.size);
}
// EH-CONFIRM: scan .rdata for MSVC C++ FuncInfo (magic 0x19930520) and, for
// any whose IP2State map points into the cache-flush chain, dump its catch
// TypeDescriptor names -- this tells us if the flush's out_of_range is
// CAUGHT (vs only cleaned up). Layout (Xenon, 32-bit full VAs, big-endian):
// FuncInfo: +0 magic, +4 maxState, +8 pUnwindMap, +12 nTryBlocks,
// +16 pTryBlockMap, +20 nIPMap, +24 pIP2StateMap
// TryBlockMapEntry(20B): +0 tryLow,+4 tryHigh,+8 catchHigh,+12 nCatches,
// +16 pHandlerArray
// HandlerType(16B): +0 adjectives,+4 pType(TypeDescriptor),+8 dispCatch,
// +12 addressOfHandler
// TypeDescriptor: +0 vfptr,+4 spare,+8 name(mangled, e.g. ".?AV...@")
// IP2StateMapEntry(8B): +0 Ip(VA), +4 State
{
auto rd = [&](uint32_t va) -> uint32_t {
auto p = memory()->TranslateVirtual<xe::be<uint32_t>*>(va);
return p ? (uint32_t)*p : 0;
};
auto valid = [](uint32_t va) { return va >= 0x82000000 && va < 0x82920000; };
auto rdata = GetPESection(".rdata");
if (rdata) {
uint32_t magic_hits = 0, raw_logged = 0;
for (uint32_t a = rdata->address; a < rdata->address + rdata->size;
a += 4) {
if (rd(a) != 0x19930522u) continue; // FuncInfo magic (newer MSVC)
uint32_t nTry = rd(a + 12), pTry = rd(a + 16);
uint32_t nIP = rd(a + 20), pIP = rd(a + 24);
++magic_hits;
if (!valid(pIP) || nIP > 4096 || !nIP) continue;
// which function? use first + last IP in the IP2State map.
uint32_t firstIp = rd(pIP), lastIp = rd(pIP + (nIP - 1) * 8);
if (raw_logged < 6) {
XELOGE("EH-RAW FuncInfo@{:08X} nTry={} ip[{:08X}..{:08X}]", a, nTry,
firstIp, lastIp);
++raw_logged;
}
// Log EVERY function that has a CATCH (nTry>=1) across the whole
// binary, so any stack frame can be mapped to a catch. (cleanup-only
// nTry=0 frames just re-propagate -- skip them to cut noise.)
if (!nTry || !valid(pTry) || nTry > 64) continue;
std::string cat;
for (uint32_t t = 0; t < nTry; ++t) {
uint32_t te = pTry + t * 20;
uint32_t nCatch = rd(te + 12), pH = rd(te + 16);
for (uint32_t c = 0; c < nCatch && c < 32 && valid(pH); ++c) {
uint32_t pType = rd(pH + c * 16 + 4);
uint32_t dispCatchObj = rd(pH + c * 16 + 8);
uint32_t funclet = rd(pH + c * 16 + 12);
std::string nm;
if (!pType) {
nm = "...";
} else {
auto s = memory()->TranslateVirtual<const char*>(pType + 8);
for (int i = 0; s && i < 96 && s[i]; ++i) nm.push_back(s[i]);
}
cat += fmt::format(" catch({} obj@fp+{:X} funclet={:08X})", nm,
dispCatchObj, funclet);
}
}
XELOGE("EH-CONFIRM FuncInfo@{:08X} ip[{:08X}..{:08X}] nTry={}{}", a,
firstIp, lastIp, nTry, cat);
}
XELOGE("EH-CONFIRM scan done; magic_hits={}", magic_hits);
}
}
auto pdata = this->GetPESection(".pdata");
XELOGE("PDATA-SCAN reached; pdata_section={}",
pdata ? "FOUND" : "NULL");
if (pdata) {
uint32_t* pdata_base =
(uint32_t*)this->memory()->TranslateVirtual(pdata->address);
uint32_t n_pdata_entries = pdata->raw_size / 8;
XELOGE("PDATA-SCAN addr={:08X} raw_size={} entries={}", pdata->address,
pdata->raw_size, n_pdata_entries);
for (uint32_t i = 0; i < n_pdata_entries; ++i) {
uint32_t funcaddr = xe::load_and_swap<uint32_t>(&pdata_base[i * 2]);
if (funcaddr >= low_address_ && funcaddr <= highest_exec_addr) {
add_new_func(funcaddr);
// DIAGNOSTIC: dump the unwind Flags word for the cache-flush region
// (Xbox360 PPC RUNTIME_FUNCTION: BeginAddress, then Flags with
// PrologLen:8, FuncLen:22, 32bit:1, ExceptionFlag:1[bit31]). The
// ExceptionFlag tells us whether a function has a language handler
// (C++ catch/cleanup) -- i.e. whether the game can CATCH the flush's
// out_of_range throw. Remove once the A-vs-B fix decision is settled.
if (funcaddr >= 0x82459000u && funcaddr <= 0x8245B200u) {
uint32_t flags = xe::load_and_swap<uint32_t>(&pdata_base[i * 2 + 1]);
XELOGE("PDATA fn={:08X} flags={:08X} funclen={} excflag={}",
funcaddr, flags, (flags >> 2) & 0x3FFFFF, (flags & 1));
}
} else {
// we hit 0 for func addr, that means we're done
break;

View File

@@ -30,10 +30,13 @@
#include "xenia/base/platform.h"
#include "xenia/base/string.h"
#include "xenia/base/system.h"
#include "xenia/base/guest_liveness.h"
#include "xenia/cpu/backend/code_cache.h"
#include "xenia/cpu/backend/null_backend.h"
#include "xenia/cpu/cpu_flags.h"
#include "xenia/cpu/ppc/ppc_context.h"
#include "xenia/cpu/thread_state.h"
#include "xenia/kernel/xthread.h"
#include "xenia/gpu/command_processor.h"
#include "xenia/gpu/graphics_system.h"
#include "xenia/hid/input_driver.h"
@@ -92,6 +95,12 @@ DEFINE_int32(priority_class, 0,
"values: 0 - Normal, 1 - Above normal, 2 - High",
"General");
DEFINE_int32(hang_watchdog_secs, 0,
"If the guest stops presenting frames for this many seconds, dump "
"every guest thread's registers and guest call stack to the log "
"(0 = off). Diagnostics only; requires no debugger.",
"General");
namespace xe {
using namespace xe::literals;
@@ -166,6 +175,13 @@ Emulator::Emulator(const std::filesystem::path& command_line,
Emulator::~Emulator() {
// Note that we delete things in the reverse order they were initialized.
if (hang_watchdog_running_) {
hang_watchdog_running_ = false;
if (hang_watchdog_thread_.joinable()) {
hang_watchdog_thread_.join();
}
}
// Give the systems time to shutdown before we delete them.
if (graphics_system_) {
graphics_system_->Shutdown();
@@ -308,6 +324,53 @@ X_STATUS Emulator::Setup(
XELOGI("{}: Initializing Kernel...", __func__);
// Shared kernel state.
kernel_state_ = std::make_unique<xe::kernel::KernelState>(this);
// Hang watchdog (--hang_watchdog_secs, diagnostics, default off).
//
// The tutorial->menu freeze is a GUEST hang, not a host deadlock: the host
// keeps running while a guest thread spins on a memory flag nobody sets. A
// host debugger is awkward to attach to that (ptrace is locked down, and the
// window may die before we get to it), but the emulator can simply read its
// own guest state. When the guest stops presenting frames, dump every guest
// thread's registers plus a walk of its guest stack -- enough to name the
// spinning function and the address it is polling.
if (cvars::hang_watchdog_secs > 0) {
hang_watchdog_running_ = true;
hang_watchdog_thread_ = std::thread([this]() {
xe::threading::set_name("Hang Watchdog");
const uint64_t limit =
static_cast<uint64_t>(cvars::hang_watchdog_secs);
uint64_t last_swaps = 0;
uint64_t stalled_s = 0;
bool dumped = false;
while (hang_watchdog_running_) {
std::this_thread::sleep_for(std::chrono::seconds(1));
if (!hang_watchdog_running_) {
break;
}
const uint64_t swaps =
xe::liveness::guest_swaps.load(std::memory_order_relaxed);
if (swaps != last_swaps) {
last_swaps = swaps;
if (stalled_s >= limit) {
XELOGE("HANG-WD guest recovered after {}s (swaps resumed)",
stalled_s);
}
stalled_s = 0;
dumped = false;
continue;
}
// Nothing presented for another second.
if (++stalled_s < limit || dumped) {
continue;
}
dumped = true; // one dump per hang, not one per second
DumpGuestHang(stalled_s);
}
});
XELOGI("HANG-WD armed: dump guest state after {}s without a frame",
cvars::hang_watchdog_secs);
}
#define LOAD_KERNEL_MODULE(t) \
static_cast<void>(kernel_state_->LoadKernelModule<kernel::t>())
// HLE kernel modules.
@@ -532,6 +595,72 @@ Emulator::FileSignatureType Emulator::GetFileSignature(
return FileSignatureType::Unknown;
}
void Emulator::DumpGuestHang(uint64_t stalled_s) {
// Read-only autopsy of a hung guest. Racy by nature (the threads keep
// running); that is fine -- a spinning thread's stack pointer and link
// register are stable, which is exactly what we need.
constexpr uint32_t kCodeLo = 0x82000000u;
constexpr uint32_t kCodeHi = 0x84000000u;
XELOGE("=========================== HANG-WD ===========================");
XELOGE("HANG-WD no frame presented for {}s -- dumping guest threads.",
stalled_s);
auto threads =
kernel_state()->object_table()->GetObjectsByType<kernel::XThread>();
for (const auto& thread : threads) {
if (!thread || !thread->is_guest_thread()) {
continue;
}
auto thread_state = thread->thread_state();
if (!thread_state) {
continue;
}
auto ctx = thread_state->context();
if (!ctx) {
continue;
}
XELOGE(
"HANG-WD tid={:04X} '{}' running={} lr={:08X} ctr={:08X} r1={:08X}",
thread->thread_id(), thread->name(), thread->is_running(),
static_cast<uint32_t>(ctx->lr), static_cast<uint32_t>(ctx->ctr),
static_cast<uint32_t>(ctx->r[1]));
XELOGE(
"HANG-WD r3={:08X} r4={:08X} r5={:08X} r6={:08X} r7={:08X} "
"r8={:08X} r9={:08X} r10={:08X} r11={:08X} r12={:08X}",
static_cast<uint32_t>(ctx->r[3]), static_cast<uint32_t>(ctx->r[4]),
static_cast<uint32_t>(ctx->r[5]), static_cast<uint32_t>(ctx->r[6]),
static_cast<uint32_t>(ctx->r[7]), static_cast<uint32_t>(ctx->r[8]),
static_cast<uint32_t>(ctx->r[9]), static_cast<uint32_t>(ctx->r[10]),
static_cast<uint32_t>(ctx->r[11]), static_cast<uint32_t>(ctx->r[12]));
// Walk the guest stack: PowerPC back chain -- [sp] = caller sp,
// [sp+4] = saved LR. Stop on anything that stops looking like a frame.
std::string frames;
uint32_t sp = static_cast<uint32_t>(ctx->r[1]);
for (int depth = 0; depth < 16; ++depth) {
if (sp < 0x1000 || !memory()->TranslateVirtual(sp)) {
break;
}
auto frame = memory()->TranslateVirtual(sp);
const uint32_t next_sp = xe::load_and_swap<uint32_t>(frame);
const uint32_t saved_lr = xe::load_and_swap<uint32_t>(frame + 4);
if (saved_lr >= kCodeLo && saved_lr < kCodeHi) {
frames += fmt::format(" {:08X}", saved_lr);
}
if (next_sp <= sp || next_sp - sp > 0x10000) {
break; // not a plausible back chain anymore
}
sp = next_sp;
}
if (!frames.empty()) {
XELOGE("HANG-WD guest stack:{}", frames);
}
}
XELOGE("HANG-WD ==== resolve these PCs with: zq.py fn <pc> ====");
}
X_STATUS Emulator::LaunchPath(const std::filesystem::path& path) {
X_STATUS mount_result = X_STATUS_SUCCESS;

View File

@@ -10,11 +10,13 @@
#ifndef XENIA_EMULATOR_H_
#define XENIA_EMULATOR_H_
#include <atomic>
#include <cstddef>
#include <cstdint>
#include <functional>
#include <optional>
#include <string>
#include <thread>
#include <vector>
#include "xenia/apu/audio_media_player.h"
@@ -309,6 +311,12 @@ class Emulator {
xe::Delegate<> on_exit;
private:
// Hang watchdog (--hang_watchdog_secs): when the guest stops presenting
// frames, dump every guest thread's registers + guest stack. Diagnostics.
void DumpGuestHang(uint64_t stalled_s);
std::atomic<bool> hang_watchdog_running_{false};
std::thread hang_watchdog_thread_;
enum : uint64_t { EmulatorFlagDisclaimerAcknowledged = 1ULL << 0 };
static uint64_t GetPersistentEmulatorFlags();
static void SetPersistentEmulatorFlags(uint64_t new_flags);

View File

@@ -9,6 +9,9 @@
#include "xenia/gpu/command_processor.h"
#include <fstream>
#include <unordered_set>
#include "third_party/fmt/include/fmt/format.h"
#include "xenia/base/byte_stream.h"
#include "xenia/base/clock.h"
@@ -18,6 +21,8 @@
#include "xenia/gpu/gpu_flags.h"
#include "xenia/gpu/graphics_system.h"
#include "xenia/gpu/packet_disassembler.h"
#include "xenia/gpu/registers.h"
#include "xenia/gpu/shader.h"
#include "xenia/gpu/sampler_info.h"
#include "xenia/gpu/texture_info.h"
#include "xenia/gpu/xenos_zpd_report.h"
@@ -77,6 +82,14 @@ DEFINE_string(
UPDATE_from_string(readback_resolve, 2025, 12, 4, 21, "fast");
DEFINE_bool(
log_draws, false,
"Reverse-engineering aid: write each distinct draw's primitive type, index "
"buffer, and per-stream vertex declaration (stream base/stride + per-element "
"format/offset) to xenia_re_draws.log in the working directory. For decoding "
"game mesh formats against GPU ground truth.",
"GPU");
DEFINE_bool(
readback_memexport, false,
"Read data written by memory export in shaders on the CPU. "
@@ -88,6 +101,171 @@ DEFINE_bool(
namespace xe {
namespace gpu {
namespace {
// Short readable name for a guest vertex element format (RE logging only).
const char* ReVertexFormatName(xenos::VertexFormat f) {
switch (f) {
case xenos::VertexFormat::k_32_FLOAT: return "f32";
case xenos::VertexFormat::k_32_32_FLOAT: return "f32x2";
case xenos::VertexFormat::k_32_32_32_FLOAT: return "f32x3";
case xenos::VertexFormat::k_32_32_32_32_FLOAT: return "f32x4";
case xenos::VertexFormat::k_16_16_FLOAT: return "f16x2";
case xenos::VertexFormat::k_16_16_16_16_FLOAT: return "f16x4";
case xenos::VertexFormat::k_16_16: return "s16x2";
case xenos::VertexFormat::k_16_16_16_16: return "s16x4";
case xenos::VertexFormat::k_8_8_8_8: return "8888";
case xenos::VertexFormat::k_2_10_10_10: return "2_10_10_10";
case xenos::VertexFormat::k_10_11_11: return "10_11_11";
case xenos::VertexFormat::k_11_11_10: return "11_11_10";
case xenos::VertexFormat::k_32: return "u32";
case xenos::VertexFormat::k_32_32: return "u32x2";
case xenos::VertexFormat::k_32_32_32_32: return "u32x4";
default: return "?";
}
}
} // namespace
void CommandProcessor::LogDrawForRE(uint32_t vgt_draw_initiator_value,
const IndexBufferInfo* index_buffer_info) {
if (!cvars::log_draws) {
return;
}
static std::mutex re_mutex;
static std::ofstream re_out;
static std::unordered_set<uint64_t> re_seen;
std::lock_guard<std::mutex> lock(re_mutex);
if (!re_out.is_open()) {
re_out.open("xenia_re_draws.log", std::ios::out | std::ios::trunc);
XELOGI("[RE-DRAW] logging distinct draws to xenia_re_draws.log");
}
if (!re_out.is_open()) {
return;
}
reg::VGT_DRAW_INITIATOR init;
init.value = vgt_draw_initiator_value;
Shader* vs = active_vertex_shader_;
// De-dup by the VERTEX-DECLARATION FINGERPRINT (shader + primitive type +
// per-stream element formats/offsets), NOT by buffer address. Animated UI
// that redraws the same mesh format into fresh buffers every frame therefore
// collapses to a single record, keeping the logging near-free — while every
// distinct mesh format (the player plane, each weapon) is still captured once.
uint64_t sig = 1469598103934665603ull; // FNV-ish seed
auto mix = [&sig](uint64_t v) { sig = (sig ^ v) * 1099511628211ull; };
mix(uint64_t(init.prim_type));
if (vs) {
mix(vs->ucode_data_hash());
}
bool analyzed = vs && vs->is_ucode_analyzed();
if (analyzed) {
for (const auto& binding : vs->vertex_bindings()) {
mix(binding.fetch_constant);
mix(binding.stride_words);
for (const auto& attr : binding.attributes) {
mix(uint64_t(attr.fetch_instr.attributes.data_format));
mix(uint64_t(uint32_t(attr.fetch_instr.attributes.offset)));
}
}
} else {
mix(uint64_t(init.num_indices));
}
if (!re_seen.insert(sig).second) {
return;
}
// Safety cap on distinct formats, so a pathological title can't grow the log
// (and the working set) without bound.
if (re_seen.size() > 4096) {
return;
}
re_out << fmt::format("DRAW prim={} indices={} src={} ",
uint32_t(init.prim_type), uint32_t(init.num_indices),
uint32_t(init.source_select));
if (index_buffer_info) {
re_out << fmt::format(
"index[base=0x{:08X} count={} fmt={} endian={} len={}] ",
index_buffer_info->guest_base, index_buffer_info->count,
index_buffer_info->format == xenos::IndexFormat::kInt16 ? "u16" : "u32",
uint32_t(index_buffer_info->endianness), index_buffer_info->length);
} else {
re_out << "index[auto] ";
}
if (vs) {
re_out << fmt::format("vs=0x{:016X}", vs->ucode_data_hash());
}
re_out << "\n";
if (analyzed) {
for (const auto& binding : vs->vertex_bindings()) {
xenos::xe_gpu_vertex_fetch_t fetch =
register_file_->GetVertexFetch(binding.fetch_constant);
re_out << fmt::format(
" stream fc={} base=0x{:08X} stride_words={} size_words={} "
"endian={} type={}\n",
binding.fetch_constant, uint32_t(fetch.address) << 2,
binding.stride_words, uint32_t(fetch.size), uint32_t(fetch.endian),
uint32_t(fetch.type));
for (const auto& attr : binding.attributes) {
const auto& a = attr.fetch_instr.attributes;
re_out << fmt::format(
" attr fmt={}({}) offset_words={} stride_words={} signed={} "
"int={} exp_adjust={}\n",
uint32_t(a.data_format), ReVertexFormatName(a.data_format), a.offset,
a.stride, a.is_signed ? 1 : 0, a.is_integer ? 1 : 0, a.exp_adjust);
}
}
// Dump the first few vertex POSITIONS from guest memory. The f32 position
// bytes are identical between the guest buffer and the on-disc .xpr (only
// f16 pairs are rearranged on load), so these values can be searched for in
// the file to locate a mesh whose in-file offset is otherwise unknown
// (e.g. multi-XBG7 body meshes). See docs/re/structures/xbg7-mesh.md.
if (!vs->vertex_bindings().empty()) {
const auto& binding = vs->vertex_bindings()[0];
xenos::xe_gpu_vertex_fetch_t fetch =
register_file_->GetVertexFetch(binding.fetch_constant);
// Position = the first f32×3 attribute (offset is in dwords).
int32_t pos_off_bytes = -1;
for (const auto& attr : binding.attributes) {
if (attr.fetch_instr.attributes.data_format ==
xenos::VertexFormat::k_32_32_32_FLOAT) {
pos_off_bytes = attr.fetch_instr.attributes.offset * 4;
break;
}
}
uint32_t stride = binding.stride_words * 4;
uint32_t vbase = uint32_t(fetch.address) << 2;
uint32_t buf_bytes = uint32_t(fetch.size) * 4;
if (pos_off_bytes >= 0 && stride > 0) {
uint32_t max_v = buf_bytes / stride;
uint32_t n = max_v < 8 ? max_v : 8;
re_out << " positions:";
for (uint32_t v = 0; v < n; ++v) {
uint32_t a = vbase + v * stride + uint32_t(pos_off_bytes);
const uint8_t* p = memory_->TranslatePhysical<const uint8_t*>(a);
if (!p) {
break;
}
auto be_f32 = [](const uint8_t* q) {
uint32_t w = (uint32_t(q[0]) << 24) | (uint32_t(q[1]) << 16) |
(uint32_t(q[2]) << 8) | uint32_t(q[3]);
float f;
std::memcpy(&f, &w, 4);
return f;
};
re_out << fmt::format(" ({:.4f},{:.4f},{:.4f})", be_f32(p),
be_f32(p + 4), be_f32(p + 8));
}
re_out << "\n";
}
}
} else {
re_out << " (vertex shader not analyzed yet)\n";
}
re_out.flush();
}
// This should be written completely differently with support for different
// types.
void SaveGPUSetting(GPUSetting setting, uint64_t value) {

View File

@@ -446,6 +446,13 @@ class CommandProcessor {
}
virtual bool IssueCopy() { return false; }
// Reverse-engineering aid (cvar `log_draws`): dump the guest's exact
// primitive type + index buffer + per-stream vertex declaration for each
// distinct draw to a dedicated file, for decoding game mesh formats.
// No-op unless the cvar is enabled. Defined in command_processor.cc.
void LogDrawForRE(uint32_t vgt_draw_initiator_value,
const IndexBufferInfo* index_buffer_info);
// "Actual" is for the command processor thread, to be read by the
// implementations.
SwapPostEffect GetActualSwapPostEffect() const {

View File

@@ -13,6 +13,8 @@
#include "xenia/base/clock.h"
#include "xenia/base/logging.h"
#include "xenia/base/math.h"
#include "xenia/base/memory.h"
#include "xenia/base/string_util.h"
#include "xenia/base/profiling.h"
#include "xenia/base/threading.h"
#include "xenia/config.h"
@@ -36,6 +38,32 @@ DEFINE_bool(
"runtime spikes and freezes when playing the game not for the first time.",
"GPU");
// Audit memory-watch: poll-based value-change logger for arbitrary guest VAs.
// Reads the configured guest virtual address(es) once per vblank (per frame)
// from inside GraphicsSystem::MarkVblank() and emits one XELOGKERNEL
// "AUDIT-MEM-WATCH" line whenever the read value changes vs the previous
// frame. Greppable on the same log stream as AUDIT-HLC / AUDIT-MEM-READ.
// Default empty => disabled => zero overhead. Mechanism is poll/value-change
// (NOT a write-trap), so it captures WHEN a value changes (vblank index +
// emulator instruction count) but NOT the writer guest-PC. To find the writer
// PC, pair this with audit_jit_prolog_pc on the suspected writer function.
DEFINE_string(
audit_mem_watch_addr, "",
"Audit memory-watch — comma-separated list of guest virtual addresses "
"(hex, e.g. \"0x40d09a40\" or \"0x40d09a40,0x40929c00\") to poll once per "
"vblank. On every value change vs the previous frame, emit one "
"XELOGKERNEL AUDIT-MEM-WATCH line (watched VA, old value, new value, "
"vblank index, instruction count). Empty (default) disables the watch. "
"Poll-based value-change log: tells you WHEN a value changes, not the "
"writer PC.",
"Auditing");
DEFINE_uint32(
audit_mem_watch_size, 4,
"Audit memory-watch — number of bytes to read at each watched VA (1, 2, "
"4, or 8). Read big-endian (guest byte order) and compared as a 64-bit "
"value. Default 4.",
"Auditing");
namespace xe {
namespace gpu {
@@ -333,12 +361,117 @@ void GraphicsSystem::DispatchInterruptCallback(uint32_t source, uint32_t cpu) {
interrupt_callback_data_, source, cpu);
}
// Audit memory-watch poll. Called once per vblank from MarkVblank(). Parses
// the comma-separated VA list from cvars::audit_mem_watch_addr exactly once
// (cached), then reads each VA (big-endian, audit_mem_watch_size bytes) and
// logs an AUDIT-MEM-WATCH line on every value change vs the previous frame.
// Poll/value-change mechanism: captures WHEN, not the writer PC. Zero work
// when the cvar is empty.
static void AuditMemWatchPoll(Memory* memory, uint64_t vblank_index) {
struct WatchEntry {
uint32_t va;
uint64_t last_value;
bool have_last;
};
static std::vector<WatchEntry> entries;
static std::string parsed_spec;
static bool parse_failed = false;
const std::string& spec = cvars::audit_mem_watch_addr;
if (spec.empty()) {
return;
}
// (Re)parse only when the cvar string changes (set once at startup).
if (spec != parsed_spec) {
parsed_spec = spec;
entries.clear();
parse_failed = false;
size_t start = 0;
while (start <= spec.size()) {
size_t comma = spec.find(',', start);
std::string tok = spec.substr(
start, comma == std::string::npos ? std::string::npos : comma - start);
// Trim whitespace.
while (!tok.empty() && (tok.front() == ' ' || tok.front() == '\t'))
tok.erase(tok.begin());
while (!tok.empty() && (tok.back() == ' ' || tok.back() == '\t'))
tok.pop_back();
if (!tok.empty()) {
uint32_t va = 0;
try {
va = static_cast<uint32_t>(std::stoul(tok, nullptr, 16));
} catch (...) {
XELOGKERNEL("AUDIT-MEM-WATCH bad VA token '{}' in '{}'", tok, spec);
parse_failed = true;
va = 0;
}
if (va != 0) {
entries.push_back({va, 0, false});
}
}
if (comma == std::string::npos) break;
start = comma + 1;
}
XELOGKERNEL("AUDIT-MEM-WATCH armed: {} address(es), size={} bytes",
entries.size(),
static_cast<uint32_t>(cvars::audit_mem_watch_size));
}
if (entries.empty()) {
return;
}
(void)parse_failed;
uint32_t size = static_cast<uint32_t>(cvars::audit_mem_watch_size);
for (auto& e : entries) {
if (e.va < 0x10000 || e.va >= 0xE0000000) {
continue;
}
uint8_t* host = memory->TranslateVirtual(e.va);
if (!host) {
continue;
}
uint64_t value = 0;
switch (size) {
case 1:
value = *host;
break;
case 2:
value = xe::load_and_swap<uint16_t>(host);
break;
case 8:
value = xe::load_and_swap<uint64_t>(host);
break;
case 4:
default:
value = xe::load_and_swap<uint32_t>(host);
break;
}
if (!e.have_last) {
e.have_last = true;
e.last_value = value;
XELOGKERNEL(
"AUDIT-MEM-WATCH va={:08X} init={:016X} vblank={} (first read)",
e.va, value, vblank_index);
continue;
}
if (value != e.last_value) {
XELOGKERNEL(
"AUDIT-MEM-WATCH va={:08X} old={:016X} new={:016X} vblank={}",
e.va, e.last_value, value, vblank_index);
e.last_value = value;
}
}
}
void GraphicsSystem::MarkVblank() {
SCOPE_profile_cpu_f("gpu");
// Increment vblank counter (so the game sees us making progress).
command_processor_->increment_counter();
// Audit memory-watch (poll-based; no-op unless audit_mem_watch_addr set).
AuditMemWatchPoll(memory_, command_processor_->counter());
// TODO(benvanik): we shouldn't need to do the dispatch here, but there's
// something wrong and the CP will block waiting for code that
// needs to be run in the interrupt.

View File

@@ -1152,6 +1152,11 @@ bool COMMAND_PROCESSOR::ExecutePacketType3Draw(
uint32_t(vgt_draw_initiator.prim_type),
uint32_t(vgt_draw_initiator.source_select));
}
// Reverse-engineering aid (no-op unless the `log_draws` cvar is set):
// record the guest's primitive type + index buffer + vertex declaration.
// Placed after IssueDraw so the vertex shader has been analyzed.
COMMAND_PROCESSOR::LogDrawForRE(
vgt_draw_initiator.value, is_indexed ? &index_buffer_info : nullptr);
}
}

View File

@@ -0,0 +1,709 @@
/**
******************************************************************************
* Xenia : Xbox 360 Emulator Research Project *
******************************************************************************
* Phase A event-log emitter — see event_log.h and schema-v1.md.
******************************************************************************
*/
#include "xenia/kernel/event_log.h"
#include <atomic>
#include <chrono>
#include <cstdio>
#include <cstring>
#include <mutex>
#include <string>
#include <unordered_map>
#include "third_party/fmt/include/fmt/format.h"
#include "xenia/base/cvar.h"
#include "xenia/cpu/ppc/ppc_context.h"
#include "xenia/kernel/kernel.h"
#include "xenia/kernel/kernel_state.h"
#include "xenia/kernel/util/object_table.h"
#include "xenia/kernel/xfile.h"
#include "xenia/kernel/xthread.h"
#include "xenia/memory.h"
DECLARE_string(phase_a_event_log_path);
DECLARE_bool(kernel_emit_contention);
DECLARE_bool(phase_a_trace_args);
DECLARE_string(phase_a_hash_probe);
namespace xe {
namespace kernel {
namespace phase_a {
namespace {
// Cached enabled state, computed lazily from cvar (cheap fast-path).
std::atomic<int> g_state{0}; // 0=untouched, 1=enabled, 2=disabled
std::FILE* g_file = nullptr;
std::mutex g_file_mu;
std::once_flag g_init_once;
// Per-thread monotonic event index (key for the diff tool).
// Phase C+15-α: per-tid (not per-host-thread). Multiple host threads
// can emit with tid=0 (boot + XThread bootstrap before guest tid is
// assigned), and a thread_local counter aliased across host threads
// produces duplicate `tid_event_idx` values, breaking the diff tool's
// monotonicity invariant. Use a tid-keyed map guarded by a mutex.
std::unordered_map<uint32_t, uint64_t> g_tid_counters;
std::mutex g_tid_counters_mu;
uint64_t NextTidEventIdx(uint32_t tid) {
std::lock_guard<std::mutex> lock(g_tid_counters_mu);
auto& c = g_tid_counters[tid];
uint64_t v = c;
c = v + 1;
return v;
}
uint64_t PeekTidEventIdxLocked(uint32_t tid) {
std::lock_guard<std::mutex> lock(g_tid_counters_mu);
auto it = g_tid_counters.find(tid);
return it == g_tid_counters.end() ? 0 : it->second;
}
// Process-start ns for the host_ns field. Captured on first use; debug only.
std::chrono::steady_clock::time_point g_t0;
std::once_flag g_t0_once;
void EnsureT0() {
std::call_once(g_t0_once,
[]() { g_t0 = std::chrono::steady_clock::now(); });
}
int64_t HostNsSinceStart() {
EnsureT0();
auto now = std::chrono::steady_clock::now();
return std::chrono::duration_cast<std::chrono::nanoseconds>(now - g_t0)
.count();
}
void OpenIfNeeded() {
std::call_once(g_init_once, []() {
const std::string& path = cvars::phase_a_event_log_path;
if (path.empty()) {
g_state.store(2, std::memory_order_release);
return;
}
g_file = std::fopen(path.c_str(), "wb");
if (!g_file) {
g_state.store(2, std::memory_order_release);
return;
}
g_state.store(1, std::memory_order_release);
// Write the schema header as the first line — synthetic tid=0.
auto header = fmt::format(
"{{\"schema_version\":1,\"engine\":\"canary\",\"kind\":\"schema_version"
"\",\"tid\":0,\"tid_event_idx\":0,\"guest_cycle\":0,\"host_ns\":{},\""
"deterministic\":true,\"payload\":{{\"version\":1,\"emitter_build\":\""
"canary-phaseA\"}}}}\n",
HostNsSinceStart());
std::fwrite(header.data(), 1, header.size(), g_file);
std::fflush(g_file);
});
}
uint32_t CurrentTid() {
// Phase C+15-α: AddHandle / RemoveHandle hooks can fire from boot
// code (XEX loader, kernel-state init) BEFORE any XThread exists.
// `XThread::GetCurrentThreadId` asserts in that case. Use the
// safe `TryGetCurrentThread` accessor (returns null instead of
// asserting). Return 0 (synthetic "no-thread" tid) when not in a
// guest thread, matching ours's `scheduler.current == None`
// semantics during boot init.
XThread* t = XThread::TryGetCurrentThread();
if (!t) {
return 0;
}
return t->guest_object<X_KTHREAD>()->thread_id;
}
void WriteLine(const std::string& line) {
std::lock_guard<std::mutex> lock(g_file_mu);
if (!g_file) return;
std::fwrite(line.data(), 1, line.size(), g_file);
std::fputc('\n', g_file);
// Flush every line so a crash mid-boot still produces a useful prefix.
std::fflush(g_file);
}
// Common-fields prefix. Caller appends `,\"payload\":{...}}`.
// kind, tid, tid_event_idx, guest_cycle=0 (canary has no kernel-layer cycle),
// host_ns, deterministic, engine.
std::string CommonPrefix(const char* kind, uint32_t tid, uint64_t idx,
bool deterministic) {
return fmt::format(
"{{\"schema_version\":1,\"engine\":\"canary\",\"kind\":\"{}\",\"tid\":{},"
"\"tid_event_idx\":{},\"guest_cycle\":0,\"host_ns\":{},\"deterministic\":"
"{}",
kind, tid, idx, HostNsSinceStart(), deterministic ? "true" : "false");
}
// Escape a JSON string. Keep it minimal — kernel names are ASCII.
std::string EscapeJson(const char* s) {
if (!s) return "null";
std::string out;
out.reserve(std::strlen(s) + 2);
for (const char* p = s; *p; ++p) {
unsigned char c = static_cast<unsigned char>(*p);
if (c == '\\' || c == '"') {
out.push_back('\\');
out.push_back(static_cast<char>(c));
} else if (c == '\n') {
out += "\\n";
} else if (c == '\r') {
out += "\\r";
} else if (c == '\t') {
out += "\\t";
} else if (c < 0x20) {
out += fmt::format("\\u{:04x}", c);
} else {
out.push_back(static_cast<char>(c));
}
}
return out;
}
} // namespace
bool IsEnabled() {
int s = g_state.load(std::memory_order_acquire);
if (s == 0) {
OpenIfNeeded();
s = g_state.load(std::memory_order_acquire);
}
return s == 1;
}
uint64_t PeekTidEventIdx() { return PeekTidEventIdxLocked(CurrentTid()); }
uint64_t ComputeSemanticId(uint32_t create_site_pc, uint32_t creating_tid,
uint64_t tid_event_idx_at_creation,
uint32_t object_type) {
uint8_t bytes[4 + 4 + 8 + 4];
auto put_u32 = [&](size_t off, uint32_t v) {
bytes[off + 0] = static_cast<uint8_t>(v & 0xFF);
bytes[off + 1] = static_cast<uint8_t>((v >> 8) & 0xFF);
bytes[off + 2] = static_cast<uint8_t>((v >> 16) & 0xFF);
bytes[off + 3] = static_cast<uint8_t>((v >> 24) & 0xFF);
};
auto put_u64 = [&](size_t off, uint64_t v) {
for (int i = 0; i < 8; ++i)
bytes[off + i] = static_cast<uint8_t>((v >> (i * 8)) & 0xFF);
};
put_u32(0, create_site_pc);
put_u32(4, creating_tid);
put_u64(8, tid_event_idx_at_creation);
put_u32(16, object_type);
uint64_t h = 0xCBF29CE484222325ULL;
for (size_t i = 0; i < sizeof(bytes); ++i) {
h ^= bytes[i];
h *= 0x100000001B3ULL;
}
return h;
}
void EmitSchemaHeader() {
if (!IsEnabled()) return;
// tid=0, tid_event_idx=0, deterministic=true. NOT consuming the per-tid
// counter (the header is on a synthetic tid 0).
std::string line = fmt::format(
"{{\"schema_version\":1,\"engine\":\"canary\",\"kind\":\"schema_version"
"\",\"tid\":0,\"tid_event_idx\":0,\"guest_cycle\":0,\"host_ns\":{},\""
"deterministic\":true,\"payload\":{{\"version\":1,\"emitter_build\":\""
"canary-phaseA\"}}}}",
HostNsSinceStart());
WriteLine(line);
}
void EmitImportCall(const char* module_name, uint16_t ordinal,
const char* fn_name) {
if (!IsEnabled()) return;
uint32_t tid = CurrentTid();
uint64_t idx = NextTidEventIdx(tid);
std::string line = CommonPrefix("import.call", tid, idx, true);
line += fmt::format(
",\"payload\":{{\"module\":\"{}\",\"ord\":{},\"name\":\"{}\"}}}}",
EscapeJson(module_name), ordinal, EscapeJson(fn_name));
WriteLine(line);
}
void EmitKernelCall(const char* name) {
if (!IsEnabled()) return;
uint32_t tid = CurrentTid();
uint64_t idx = NextTidEventIdx(tid);
std::string line = CommonPrefix("kernel.call", tid, idx, true);
line += fmt::format(",\"payload\":{{\"name\":\"{}\",\"args\":{{}},\"args_"
"resolved\":{{}}}}}}",
EscapeJson(name));
WriteLine(line);
}
// Phase C+10 schema-v1 extension: emit a `kernel.call` event whose
// `args_resolved` field includes a `"path"` entry. The path string is
// the canonical post-prefix-strip form (forward slashes, leading
// device prefix removed). When `path` is null/empty, degrades to the
// existing empty-args_resolved form so output is byte-identical to
// the pre-extension behavior for unknown export names.
void EmitKernelCallWithPath(const char* name, const char* path) {
if (!IsEnabled()) return;
uint32_t tid = CurrentTid();
uint64_t idx = NextTidEventIdx(tid);
std::string line = CommonPrefix("kernel.call", tid, idx, true);
if (path && *path) {
line += fmt::format(
",\"payload\":{{\"name\":\"{}\",\"args\":{{}},\"args_resolved\":"
"{{\"path\":\"{}\"}}}}}}",
EscapeJson(name), EscapeJson(path));
} else {
line += fmt::format(",\"payload\":{{\"name\":\"{}\",\"args\":{{}},\"args_"
"resolved\":{{}}}}}}",
EscapeJson(name));
}
WriteLine(line);
}
void EmitKernelReturn(const char* name, uint64_t return_value) {
if (!IsEnabled()) return;
uint32_t tid = CurrentTid();
uint64_t idx = NextTidEventIdx(tid);
std::string line = CommonPrefix("kernel.return", tid, idx, true);
line += fmt::format(
",\"payload\":{{\"name\":\"{}\",\"return_value\":{},\"status\":\"0x{:08x}"
"\",\"side_effects\":[]}}}}",
EscapeJson(name), return_value, static_cast<uint32_t>(return_value));
WriteLine(line);
}
void EmitHandleCreate(uint64_t semantic_id, uint32_t object_type,
uint32_t raw_handle_id, const char* object_name) {
if (!IsEnabled()) return;
uint32_t tid = CurrentTid();
uint64_t idx = NextTidEventIdx(tid);
std::string line = CommonPrefix("handle.create", tid, idx, true);
if (object_name && *object_name) {
line += fmt::format(
",\"payload\":{{\"handle_semantic_id\":\"{:016x}\",\"object_type\":{},"
"\"object_name\":\"{}\",\"raw_handle_id\":\"0x{:08x}\"}}}}",
semantic_id, object_type, EscapeJson(object_name), raw_handle_id);
} else {
line += fmt::format(
",\"payload\":{{\"handle_semantic_id\":\"{:016x}\",\"object_type\":{},"
"\"object_name\":null,\"raw_handle_id\":\"0x{:08x}\"}}}}",
semantic_id, object_type, raw_handle_id);
}
WriteLine(line);
}
void EmitHandleDestroy(uint64_t semantic_id, uint32_t raw_handle_id,
uint32_t prior_refcount) {
if (!IsEnabled()) return;
uint32_t tid = CurrentTid();
uint64_t idx = NextTidEventIdx(tid);
std::string line = CommonPrefix("handle.destroy", tid, idx, true);
line += fmt::format(
",\"payload\":{{\"handle_semantic_id\":\"{:016x}\",\"raw_handle_id\":\""
"0x{:08x}\",\"prior_refcount\":{}}}}}",
semantic_id, raw_handle_id, prior_refcount);
WriteLine(line);
}
void EmitThreadCreate(uint64_t semantic_id, uint32_t parent_tid,
uint32_t entry_pc, uint32_t ctx_ptr, uint32_t priority,
uint32_t affinity, uint32_t stack_size, bool suspended) {
if (!IsEnabled()) return;
uint32_t tid = CurrentTid();
uint64_t idx = NextTidEventIdx(tid);
std::string line = CommonPrefix("thread.create", tid, idx, true);
line += fmt::format(
",\"payload\":{{\"handle_semantic_id\":\"{:016x}\",\"parent_tid\":{},"
"\"entry_pc\":\"0x{:08x}\",\"ctx_ptr\":\"0x{:08x}\",\"priority\":{},"
"\"affinity\":{},\"stack_size\":{},\"suspended\":{}}}}}",
semantic_id, parent_tid, entry_pc, ctx_ptr, priority, affinity,
stack_size, suspended ? "true" : "false");
WriteLine(line);
}
void EmitThreadExit(uint32_t exit_code) {
if (!IsEnabled()) return;
uint32_t tid = CurrentTid();
uint64_t idx = NextTidEventIdx(tid);
std::string line = CommonPrefix("thread.exit", tid, idx, true);
line += fmt::format(",\"payload\":{{\"exit_code\":{}}}}}", exit_code);
WriteLine(line);
}
void EmitWaitBegin(const uint64_t* handles_semantic_ids, uint32_t count,
int64_t timeout_ns, bool alertable, bool wait_all) {
if (!IsEnabled()) return;
uint32_t tid = CurrentTid();
uint64_t idx = NextTidEventIdx(tid);
std::string line = CommonPrefix("wait.begin", tid, idx, true);
std::string ids = "[";
for (uint32_t i = 0; i < count; ++i) {
if (i) ids += ",";
ids += fmt::format("\"{:016x}\"", handles_semantic_ids[i]);
}
ids += "]";
line += fmt::format(
",\"payload\":{{\"handles_semantic_ids\":{},\"timeout_ns\":{},"
"\"alertable\":{},\"wait_type\":\"{}\"}}}}",
ids, timeout_ns, alertable ? "true" : "false",
wait_all ? "all" : "any");
WriteLine(line);
}
void EmitWaitEnd(uint32_t status, uint64_t woken_by_semantic_id_or_zero) {
if (!IsEnabled()) return;
uint32_t tid = CurrentTid();
uint64_t idx = NextTidEventIdx(tid);
std::string line = CommonPrefix("wait.end", tid, idx, false);
if (woken_by_semantic_id_or_zero) {
line += fmt::format(
",\"payload\":{{\"status\":\"0x{:08x}\",\"woken_by_semantic_id\":\""
"{:016x}\",\"wait_duration_cycles\":0}}}}",
status, woken_by_semantic_id_or_zero);
} else {
line += fmt::format(
",\"payload\":{{\"status\":\"0x{:08x}\",\"woken_by_semantic_id\":null,"
"\"wait_duration_cycles\":0}}}}",
status);
}
WriteLine(line);
}
// ===== Phase C+15-α — Handle semantic ID registry =====
namespace {
std::unordered_map<uint32_t, uint64_t> g_handle_sids;
std::mutex g_handle_sids_mu;
} // namespace
void RegisterHandleSemanticId(uint32_t raw_handle_id, uint64_t sid) {
if (!IsEnabled()) return;
std::lock_guard<std::mutex> lock(g_handle_sids_mu);
g_handle_sids[raw_handle_id] = sid;
}
uint64_t LookupHandleSemanticId(uint32_t raw_handle_id) {
std::lock_guard<std::mutex> lock(g_handle_sids_mu);
auto it = g_handle_sids.find(raw_handle_id);
return it == g_handle_sids.end() ? 0 : it->second;
}
uint64_t ForgetHandleSemanticId(uint32_t raw_handle_id) {
std::lock_guard<std::mutex> lock(g_handle_sids_mu);
auto it = g_handle_sids.find(raw_handle_id);
if (it == g_handle_sids.end()) return 0;
uint64_t sid = it->second;
g_handle_sids.erase(it);
return sid;
}
uint64_t EmitHandleCreateAuto(uint32_t create_site_pc, uint32_t object_type,
uint32_t raw_handle_id,
const char* object_name) {
if (!IsEnabled()) return 0;
uint32_t tid = CurrentTid();
uint64_t idx_at_creation = PeekTidEventIdxLocked(tid);
uint64_t sid =
ComputeSemanticId(create_site_pc, tid, idx_at_creation, object_type);
RegisterHandleSemanticId(raw_handle_id, sid);
EmitHandleCreate(sid, object_type, raw_handle_id, object_name);
return sid;
}
void EmitHandleDestroyAuto(uint32_t raw_handle_id, uint32_t prior_refcount) {
if (!IsEnabled()) return;
uint64_t sid = ForgetHandleSemanticId(raw_handle_id);
EmitHandleDestroy(sid, raw_handle_id, prior_refcount);
}
// ===== Phase C+18 — Shared-global SIDs =====
uint64_t ComputeSharedGlobalSemanticId(uint32_t pointer, uint32_t object_type) {
// Reuse the same FNV-1a recipe as `ComputeSemanticId` but with inputs
// chosen to be scheduling-invariant:
// create_site_pc = kSharedGlobalSidMarker (distinguishes from regular SIDs)
// creating_tid = 0
// tid_event_idx_at_creation = pointer (as u64)
// object_type = object_type
// Matches `event_log.rs::semantic_id_shared_global` byte-for-byte.
return ComputeSemanticId(kSharedGlobalSidMarker, 0,
static_cast<uint64_t>(pointer), object_type);
}
void EmitHandleCreateSharedGlobal(uint32_t pointer, uint32_t object_type,
uint32_t raw_handle_id,
const char* object_name) {
if (!IsEnabled()) return;
uint64_t sid = ComputeSharedGlobalSemanticId(pointer, object_type);
RegisterHandleSemanticId(raw_handle_id, sid);
EmitHandleCreate(sid, object_type, raw_handle_id, object_name);
}
// Phase C+18: per-host-thread flag that the AddHandle hook checks to
// skip its `EmitHandleCreateAuto` call for XObjects synthesized by
// `XObject::GetNativeObject` (a single boolean — the global critical
// region is held across the GetNativeObject body so re-entrancy isn't
// expected).
namespace {
thread_local bool t_in_get_native_object = false;
} // namespace
void SetInGetNativeObject(bool active) { t_in_get_native_object = active; }
bool IsInGetNativeObject() { return t_in_get_native_object; }
// ===== Phase D Stage 1 — contention.observed =====
void EmitContentionObserved(uint32_t cs_guest_ptr, bool contended) {
// Two-gate fast path: cvar OFF is the default and must be byte-identical
// to pre-Stage-1 canary. The cvar is checked first to short-circuit even
// when the phase A event log itself is enabled (Stage 0/baseline cold
// runs may have event log on but contention emit off).
if (!cvars::kernel_emit_contention) return;
if (!IsEnabled()) return;
uint32_t tid = CurrentTid();
uint64_t idx = NextTidEventIdx(tid);
uint64_t site_sid =
ComputeSharedGlobalSemanticId(cs_guest_ptr, kObjCriticalSection);
std::string line = CommonPrefix("contention.observed", tid, idx, true);
line += fmt::format(
",\"payload\":{{\"cs_ptr\":\"0x{:08x}\",\"site_sid\":\"{:016x}\","
"\"contended\":{}}}}}",
cs_guest_ptr, site_sid, contended ? "true" : "false");
WriteLine(line);
}
// ── Expansive extraction tracing (game-data RE) ────────────────────────────
// All gated by `phase_a_trace_args` / `phase_a_hash_probe` (default off), so
// with those unset the JSONL output is byte-identical to the diff-schema form.
// kernel.call with populated `args` (raw r3..r10) and `args_resolved`
// (currently the resolved file path, when known). `ppc_context` is a
// PPCContext* passed as void* to keep the header free of the PPC include.
void EmitKernelCallArgs(const char* name, void* ppc_context,
const char* resolved_path) {
if (!IsEnabled()) return;
auto* ctx = reinterpret_cast<::xe::cpu::ppc::PPCContext*>(ppc_context);
uint32_t tid = CurrentTid();
uint64_t idx = NextTidEventIdx(tid);
std::string line = CommonPrefix("kernel.call", tid, idx, true);
std::string args;
if (ctx) {
args = fmt::format(
"\"r3\":{},\"r4\":{},\"r5\":{},\"r6\":{},\"r7\":{},\"r8\":{},\"r9\":{},"
"\"r10\":{}",
ctx->r[3], ctx->r[4], ctx->r[5], ctx->r[6], ctx->r[7], ctx->r[8],
ctx->r[9], ctx->r[10]);
}
std::string resolved;
if (resolved_path && *resolved_path) {
resolved = fmt::format("\"path\":\"{}\"", EscapeJson(resolved_path));
}
line += fmt::format(
",\"payload\":{{\"name\":\"{}\",\"args\":{{{}}},\"args_resolved\":{{{}}}}}}}",
EscapeJson(name), args, resolved);
WriteLine(line);
}
// file.read — a guest read from an open file handle. `path` is resolved from
// the handle via the object table; `offset` is the requested byte offset.
void EmitFileRead(uint32_t handle, const char* path, uint64_t offset,
uint32_t length, uint32_t buffer_va) {
if (!IsEnabled()) return;
uint32_t tid = CurrentTid();
uint64_t idx = NextTidEventIdx(tid);
std::string line = CommonPrefix("file.read", tid, idx, true);
line += fmt::format(
",\"payload\":{{\"handle\":\"0x{:08x}\",\"path\":\"{}\",\"offset\":{},"
"\"length\":{},\"buffer_va\":\"0x{:08x}\"}}}}",
handle, EscapeJson(path), offset, length, buffer_va);
WriteLine(line);
}
// guest.call — fired by the guest-PC hash probe (Tier 3). `arg_str` is r3
// dereferenced as a guest C-string (the archive path being hashed).
void EmitGuestCall(uint32_t pc, const char* arg_str, uint32_t r3, uint32_t r4,
uint32_t r5, uint32_t r6) {
if (!IsEnabled()) return;
uint32_t tid = CurrentTid();
uint64_t idx = NextTidEventIdx(tid);
std::string line = CommonPrefix("guest.call", tid, idx, true);
line += fmt::format(
",\"payload\":{{\"pc\":\"0x{:08x}\",\"arg_str\":\"{}\",\"r3\":\"0x{:08x}\","
"\"r4\":\"0x{:08x}\",\"r5\":\"0x{:08x}\",\"r6\":\"0x{:08x}\"}}}}",
pc, EscapeJson(arg_str), r3, r4, r5, r6);
WriteLine(line);
}
} // namespace phase_a
// Bridge entry points referenced from shim_utils.h. Defined here so the
// template-heavy header does not need to include event_log.h directly.
namespace shim {
namespace phase_a_bridge {
namespace {
// Phase C+10: read an OBJECT_ATTRIBUTES* guest address and return the
// raw ANSI_STRING path (trimmed). Empty/null returns std::string().
// Mirrors ours's `path::object_attributes_raw_name`.
std::string ReadObjectAttributesRawName(uint32_t obj_attrs_ptr) {
if (!obj_attrs_ptr) return std::string();
auto* ks = ::xe::kernel::KernelState::shared();
if (!ks) return std::string();
auto* memory = ks->memory();
if (!memory) return std::string();
auto* obj_attrs =
memory->TranslateVirtual<::xe::kernel::X_OBJECT_ATTRIBUTES*>(
obj_attrs_ptr);
if (!obj_attrs) return std::string();
uint32_t name_ptr = obj_attrs->name_ptr;
if (!name_ptr) return std::string();
auto* ansi =
memory->TranslateVirtual<::xe::kernel::X_ANSI_STRING*>(name_ptr);
if (!ansi) return std::string();
uint16_t length = ansi->length;
uint32_t buffer = ansi->pointer;
if (!length || !buffer) return std::string();
auto* bytes = memory->TranslateVirtual<const char*>(buffer);
if (!bytes) return std::string();
std::string raw(bytes, length);
// Strip trailing NULs that some callers include in the byte count.
while (!raw.empty() && raw.back() == '\0') raw.pop_back();
// Trim whitespace (mirror canary's `string_util::trim`).
auto first = raw.find_first_not_of(" \t\r\n");
auto last = raw.find_last_not_of(" \t\r\n");
if (first == std::string::npos) return std::string();
return raw.substr(first, last - first + 1);
}
// Phase C+11 — read an `X_FILE_RENAME_INFORMATION` buffer's rename
// target ANSI_STRING. Layout per `info/file.h:79-83` (16 bytes):
// offset 0 be<u32> replace_existing
// offset 4 be<u32> root_dir_handle
// offset 8 X_ANSI_STRING { u16 Length, u16 MaxLength, u32 Buffer }
// Caller is expected to check `info_length >= 16` before invoking.
// Mirrors ours's `path::file_rename_information_raw_target`.
std::string ReadFileRenameInformationRawTarget(uint32_t info_ptr,
uint32_t info_length) {
if (!info_ptr || info_length < 16) return std::string();
auto* ks = ::xe::kernel::KernelState::shared();
if (!ks) return std::string();
auto* memory = ks->memory();
if (!memory) return std::string();
auto* ansi = memory->TranslateVirtual<::xe::kernel::X_ANSI_STRING*>(
info_ptr + 8);
if (!ansi) return std::string();
uint16_t length = ansi->length;
uint32_t buffer = ansi->pointer;
if (!length || !buffer) return std::string();
auto* bytes = memory->TranslateVirtual<const char*>(buffer);
if (!bytes) return std::string();
std::string raw(bytes, length);
while (!raw.empty() && raw.back() == '\0') raw.pop_back();
auto first = raw.find_first_not_of(" \t\r\n");
auto last = raw.find_last_not_of(" \t\r\n");
if (first == std::string::npos) return std::string();
return raw.substr(first, last - first + 1);
}
// Phase C+10/C+11: known path-bearing exports. Returns the empty string
// for any export whose name is not in the set OR whose OBJECT_ATTRIBUTES*
// arg is null. Argument positions verified against canary's
// `xboxkrnl_io.cc` / `xboxkrnl_io_info.cc` signatures.
std::string ResolvePathArg(const char* name,
::xe::cpu::ppc::PPCContext* ctx) {
if (!name || !ctx) return std::string();
// r3..r7 only — narrow the dispatch by first char to keep the
// hot-path branch table tight.
if (name[0] != 'N') return std::string();
// NtQueryFullAttributesFile: r3 = obj_attrs
if (std::strcmp(name, "NtQueryFullAttributesFile") == 0) {
return ReadObjectAttributesRawName(static_cast<uint32_t>(ctx->r[3]));
}
// NtOpenSymbolicLinkObject: r4 = obj_attrs
if (std::strcmp(name, "NtOpenSymbolicLinkObject") == 0) {
return ReadObjectAttributesRawName(static_cast<uint32_t>(ctx->r[4]));
}
// NtCreateFile, NtOpenFile: r5 = obj_attrs
if (std::strcmp(name, "NtCreateFile") == 0 ||
std::strcmp(name, "NtOpenFile") == 0) {
return ReadObjectAttributesRawName(static_cast<uint32_t>(ctx->r[5]));
}
// NtSetInformationFile: r5 = info_ptr, r6 = info_length, r7 = info_class.
// Surface the rename target path when info_class==10
// (XFileRenameInformation). Mirrors ours's C+11 dispatch in
// `crates/xenia-kernel/src/state.rs` call_export.
if (std::strcmp(name, "NtSetInformationFile") == 0 &&
static_cast<uint32_t>(ctx->r[7]) == 10) {
return ReadFileRenameInformationRawTarget(
static_cast<uint32_t>(ctx->r[5]),
static_cast<uint32_t>(ctx->r[6]));
}
return std::string();
}
} // namespace
bool Enabled() { return ::xe::kernel::phase_a::IsEnabled(); }
void EmitImportAndCall(const char* module_name, uint16_t ord,
const char* name) {
::xe::kernel::phase_a::EmitImportCall(module_name, ord, name);
::xe::kernel::phase_a::EmitKernelCall(name);
}
// Tier 2: for NtReadFile, resolve the handle to its file path (object table)
// and emit a file.read event with the requested byte offset / length / buffer.
// NtReadFile(r3=FileHandle, .., r8=Buffer, r9=Length, r10=ByteOffset*).
void MaybeEmitFileRead(const char* name, ::xe::cpu::ppc::PPCContext* ctx) {
if (!ctx || std::strcmp(name, "NtReadFile") != 0) return;
auto* ks = ::xe::kernel::KernelState::shared();
if (!ks) return;
auto* memory = ks->memory();
uint32_t handle = static_cast<uint32_t>(ctx->r[3]);
uint32_t buffer = static_cast<uint32_t>(ctx->r[8]);
uint32_t length = static_cast<uint32_t>(ctx->r[9]);
uint32_t byteoff_ptr = static_cast<uint32_t>(ctx->r[10]);
uint64_t offset = 0;
if (byteoff_ptr && memory) {
auto* p = memory->TranslateVirtual<::xe::be<uint64_t>*>(byteoff_ptr);
if (p) offset = static_cast<uint64_t>(*p);
}
std::string path;
auto file = ks->object_table()->LookupObject<::xe::kernel::XFile>(handle);
if (file) path = file->path();
::xe::kernel::phase_a::EmitFileRead(handle, path.c_str(), offset, length,
buffer);
}
void EmitImportAndCallWithCtx(const char* module_name, uint16_t ord,
const char* name, void* ppc_context) {
::xe::kernel::phase_a::EmitImportCall(module_name, ord, name);
auto* ctx = reinterpret_cast<::xe::cpu::ppc::PPCContext*>(ppc_context);
std::string path = ResolvePathArg(name, ctx);
if (cvars::phase_a_trace_args) {
// Extraction mode: raw GPR args + resolved path, plus file.read detail.
::xe::kernel::phase_a::EmitKernelCallArgs(
name, ppc_context, path.empty() ? nullptr : path.c_str());
MaybeEmitFileRead(name, ctx);
return;
}
if (!path.empty()) {
::xe::kernel::phase_a::EmitKernelCallWithPath(name, path.c_str());
} else {
::xe::kernel::phase_a::EmitKernelCall(name);
}
}
void EmitReturn(const char* name, uint64_t return_value) {
::xe::kernel::phase_a::EmitKernelReturn(name, return_value);
}
} // namespace phase_a_bridge
} // namespace shim
} // namespace kernel
} // namespace xe

View File

@@ -0,0 +1,191 @@
/**
******************************************************************************
* Xenia : Xbox 360 Emulator Research Project *
******************************************************************************
* Phase A event-log emitter. Cvar-gated (default off). Schema v1.
* Companion: xenia-rs/audit-runs/phase-a-diff-harness/schema-v1.md
******************************************************************************
*/
#ifndef XENIA_KERNEL_EVENT_LOG_H_
#define XENIA_KERNEL_EVENT_LOG_H_
#include <cstdint>
namespace xe {
namespace kernel {
namespace phase_a {
// Object-type codes (must match ours's enum exactly — see schema-v1.md).
enum ObjectType : uint32_t {
kObjUnknown = 0x00,
kObjEvent = 0x01,
kObjMutant = 0x02,
kObjSemaphore = 0x03,
kObjTimer = 0x04,
kObjThread = 0x05,
kObjFile = 0x06,
kObjIoCompletion = 0x07,
kObjModule = 0x08,
kObjEnumState = 0x09,
kObjSection = 0x0A,
kObjNotification = 0x0B,
// Phase D Stage 1: pseudo-type used as the `object_type` input to
// `ComputeSharedGlobalSemanticId` for RTL_CRITICAL_SECTION pointers. CS
// is not a regular `XObject` (it lives as a guest-memory struct, not a
// handle-tabled kernel object), but the `site_sid` field of
// `contention.observed` reuses the shared-global SID recipe so the
// Stage-3 manifest loader can compute the same SID in both engines.
kObjCriticalSection = 0x0C,
};
// Fast bool check (default off). Inlinable so we can guard hot paths cheaply.
bool IsEnabled();
// Emitted once at startup if enabled (first line of the JSONL).
void EmitSchemaHeader();
// FNV-1a 64-bit identity (see schema-v1.md). Both engines compute identically.
uint64_t ComputeSemanticId(uint32_t create_site_pc, uint32_t creating_tid,
uint64_t tid_event_idx_at_creation,
uint32_t object_type);
// One emit per imported kernel function invocation. Emitted by the export
// trampoline before the kernel.call event.
void EmitImportCall(const char* module_name, uint16_t ordinal,
const char* fn_name);
// Kernel call entry / return. args/args_resolved are deferred to a later
// phase; v1 emits the name + return value only (sufficient for the diff
// tool to align by sequence).
void EmitKernelCall(const char* name);
// Phase C+10: schema-v1 extension — emit kernel.call whose
// `args_resolved` field carries a resolved `"path"` value (see
// schema-v1.md kernel.call payload). `path == nullptr || *path == '\0'`
// degrades to the existing empty-args_resolved form.
void EmitKernelCallWithPath(const char* name, const char* path);
void EmitKernelReturn(const char* name, uint64_t return_value);
// Handle lifecycle. raw_handle_id is engine-local; the diff key is the
// FNV-1a semantic id.
void EmitHandleCreate(uint64_t semantic_id, uint32_t object_type,
uint32_t raw_handle_id, const char* object_name);
void EmitHandleDestroy(uint64_t semantic_id, uint32_t raw_handle_id,
uint32_t prior_refcount);
// Thread create/exit. parent_tid is the caller; entry_pc is the spawned
// thread's first instruction.
void EmitThreadCreate(uint64_t semantic_id, uint32_t parent_tid,
uint32_t entry_pc, uint32_t ctx_ptr, uint32_t priority,
uint32_t affinity, uint32_t stack_size, bool suspended);
void EmitThreadExit(uint32_t exit_code);
// Wait begin/end. handles_count + handles_semantic_ids array.
void EmitWaitBegin(const uint64_t* handles_semantic_ids, uint32_t count,
int64_t timeout_ns, bool alertable, bool wait_all);
void EmitWaitEnd(uint32_t status, uint64_t woken_by_semantic_id_or_zero);
// Returns the next per-tid event index (post-increment). Useful for
// `tid_event_idx_at_creation` capture before calling ComputeSemanticId.
uint64_t PeekTidEventIdx();
// Phase C+15-α: handle-semantic-ID registry. Maps raw handle id ->
// FNV-1a 64-bit SID assigned at handle creation, so subsequent
// `handle.destroy` / `wait.begin` / etc. events can emit a stable
// cross-engine identity. No-op when event_log is disabled.
void RegisterHandleSemanticId(uint32_t raw_handle_id, uint64_t sid);
uint64_t LookupHandleSemanticId(uint32_t raw_handle_id);
uint64_t ForgetHandleSemanticId(uint32_t raw_handle_id);
// Convenience: at handle creation time, peek tid_event_idx, compute
// the FNV-1a SID, register it for `raw_handle_id`, and emit a
// `handle.create` event. Returns the SID. `create_site_pc` is set to
// 0 by callers that cannot resolve a guest LR — both engines agree
// on `0` for canonicalization at v1.1.
uint64_t EmitHandleCreateAuto(uint32_t create_site_pc, uint32_t object_type,
uint32_t raw_handle_id,
const char* object_name);
// Convenience: forget mapping + emit `handle.destroy` with the
// previously registered SID.
void EmitHandleDestroyAuto(uint32_t raw_handle_id, uint32_t prior_refcount);
// Phase C+18: marker constant used as `create_site_pc` in shared-global
// SID computation. Both engines must use exactly this value. See
// schema-v1.md §"Shared-global SIDs".
constexpr uint32_t kSharedGlobalSidMarker = 0xC01AB005;
// Phase C+18: compute the scheduling-invariant SID for a
// **process-global** kernel dispatcher (canary's
// `XObject::GetNativeObject` lazy-wrap on first guest-thread touch).
// Keyed on `(SHARED_GLOBAL_SID_MARKER, 0, pointer, object_type)` so the
// SID depends only on the object's identity, not on the scheduling order.
uint64_t ComputeSharedGlobalSemanticId(uint32_t pointer, uint32_t object_type);
// Phase C+18: emit `handle.create` with a scheduling-invariant SID for
// a process-global kernel dispatcher synthesized by
// `XObject::GetNativeObject`. The SID is computed via
// `ComputeSharedGlobalSemanticId(pointer, object_type)` so the same
// dispatcher yields the same SID in both engines regardless of which
// guest thread happens to be the first toucher. `raw_handle_id` is the
// XObject's allocated handle; `pointer` is the guest dispatcher
// (`X_DISPATCH_HEADER*`) pointer (used only to derive the SID).
//
// Caller MUST avoid the regular AddHandle emit for this XObject (set
// the in-flight thread-local marker around the `new XEvent` /
// `new XSemaphore` ctor and have the AddHandle hook short-circuit).
void EmitHandleCreateSharedGlobal(uint32_t pointer, uint32_t object_type,
uint32_t raw_handle_id,
const char* object_name);
// Phase C+18: thread-local flag indicating the current host thread is
// inside `XObject::GetNativeObject` lazy-wrap, which constructs a new
// XEvent/XSemaphore wrapper for a process-global guest dispatcher.
// `AddHandle` consults this to skip its regular per-thread
// `handle.create` emit; the explicit shared-global emit happens in
// `GetNativeObject` after `StashHandle`. The flag is a single
// host-thread-local bool — re-entrancy is not expected (the global
// critical region is held throughout).
void SetInGetNativeObject(bool active);
bool IsInGetNativeObject();
// Phase D Stage 1: emit a `contention.observed` event from
// `RtlEnterCriticalSection_entry` when the spin-loop is exhausted and
// control falls through to `xeKeWaitForSingleObject`. The Stage-2 manifest
// builder filters on `contended=true` and keys on `(tid, tid_event_idx)`
// so the Stage-3 replay loop in ours can park its own `rtl_enter_critical_section`
// at exactly the same per-tid ordinal.
//
// `cs_guest_ptr` is the guest VA of the `X_RTL_CRITICAL_SECTION` (the
// argument to RtlEnterCS). `site_sid` is computed via
// `ComputeSharedGlobalSemanticId(cs_guest_ptr, kObjCriticalSection)` so
// both engines agree on the SID for the same CS pointer.
//
// Gated on `cvars::kernel_emit_contention && IsEnabled()`. Default
// behavior (cvar off) is byte-identical to pre-Stage-1 canary.
void EmitContentionObserved(uint32_t cs_guest_ptr, bool contended);
// ── Expansive extraction tracing (game-data RE; gated by phase_a_trace_args /
// phase_a_hash_probe, default off) ─────────────────────────────────────────
// kernel.call with populated `args` (raw r3..r10 from the PPCContext, passed
// as void*) and `args_resolved` (the resolved file path when known).
void EmitKernelCallArgs(const char* name, void* ppc_context,
const char* resolved_path);
// file.read — a guest read from an open file handle (path resolved from the
// handle via the object table). Enables correlating .pak reads to TOC entries.
void EmitFileRead(uint32_t handle, const char* path, uint64_t offset,
uint32_t length, uint32_t buffer_va);
// guest.call — emitted by the guest-PC hash probe: `arg_str` is r3 dereferenced
// as a guest C-string (the archive path being hashed). Used to recover the
// custom IPFB/IDXD name-hash by observing (string -> hash) pairs.
void EmitGuestCall(uint32_t pc, const char* arg_str, uint32_t r3, uint32_t r4,
uint32_t r5, uint32_t r6);
} // namespace phase_a
} // namespace kernel
} // namespace xe
#endif // XENIA_KERNEL_EVENT_LOG_H_

View File

@@ -14,3 +14,12 @@ DEFINE_bool(headless, false,
"UI");
DEFINE_bool(log_high_frequency_kernel_calls, false,
"Log kernel calls with the kHighFrequency tag.", "Logging");
DEFINE_bool(audit_handle_lifecycle, false,
"Emit XELOGKERNEL on Event/Semaphore/Wait lifecycle "
"(create/set/wait/complete). Audit oracle probe — off by default.",
"Auditing");
DEFINE_uint32(audit_track_event_handle, 0,
"If non-zero and AUDIT-HLC enabled, log underlying X_KEVENT "
"guest VA whenever NtCreateEvent returns this handle. "
"Audit round-24 oracle probe.",
"Auditing");

View File

@@ -13,5 +13,7 @@
DECLARE_bool(headless);
DECLARE_bool(log_high_frequency_kernel_calls);
DECLARE_bool(audit_handle_lifecycle);
DECLARE_uint32(audit_track_event_handle);
#endif // XENIA_KERNEL_KERNEL_FLAGS_H_

View File

@@ -9,12 +9,21 @@
#include <ranges>
#include <atomic>
#include <chrono>
#include <cstdio>
#include <thread>
#if defined(__linux__)
#include <malloc.h>
#endif
#include "xenia/kernel/kernel_state.h"
#include "xenia/base/byte_stream.h"
#include "xenia/base/logging.h"
#include "xenia/emulator.h"
#include "xenia/hid/input_system.h"
#include "xenia/kernel/kernel_flags.h"
#include "xenia/kernel/user_module.h"
#include "xenia/kernel/util/shim_utils.h"
#include "xenia/kernel/xboxkrnl/xboxkrnl_memory.h"
@@ -40,9 +49,69 @@ DEFINE_uint32(kernel_build_version, 1888, "Define current kernel version",
DECLARE_string(cl);
DEFINE_bool(mem_watch, true,
"Periodically log host RSS / malloc-vs-mmap / guest-physical / "
"cache-deque size to localize the mission memory leak.", "Kernel");
DEFINE_uint32(mem_watch_secs, 3, "MEM-WATCH sample interval (seconds).",
"Kernel");
namespace xe {
namespace kernel {
// Diagnostic: a detached sampler that periodically logs where host memory is
// going, so a SHORT mission run localizes the leak (host malloc vs mmap vs
// guest-physical vs the cache work-queue). Gated by --mem_watch.
static std::atomic<bool> g_mem_watch_run{false};
static void MemWatchLoop(Memory* memory) {
uint64_t peak_rss_kb = 0;
while (g_mem_watch_run.load(std::memory_order_relaxed)) {
// Host RSS / VmSize from /proc/self/statm (fields in pages).
uint64_t rss_kb = 0, vsz_kb = 0;
if (FILE* f = std::fopen("/proc/self/statm", "r")) {
unsigned long vsz_pg = 0, rss_pg = 0;
if (std::fscanf(f, "%lu %lu", &vsz_pg, &rss_pg) == 2) {
rss_kb = static_cast<uint64_t>(rss_pg) * 4; // 4KB pages
vsz_kb = static_cast<uint64_t>(vsz_pg) * 4;
}
std::fclose(f);
}
if (rss_kb > peak_rss_kb) peak_rss_kb = rss_kb;
// Host allocator breakdown: malloc-in-use vs mmap'd bytes.
uint64_t malloc_kb = 0, mmap_kb = 0;
#if defined(__linux__)
struct mallinfo2 mi = mallinfo2();
malloc_kb = static_cast<uint64_t>(mi.uordblks) / 1024;
mmap_kb = static_cast<uint64_t>(mi.hblkhd) / 1024;
#endif
// Cache work-queue (guest): deque count OBJ+0x58 / list count OBJ+0x38,
// only once the singleton is initialized (once-flag 0x828F48B4 bit0).
uint32_t deque = 0, listc = 0;
auto rd = [&](uint32_t va) -> uint32_t {
auto p = memory->TranslateVirtual<xe::be<uint32_t>*>(va);
return p ? static_cast<uint32_t>(*p) : 0;
};
if (rd(0x828F48B4u) & 1u) {
deque = rd(0x828F4890u);
listc = rd(0x828F4870u);
}
XELOGE(
"MEM-WATCH rss={}MB (peak {}MB) vsz={}MB malloc_inuse={}MB mmap={}MB "
"cache_deque={} cache_list={}",
rss_kb / 1024, peak_rss_kb / 1024, vsz_kb / 1024, malloc_kb / 1024,
mmap_kb / 1024, deque, listc);
for (uint32_t i = 0; i < cvars::mem_watch_secs * 10 &&
g_mem_watch_run.load(std::memory_order_relaxed);
++i) {
std::this_thread::sleep_for(std::chrono::milliseconds(100));
}
}
}
constexpr std::chrono::milliseconds kDeferredOverlappedDelayMillis(25);
// This is a global object initialized with the XboxkrnlModule.
@@ -77,9 +146,16 @@ KernelState::KernelState(Emulator* emulator)
kMemoryProtectRead | kMemoryProtectWrite);
xenia_assert(fixed_alloc_worked);
if (cvars::mem_watch) {
g_mem_watch_run.store(true, std::memory_order_relaxed);
Memory* mem = memory_;
std::thread([mem]() { MemWatchLoop(mem); }).detach();
}
}
KernelState::~KernelState() {
g_mem_watch_run.store(false, std::memory_order_relaxed);
SetExecutableModule(nullptr);
if (dispatch_thread_running_) {
@@ -1070,6 +1146,14 @@ void KernelState::CompleteOverlappedEx(uint32_t overlapped_ptr, X_RESULT result,
auto ev = object_table()->LookupObject<XEvent>(event_handle);
assert_not_null(ev);
if (ev) {
if (cvars::audit_handle_lifecycle) {
uint32_t lr =
static_cast<uint32_t>(cpu::ThreadState::Get()->context()->lr);
XELOGKERNEL(
"AUDIT-HLC CompleteOverlappedEx_signal_event handle={:08X} "
"kevent_va={:08X} lr={:08X}",
uint32_t(event_handle), ev->guest_object(), lr);
}
ev->Set(0, false);
}
}
@@ -1372,6 +1456,47 @@ void KernelState::EmulateCPInterruptDPC(uint32_t interrupt_callback,
return;
}
if (cvars::audit_handle_lifecycle) {
XELOGKERNEL(
"AUDIT-HLC EmulateCPInterruptDPC callback={:08X} data={:08X} source={} "
"cpu={}",
interrupt_callback, interrupt_callback_data, source, cpu);
// AUDIT-2BF round 14 — one-shot singleton + vtable dump. Resolves
// the silph init chain bctrl target at PC 0x822F1B4C (vtable[0] of
// ANON_Class_2D56F86D at [0x828E1F08]). Dereferences 3 deep:
// [0x828E1F08] (singleton) → vtable → vtable[0] (=first virtual
// method, the bctrl target) and vtable[24] (=slot 6, canary's silph
// chain target sub_821B55D8). Done once per process via atomic
// flag. Defensive null-checks at each level.
static std::atomic<bool> g_audit_singleton_dumped{false};
bool expected = false;
if (g_audit_singleton_dumped.compare_exchange_strong(expected, true)) {
const uint32_t addr = 0x828E1F08;
uint32_t val = 0, vtable = 0, m0 = 0, m6 = 0;
auto* host_addr = memory()->TranslateVirtual<uint32_t*>(addr);
if (host_addr) {
val = xe::load_and_swap<uint32_t>(host_addr);
}
if (val) {
auto* host_val = memory()->TranslateVirtual<uint32_t*>(val);
if (host_val) {
vtable = xe::load_and_swap<uint32_t>(host_val);
}
}
if (vtable) {
auto* host_vt0 = memory()->TranslateVirtual<uint32_t*>(vtable);
auto* host_vt6 = memory()->TranslateVirtual<uint32_t*>(vtable + 24);
if (host_vt0) m0 = xe::load_and_swap<uint32_t>(host_vt0);
if (host_vt6) m6 = xe::load_and_swap<uint32_t>(host_vt6);
}
XELOGKERNEL(
"AUDIT-HLC singleton[0x828E1F08]={:08X} vtable={:08X} "
"vtable[0]={:08X} vtable[24]={:08X}",
val, vtable, m0, m6);
}
}
auto thread = kernel::XThread::GetCurrentThread();
assert_not_null(thread);

View File

@@ -479,6 +479,29 @@ enum class KernelModuleId {
xbdm,
};
// Phase A bridge — see kernel/event_log.h. Declared inline here to avoid
// pulling the event_log / PPCContext headers into shim_utils.h's transitive
// include set. Zero-cost when --phase_a_event_log_path is unset (Enabled()
// returns false and the hooks are skipped).
namespace phase_a_bridge {
constexpr const char* KernelModuleIdName(KernelModuleId m) {
switch (m) {
case KernelModuleId::xboxkrnl: return "xboxkrnl.exe";
case KernelModuleId::xam: return "xam.xex";
case KernelModuleId::xbdm: return "xbdm.xex";
}
return "unknown";
}
bool Enabled();
void EmitReturn(const char* name, uint64_t return_value);
// Resolves path-bearing export args (OBJECT_ATTRIBUTES*, handles) from the PPC
// context and, under --phase_a_trace_args, fills args/args_resolved and emits
// file.read events. `ppc_context` is a void* to keep PPCContext out of this
// header's transitive includes.
void EmitImportAndCallWithCtx(const char* module_name, uint16_t ord,
const char* name, void* ppc_context);
} // namespace phase_a_bridge
template <size_t I = 0, typename... Ps>
requires(I == sizeof...(Ps))
void AppendKernelCallParams(StringBuffer& string_buffer,
@@ -558,14 +581,26 @@ struct ExportRegistrerHelper {
cvars::log_high_frequency_kernel_calls)) {
PrintKernelCall(export_entry, params);
}
const bool phase_a_on = phase_a_bridge::Enabled();
if (phase_a_on) {
phase_a_bridge::EmitImportAndCallWithCtx(
phase_a_bridge::KernelModuleIdName(MODULE), ORDINAL,
export_entry->name, ppc_context);
}
if constexpr (std::is_void<R>::value) {
KernelTrampoline(fn, std::forward<std::tuple<Ps...>>(params),
std::make_index_sequence<sizeof...(Ps)>());
if (phase_a_on) {
phase_a_bridge::EmitReturn(export_entry->name, 0);
}
} else {
auto result =
KernelTrampoline(fn, std::forward<std::tuple<Ps...>>(params),
std::make_index_sequence<sizeof...(Ps)>());
result.Store(ppc_context);
if (phase_a_on) {
phase_a_bridge::EmitReturn(export_entry->name, 0);
}
if (TAGS &
(xe::cpu::ExportTag::kLog | xe::cpu::ExportTag::kLogResult)) {
// TODO(benvanik): log result.

View File

@@ -7,7 +7,9 @@
******************************************************************************
*/
#include "xenia/apu/apu_flags.h"
#include "xenia/apu/audio_system.h"
#include "xenia/base/logging.h"
#include "xenia/emulator.h"
#include "xenia/kernel/kernel_state.h"
#include "xenia/kernel/util/shim_utils.h"
@@ -55,8 +57,13 @@ DECLARE_XBOXKRNL_EXPORT2(XAudioGetVoiceCategoryVolume, kAudio, kStub,
dword_result_t XAudioEnableDucker_entry(dword_t unk) { return X_ERROR_SUCCESS; }
DECLARE_XBOXKRNL_EXPORT1(XAudioEnableDucker, kAudio, kStub);
dword_result_t XAudioRegisterRenderDriverClient_entry(lpdword_t callback_ptr,
lpdword_t driver_ptr) {
dword_result_t XAudioRegisterRenderDriverClient_entry(
lpdword_t callback_ptr, lpdword_t driver_ptr,
const ppc_context_t& ppc_context) {
if (cvars::audio_watchdog) {
XELOGW("AUDIO-WD guest called XAudioRegisterRenderDriverClient lr={:08X}",
static_cast<uint32_t>(ppc_context->lr));
}
if (!callback_ptr) {
return X_E_INVALIDARG;
}
@@ -84,9 +91,17 @@ DECLARE_XBOXKRNL_EXPORT1(XAudioRegisterRenderDriverClient, kAudio,
kImplemented);
dword_result_t XAudioUnregisterRenderDriverClient_entry(
lpunknown_t driver_ptr) {
lpunknown_t driver_ptr, const ppc_context_t& ppc_context) {
assert_true((driver_ptr.guest_address() & 0xFFFF0000) == 0x41550000);
// Who tore audio down? The guest's return address names the game code path
// (resolve with zq.py fn <lr>) -- the game only does this on its own error /
// teardown logic, which is what we are hunting. Diagnostics only.
if (cvars::audio_watchdog) {
XELOGW("AUDIO-WD guest called XAudioUnregisterRenderDriverClient lr={:08X}",
static_cast<uint32_t>(ppc_context->lr));
}
auto audio_system = kernel_state()->emulator()->audio_system();
audio_system->UnregisterClient(driver_ptr.guest_address() & 0x0000FFFF);
return X_ERROR_SUCCESS;

View File

@@ -7,8 +7,17 @@
******************************************************************************
*/
#include <algorithm>
#include <map>
#include <set>
#include <vector>
#include "xenia/base/cvar.h"
#include "xenia/base/debugging.h"
#include "xenia/base/logging.h"
#include "xenia/cpu/backend/backend.h"
#include "xenia/cpu/function.h"
#include "xenia/cpu/processor.h"
#include "xenia/emulator.h"
#include "xenia/kernel/kernel_state.h"
#include "xenia/kernel/util/shim_utils.h"
@@ -19,6 +28,22 @@
#include "xenia/ui/window.h"
#include "xenia/ui/windowed_app_context.h"
DEFINE_bool(
cache_throw_diag, false,
"Run the heavy guest-throw diagnostics (LogGuestThrow / cache-manager dump / "
"catch-frame walk) on every guest C++ throw. OFF by default: in missions the "
"cache throws constantly and these dumps allocate gigabytes -- they are for "
"targeted debugging only.",
"Kernel");
DEFINE_bool(
eh_dispatch, false,
"Dispatch guest C++ exceptions (0xE06D7363) to their catch handler instead "
"of letting the throw fall through. NOTE: disproven as a fix for the Project "
"Sylpheed cache crash (that throw is uncaught by design -- its stack ends at "
"the thread-entry Execute boundary); kept as inert infra + diagnostics.",
"Kernel");
namespace xe {
namespace kernel {
namespace xboxkrnl {
@@ -104,6 +129,468 @@ typedef struct {
xe::be<uint32_t> catchable_type_array_ptr;
} x_s__ThrowInfo;
// Read a guest C-string, bounded.
static std::string GuestCString(uint32_t guest_ptr, size_t max_len = 128) {
if (!guest_ptr) {
return {};
}
auto p = kernel_memory()->TranslateVirtual<const char*>(guest_ptr);
if (!p) {
return {};
}
std::string s;
for (size_t i = 0; i < max_len && p[i]; ++i) {
s.push_back(p[i]);
}
return s;
}
// Name the thrown C++ type via the MSVC RTTI chain hanging off its vtable:
// object -> vtable ; vtable[-1] -> CompleteObjectLocator ; COL+0xC ->
// TypeDescriptor ; TypeDescriptor+8 -> mangled name (".?AVout_of_range@std@@")
static std::string ThrownTypeName(uint32_t thrown_ptr) {
if (!thrown_ptr) {
return "<null>";
}
auto rd32 = [](uint32_t va) -> uint32_t {
auto p = kernel_memory()->TranslateVirtual<xe::be<uint32_t>*>(va);
return p ? static_cast<uint32_t>(*p) : 0;
};
const uint32_t vtable = rd32(thrown_ptr);
if (!vtable) {
return "<no vtable>";
}
const uint32_t col = rd32(vtable - 4);
if (!col) {
return "<no RTTI>";
}
const uint32_t type_desc = rd32(col + 0x0C);
if (!type_desc) {
return "<no type descriptor>";
}
return GuestCString(type_desc + 8);
}
// Diagnostics for the swallowed-throw crash: xenia does NOT dispatch guest C++
// exceptions (see below), so a throw returns and the game crashes in the
// unreachable code after it. By then the crash dump's registers are already
// clobbered. Capture the guest state HERE, while the throwing call frame is
// still intact -- the thrown type, the registers (the failing lookup's key and
// loop state live in these), and the guest call stack.
// Dump the asset-cache-manager LRU state at the moment it throws out_of_range,
// so we can see WHICH access-order deque hash-pair is missing from the entry
// map (the desync that crashes in sub_8245A098). r25 survives the throw and
// holds the cache-manager global (guest VA 0x828F4838). Layout (from RE):
// OBJ+0x30 = std::list<Entry> (map is rebuilt from this, keyed by hash-pair)
// OBJ+0x48 = std::deque<hashpair(8B)>: +0x4C block-map ptr, +0x50 map_size,
// +0x54 start off, +0x58 element count. Element i (8-byte, 2/block):
// bi=((start+i)/2); if bi>=map_size bi-=map_size; addr=blockmap[bi]+(i&1)*8
static void DumpCacheManagerOnThrow(const ppc_context_t& ctx) {
const uint32_t OBJ = 0x828F4838u;
if (static_cast<uint32_t>(ctx->r[25]) != OBJ) {
return; // not the cache-manager map::at that threw
}
auto rd = [](uint32_t va) -> uint32_t {
auto p = kernel_memory()->TranslateVirtual<xe::be<uint32_t>*>(va);
return p ? static_cast<uint32_t>(*p) : 0;
};
const uint32_t deque_count = rd(OBJ + 0x58);
const uint32_t list_count = rd(OBJ + 0x38);
const uint32_t blockmap = rd(OBJ + 0x4C);
const uint32_t map_size = rd(OBJ + 0x50);
const uint32_t start = rd(OBJ + 0x54);
XELOGE(
"CACHE-DUMP deque_count={} list_count={} blockmap={:08X} map_size={} "
"start={}",
deque_count, list_count, blockmap, map_size, start);
// Raw header words -- resolve the real container layout without guessing.
auto rawrow = [&](const char* tag, uint32_t base, int words) {
std::string s;
for (int i = 0; i < words; ++i)
s += fmt::format(" +{:X}={:08X}", i * 4, rd(base + i * 4));
XELOGE("CACHE-RAW {} @{:08X}:{}", tag, base, s);
};
rawrow("mgr+0x28", OBJ + 0x28, 16); // map(+0x30) + deque(+0x48) headers
// deque hash-pairs (access order)
std::string dq;
const uint32_t n = deque_count > 512 ? 512 : deque_count; // sanity cap
for (uint32_t i = 0; i < n; ++i) {
uint32_t bi = (start + i) / 2;
if (map_size && bi >= map_size) {
bi -= map_size;
}
const uint32_t block = rd(blockmap + bi * 4);
const uint32_t addr = block + (i & 1) * 8;
dq += fmt::format(" [{}]{:08X}:{:08X}", i, rd(addr), rd(addr + 4));
}
XELOGE("CACHE-DUMP deque hashpairs:{}", dq);
// Walk the entry map at OBJ+0x30 (MSVC _Tree, CONFIRMED by live raw dump:
// _Left@+0, _Parent@+4, _Right@+8, keyLo@+12, keyHi@+16, _Isnil@+25). Map
// object header is at OBJ+0x30; head=[OBJ+0x34]; root=head._Parent=[head+4].
// This is the map sub_8245A098 queries per deque entry.
std::set<uint64_t> map_keys;
const uint32_t head = rd(OBJ + 0x34);
const uint32_t root = head ? rd(head + 4) : 0;
std::vector<uint32_t> stack;
if (root && (rd(root + 25) & 0xFF) == 0) {
stack.push_back(root);
}
// Hard guards: a corrupted map (cyclic/garbage node pointers -- common at the
// moment it throws) would otherwise balloon this walk to gigabytes.
uint32_t visits = 0;
while (!stack.empty() && map_keys.size() < 4096 && ++visits < 100000 &&
stack.size() < 100000) {
const uint32_t nd = stack.back();
stack.pop_back();
const uint64_t key = (static_cast<uint64_t>(rd(nd + 12)) << 32) | rd(nd + 16);
map_keys.insert(key);
const uint32_t l = rd(nd + 0), r = rd(nd + 8);
if (l && (rd(l + 25) & 0xFF) == 0) stack.push_back(l);
if (r && (rd(r + 25) & 0xFF) == 0) stack.push_back(r);
}
// For each deque key, flag whether it exists in the persistent map. The
// orphan(s) = deque keys absent from the map == the cause of the map::at miss.
std::string orphans;
uint32_t orphan_count = 0;
for (uint32_t i = 0; i < n; ++i) {
uint32_t bi = (start + i) / 2;
if (map_size && bi >= map_size) bi -= map_size;
const uint32_t block = rd(blockmap + bi * 4);
const uint32_t addr = block + (i & 1) * 8;
const uint64_t key =
(static_cast<uint64_t>(rd(addr)) << 32) | rd(addr + 4);
if (!map_keys.count(key)) {
orphans += fmt::format(" [{}]{:08X}:{:08X}", i, rd(addr), rd(addr + 4));
++orphan_count;
}
}
XELOGE("CACHE-DUMP map_keys={} deque_orphans={} (deque keys NOT in map):{}",
static_cast<uint32_t>(map_keys.size()), orphan_count, orphans);
// --- SNAPSHOT vs LIVE: prove the TOCTOU race. The flush (sub_8245A098) locks,
// copies OBJ+0x30 into a temp map at [flush_r31+104], UNLOCKS (0x8245a150),
// then iterates the live deque doing map::at on the FROZEN snapshot. A
// concurrent LOCKED add (8245ABD8/8245AD00) pushes a deque + map entry during
// the unlocked window -> that key is in the LIVE map but NOT the snapshot ->
// map::at throws. Find the flush frame (its live PC is in the map::at loop);
// its snapshot map object is at frame_sp+104 (== r26 at the throw).
uint32_t flush_sp = 0;
{
uint32_t sp = static_cast<uint32_t>(ctx->r[1]);
for (int depth = 0; depth < 128 && sp; ++depth) {
auto f = kernel_memory()->TranslateVirtual(sp);
if (!f) break;
uint32_t nsp = xe::load_and_swap<uint32_t>(f);
if (nsp <= sp || nsp - sp > 0x1000000) break;
auto lp = kernel_memory()->TranslateVirtual(nsp - 8);
uint32_t pc = lp ? xe::load_and_swap<uint32_t>(lp) : 0;
if (pc >= 0x8245A154u && pc <= 0x8245A1D0u) { // flush deque/map::at loop
flush_sp = nsp;
break;
}
sp = nsp;
}
}
if (!flush_sp) {
XELOGE("CACHE-DUMP flush frame not found on stack (snapshot compare skipped)");
return;
}
rawrow("snapshot@r31+104", flush_sp + 96, 16); // raw temp-map header region
const uint32_t snap = flush_sp + 104; // temp map object [r31+104]
std::set<uint64_t> snap_keys;
const uint32_t shead = rd(snap + 4);
const uint32_t sroot = shead ? rd(shead + 4) : 0;
std::vector<uint32_t> st;
if (sroot && (rd(sroot + 25) & 0xFF) == 0) st.push_back(sroot);
uint32_t svisits = 0;
while (!st.empty() && snap_keys.size() < 4096 && ++svisits < 100000 &&
st.size() < 100000) {
const uint32_t nd = st.back();
st.pop_back();
snap_keys.insert((static_cast<uint64_t>(rd(nd + 12)) << 32) | rd(nd + 16));
const uint32_t l = rd(nd + 0), r = rd(nd + 8);
if (l && (rd(l + 25) & 0xFF) == 0) st.push_back(l);
if (r && (rd(r + 25) & 0xFF) == 0) st.push_back(r);
}
std::string miss;
uint32_t miss_count = 0;
for (uint32_t i = 0; i < n; ++i) {
uint32_t bi = (start + i) / 2;
if (map_size && bi >= map_size) bi -= map_size;
const uint32_t addr = rd(blockmap + bi * 4) + (i & 1) * 8;
const uint64_t key = (static_cast<uint64_t>(rd(addr)) << 32) | rd(addr + 4);
if (!snap_keys.count(key)) {
miss += fmt::format(" [{}]{:08X}:{:08X}(in_live_map={})", i,
static_cast<uint32_t>(key >> 32),
static_cast<uint32_t>(key), map_keys.count(key) ? 1 : 0);
++miss_count;
}
}
XELOGE(
"CACHE-DUMP flush_sp={:08X} snapshot_keys={} deque_NOT_in_snapshot={} "
"(these are what map::at throws on; in_live_map=1 => added during the "
"flush's UNLOCKED window = the TOCTOU race):{}",
flush_sp, static_cast<uint32_t>(snap_keys.size()), miss_count, miss);
}
// ---------------------------------------------------------------------------
// Fix-A analysis half (read-only): determine which guest stack frame WOULD catch
// the current C++ throw and where it would resume, by parsing the guest's MSVC
// C++ EH tables. Zero behaviour change -- logs WOULD-CATCH so the frame-finding
// can be validated against a live crash before the control-transfer half is
// wired in. Layout (all BE u32 unless noted):
// FuncInfo (magic 0x19930522): +12 nTryBlocks, +16 pTryBlockMap,
// +20 nIPMap, +24 pIP2StateMap
// IP2StateMapEntry(8B): +0 Ip(VA), +4 State(int)
// TryBlockMapEntry(20B): +0 tryLow, +4 tryHigh, +8 catchHigh, +12 nCatches,
// +16 pHandlerArray
// HandlerType(16B): +4 pType(TypeDescriptor; 0=catch(...)), +8 dispCatchObj,
// +12 addressOfHandler(funclet)
// CatchableTypeArray: +0 count, +4 CatchableType*[]; CatchableType: +4 type_ptr
namespace {
struct EhFuncInfo {
uint32_t funcinfo_va;
uint32_t func_start; // xenia function containing this FuncInfo's code
uint32_t first_ip, last_ip; // IP2State map coverage (fallback PC match)
uint32_t p_ip, n_ip; // IP2State map
uint32_t p_try, n_try; // try-block map
};
static std::vector<EhFuncInfo>* g_eh_catch_index = nullptr;
static uint32_t EhRd(uint32_t va) {
auto p = kernel_memory()->TranslateVirtual<xe::be<uint32_t>*>(va);
return p ? static_cast<uint32_t>(*p) : 0;
}
// xenia function-start containing pc, or 0. Non-analyzing lookup: every frame on
// a live stack has already executed, so its function is known (no side effects).
static uint32_t EhFuncStart(uint32_t pc) {
auto* f = kernel_state()->processor()->LookupFunction(pc);
return f ? f->address() : 0;
}
// Build the catch index once: scan .rdata for FuncInfo(magic) with nTry>=1.
static void EhBuildIndex() {
if (g_eh_catch_index) return;
g_eh_catch_index = new std::vector<EhFuncInfo>();
// .rdata bounds from the PE section table (PESEC): addr 82000600 size 1142488.
const uint32_t lo = 0x82000600u, hi = 0x82000600u + 1142488u;
for (uint32_t a = lo; a + 28 < hi; a += 4) {
if (EhRd(a) != 0x19930522u) continue;
uint32_t n_try = EhRd(a + 12), p_try = EhRd(a + 16);
uint32_t n_ip = EhRd(a + 20), p_ip = EhRd(a + 24);
if (!n_try || !p_try || n_try > 64 || !n_ip || !p_ip) continue;
uint32_t first_ip = EhRd(p_ip);
uint32_t last_ip = EhRd(p_ip + (n_ip - 1) * 8);
uint32_t fn = EhFuncStart(first_ip); // first IP -> its function
if (!fn) fn = first_ip; // fall back to the IP itself
g_eh_catch_index->push_back(
{a, fn, first_ip, last_ip, p_ip, n_ip, p_try, n_try});
}
XELOGE("EH-INDEX built: {} catch-bearing FuncInfos",
static_cast<uint32_t>(g_eh_catch_index->size()));
}
// State at pc: State of the IP2State entry with the greatest Ip<=pc; -1 if pc
// precedes the first entry (not inside any protected region).
static int EhStateAt(const EhFuncInfo& fi, uint32_t pc) {
int state = -1;
uint32_t best_ip = 0;
for (uint32_t i = 0; i < fi.n_ip; ++i) {
uint32_t ip = EhRd(fi.p_ip + i * 8);
if (ip <= pc && ip >= best_ip) {
best_ip = ip;
state = static_cast<int>(EhRd(fi.p_ip + i * 8 + 4));
}
}
return state;
}
} // namespace
// Sentinel return address ExecuteRaw() gives a guest function (matches
// Processor::ExecuteRaw). We force the catching frame's saved-LR slot to this so
// the catch funclet returns to us regardless of how it restores LR.
static constexpr uint32_t kFuncletReturnSentinel = 0xBCBCBCBCu;
// Fix A. Dispatch the current guest C++ throw to the first stack frame that
// catches it, then resume the guest as if that frame had caught-and-returned.
// Returns true if dispatched -- in which case this does NOT return normally: it
// calls XThread::Reenter, which throws FiberReentryException to unwind every
// intervening host/JIT frame before resuming the guest at the catch frame's
// return site. Returns false (falls through to the old crash path) when no
// handler matches or --eh_dispatch=false.
bool DispatchGuestCatch(pointer_t<X_EXCEPTION_RECORD> record,
const ppc_context_t& ctx) {
EhBuildIndex();
const uint32_t thrown_obj = record->exception_information[1];
// Every TypeDescriptor the throw can be caught as -> its base-subobject
// displacement (x_PMD.mdisp), from the throw's CatchableTypeArray.
std::map<uint32_t, int32_t> catchable;
uint32_t cta = EhRd(record->exception_information[2] + 12);
if (cta) {
uint32_t n = EhRd(cta);
for (uint32_t i = 0; i < n && i < 32; ++i) {
uint32_t ct = EhRd(cta + 4 + i * 4);
if (ct) catchable[EhRd(ct + 4)] = static_cast<int32_t>(EhRd(ct + 8));
}
}
uint32_t sp = static_cast<uint32_t>(ctx->r[1]);
for (int depth = 0; depth < 128; ++depth) {
auto frame = kernel_memory()->TranslateVirtual(sp);
if (!sp || !frame) {
XELOGE("EH-WALK stop depth={} sp={:08X} (untranslatable)", depth, sp);
break;
}
uint32_t next_sp = xe::load_and_swap<uint32_t>(frame);
// The cache flush runs on a fiber/task stack; the back-chain can jump a long
// way (or to a different stack) when crossing into the dispatcher that has
// the try/catch. Only require it to go UP; allow large gaps.
if (next_sp <= sp) {
XELOGE("EH-WALK stop depth={} sp={:08X} next_sp={:08X} (not ascending)",
depth, sp, next_sp);
break;
}
if (next_sp - sp > 0x1000000) {
XELOGE("EH-WALK stop depth={} sp={:08X} next_sp={:08X} (gap>16M)", depth,
sp, next_sp);
break;
}
auto lrp = kernel_memory()->TranslateVirtual(next_sp - 8);
uint32_t pc = lrp ? xe::load_and_swap<uint32_t>(lrp) : 0;
uint32_t frame_sp = next_sp; // SP_F: the catching frame's running SP
sp = next_sp;
uint32_t fn = (pc >= 0x82150000 && pc < 0x8284A000) ? EhFuncStart(pc) : 0;
XELOGE("EH-WALK depth={} SP_F={:08X} pc={:08X} fn={:08X}", depth, frame_sp,
pc, fn);
if (pc < 0x82150000 || pc >= 0x8284A000) continue;
for (const auto& fi : *g_eh_catch_index) {
// Match the frame to a catch FuncInfo either by xenia's function-start or
// (robust to xenia splitting funcs/funclets) by the FuncInfo's IP range.
bool by_fn = fn && fi.func_start == fn;
bool by_ip = pc >= fi.first_ip && pc <= fi.last_ip;
if (!by_fn && !by_ip) continue;
int state = EhStateAt(fi, pc);
for (uint32_t t = 0; t < fi.n_try; ++t) {
uint32_t te = fi.p_try + t * 20;
int try_low = static_cast<int>(EhRd(te));
int try_high = static_cast<int>(EhRd(te + 4));
if (state < try_low || state > try_high) continue;
uint32_t n_catch = EhRd(te + 12), pH = EhRd(te + 16);
for (uint32_t c = 0; c < n_catch && c < 32; ++c) {
uint32_t pType = EhRd(pH + c * 16 + 4);
auto it = (pType == 0) ? catchable.end() : catchable.find(pType);
if (pType != 0 && it == catchable.end()) continue;
int32_t mdisp = (it == catchable.end()) ? 0 : it->second;
uint32_t dispCatchObj = EhRd(pH + c * 16 + 8);
uint32_t funclet = EhRd(pH + c * 16 + 12);
// Establisher frame = SP at F's entry = the back-chain word saved at
// F's SP by its `stwu`. The funclet rebuilds its frame ptr as
// r31 = r12 - N, and __save/restgprlr save/restore F's nonvolatiles +
// return address at [establisher-8].
uint32_t establisher = EhRd(frame_sp);
uint32_t f_return = EhRd(establisher - 8); // F's real return address
XELOGE(
"GUEST-CATCH frame_pc={:08X} fn={:08X} SP_F={:08X} est={:08X} "
"f_return={:08X} state={} try{}[{}..{}] catch#{} pType={:08X} "
"obj@est+{:X} funclet={:08X} dispatch={}",
pc, fn, frame_sp, establisher, f_return, state, t, try_low,
try_high, c, pType, dispCatchObj, funclet,
cvars::eh_dispatch ? 1 : 0);
if (!cvars::eh_dispatch) return false;
if (!establisher || !f_return) {
XELOGE("GUEST-CATCH abort: bad establisher/return frame");
return false;
}
auto store32 = [](uint32_t va, uint32_t val) {
auto p = kernel_memory()->TranslateVirtual<xe::be<uint32_t>*>(va);
if (p) *p = val;
};
// Hand the caught object (adjusted to the caught base) to the catch.
// catch(...) (dispCatchObj==0) takes no object.
if (dispCatchObj != 0) {
store32(establisher + dispCatchObj,
thrown_obj + static_cast<uint32_t>(mdisp));
}
// Force the funclet to return to us no matter how it restores LR.
store32(establisher - 8, kFuncletReturnSentinel);
// Run the game's own catch funclet in F's frame: r12=r1=establisher.
// It runs the catch body, restores F's inherited nonvolatiles, and
// returns (r3 = F's return value).
ctx->r[12] = establisher;
ctx->r[1] = establisher;
ctx->processor->ExecuteRaw(ctx->thread_state, funclet);
// F has effectively caught-and-returned: resume at F's caller with the
// funclet's return value. Reenter unwinds all the throw's host/JIT
// frames first. r1 is already the caller SP (establisher).
ctx->processor->backend()->PrepareForReentry(ctx.value());
XELOGE("GUEST-CATCH dispatched -> resuming at f_return={:08X} r3={:08X}",
f_return, static_cast<uint32_t>(ctx->r[3]));
XThread::GetCurrentThread()->Reenter(f_return);
return true; // not reached
}
}
}
}
XELOGE("GUEST-CATCH none (no matching handler frame found)");
return false;
}
void LogGuestThrow(pointer_t<X_EXCEPTION_RECORD> record,
const ppc_context_t& ctx) {
const uint32_t thrown_ptr = record->exception_information[1];
XELOGE("GUEST-THROW type={} object={:08X} lr={:08X}",
ThrownTypeName(thrown_ptr), thrown_ptr,
static_cast<uint32_t>(ctx->lr));
DumpCacheManagerOnThrow(ctx);
std::string regs;
for (int i = 3; i <= 31; ++i) {
regs += fmt::format(" r{}={:08X}", i, static_cast<uint32_t>(ctx->r[i]));
}
XELOGE("GUEST-THROW regs:{}", regs);
// Walk the guest stack. Xenon prologues do `mfspr r12,LR; stw r12,-8(r1)`
// BEFORE `stwu r1,-N(r1)`, so a frame's return address is stored at
// [caller_sp - 8] = [([sp]) - 8], NOT [sp+4]. Back chain = [sp]. Filter to
// .text (0x82150000..0x8284A000).
std::string frames;
uint32_t sp = static_cast<uint32_t>(ctx->r[1]);
for (int depth = 0; depth < 64; ++depth) {
auto frame = kernel_memory()->TranslateVirtual(sp);
if (!sp || !frame) {
break;
}
const uint32_t next_sp = xe::load_and_swap<uint32_t>(frame);
if (next_sp <= sp || next_sp - sp > 0x40000) {
break;
}
auto lrp = kernel_memory()->TranslateVirtual(next_sp - 8);
if (lrp) {
const uint32_t lr = xe::load_and_swap<uint32_t>(lrp);
if (lr >= 0x82150000 && lr < 0x8284A000) {
frames += fmt::format(" {:08X}", lr);
}
}
sp = next_sp;
}
XELOGE("GUEST-THROW guest stack:{}", frames);
}
void HandleCppException(pointer_t<X_EXCEPTION_RECORD> record) {
// C++ exception.
// https://blogs.msdn.com/b/oldnewthing/archive/2010/07/30/10044061.aspx
@@ -128,13 +615,29 @@ void HandleCppException(pointer_t<X_EXCEPTION_RECORD> record) {
XELOGE("Guest attempted to throw a C++ exception!");
}
void RtlRaiseException_entry(pointer_t<X_EXCEPTION_RECORD> record) {
void RtlRaiseException_entry(pointer_t<X_EXCEPTION_RECORD> record,
const ppc_context_t& ppc_context) {
switch (record->code) {
case 0x406D1388: {
HandleSetThreadName(record);
return;
}
case 0xE06D7363: {
// Heavy diagnostics are OFF by default: in a mission the cache flush
// throws constantly, and these dumps (esp. the cache-manager tree walk on
// a corrupted map) allocate gigabytes per throw. Stock behaviour is just
// HandleCppException below.
if (cvars::cache_throw_diag) {
LogGuestThrow(record, ppc_context);
}
// Fix A: dispatch to the catch handler. On success this does not return
// (it reenters the guest at the catch frame). Disproven for the cache
// crash and default-off; also skip its (allocating) frame walk unless a
// diagnostic/dispatch knob is set.
if ((cvars::eh_dispatch || cvars::cache_throw_diag) &&
DispatchGuestCatch(record, ppc_context)) {
return;
}
HandleCppException(record);
return;
}

View File

@@ -8,7 +8,9 @@
*/
#include "xenia/base/logging.h"
#include "xenia/cpu/thread_state.h"
#include "xenia/kernel/info/file.h"
#include "xenia/kernel/kernel_flags.h"
#include "xenia/kernel/kernel_state.h"
#include "xenia/kernel/util/shim_utils.h"
#include "xenia/kernel/xboxkrnl/xboxkrnl_private.h"
@@ -208,6 +210,13 @@ dword_result_t NtReadFile_entry(dword_t file_handle, dword_t event_handle,
}
if (ev && signal_event) {
if (cvars::audit_handle_lifecycle) {
uint32_t lr = static_cast<uint32_t>(cpu::ThreadState::Get()->context()->lr);
XELOGKERNEL(
"AUDIT-HLC NtReadFile_signal_event handle={:08X} kevent_va={:08X} "
"lr={:08X}",
uint32_t(event_handle), ev->guest_object(), lr);
}
ev->Set(0, false);
}
@@ -294,6 +303,13 @@ dword_result_t NtReadFileScatter_entry(
}
if (ev && signal_event) {
if (cvars::audit_handle_lifecycle) {
uint32_t lr = static_cast<uint32_t>(cpu::ThreadState::Get()->context()->lr);
XELOGKERNEL(
"AUDIT-HLC NtReadFileScatter_signal_event handle={:08X} "
"kevent_va={:08X} lr={:08X}",
uint32_t(event_handle), ev->guest_object(), lr);
}
ev->Set(0, false);
}
@@ -381,6 +397,13 @@ dword_result_t NtWriteFile_entry(dword_t file_handle, dword_t event_handle,
}
if (ev && signal_event) {
if (cvars::audit_handle_lifecycle) {
uint32_t lr = static_cast<uint32_t>(cpu::ThreadState::Get()->context()->lr);
XELOGKERNEL(
"AUDIT-HLC NtWriteFile_signal_event handle={:08X} kevent_va={:08X} "
"lr={:08X}",
uint32_t(event_handle), ev->guest_object(), lr);
}
ev->Set(0, false);
}
@@ -760,6 +783,15 @@ void IoDeleteDevice_entry(dword_t device_ptr, const ppc_context_t& ctx) {
DECLARE_XBOXKRNL_EXPORT1(IoDeleteDevice, kFileSystem, kStub);
// NOTE (2026-07-14): do NOT stub StfsCreateDevice / IoDismountVolumeByFileHandle
// without testing an actual playthrough. They are deliberately left
// unimplemented (the JIT's "undefined extern call" stub handles them, leaving
// guest r3 untouched so the title reads back its own first argument as the
// status). Implementing them -- even returning X_STATUS_NOT_SUPPORTED -- makes
// the title hang at boot (black screen) right after the devkit-memory
// allocation, before it ever calls StfsCreateDevice. Whatever the title keys
// off here, it is not a plain NTSTATUS check.
} // namespace xboxkrnl
} // namespace kernel
} // namespace xe

View File

@@ -10,6 +10,8 @@
#include "xenia/kernel/xboxkrnl/xboxkrnl_ob.h"
#include "xenia/base/logging.h"
#include "xenia/cpu/processor.h"
#include "xenia/cpu/thread_state.h"
#include "xenia/kernel/kernel_flags.h"
#include "xenia/kernel/kernel_state.h"
#include "xenia/kernel/xboxkrnl/xboxkrnl_private.h"
#include "xenia/kernel/xboxkrnl/xboxkrnl_threading.h"
@@ -398,6 +400,14 @@ dword_result_t NtDuplicateObject_entry(dword_t handle, lpdword_t new_handle_ptr,
X_STATUS result =
kernel_state()->object_table()->DuplicateHandle(handle, &new_handle);
if (cvars::audit_handle_lifecycle) {
uint32_t lr = static_cast<uint32_t>(cpu::ThreadState::Get()->context()->lr);
XELOGKERNEL(
"AUDIT-HLC NtDuplicateObject src={:08X} dst={:08X} options={:08X} "
"lr={:08X}",
uint32_t(handle), uint32_t(new_handle), uint32_t(options), lr);
}
if (new_handle_ptr) {
*new_handle_ptr = new_handle;
}

View File

@@ -8,10 +8,12 @@
*/
#include "xenia/kernel/xboxkrnl/xboxkrnl_threading.h"
#include <atomic>
#include "xenia/base/atomic.h"
#include "xenia/base/clock.h"
#include "xenia/base/platform.h"
#include "xenia/cpu/processor.h"
#include "xenia/kernel/kernel_flags.h"
#include "xenia/kernel/util/shim_utils.h"
#include "xenia/kernel/xboxkrnl/xboxkrnl_private.h"
#include "xenia/kernel/xsemaphore.h"
@@ -22,6 +24,9 @@ namespace xe {
namespace kernel {
namespace xboxkrnl {
// AUDIT-HLC: one-shot guard for silph::WorkerCtx context dump (round5).
static std::atomic<bool> g_audit_silph_ctx_dumped{false};
// r13 + 0x100: pointer to thread local state
// Thread local state:
// 0x058: kernel time
@@ -192,6 +197,30 @@ dword_result_t ExCreateThread_entry(lpdword_t handle_ptr, dword_t stack_size,
lpvoid_t start_address,
lpvoid_t start_context,
dword_t creation_flags) {
if (cvars::audit_handle_lifecycle) {
auto* ctx = cpu::ThreadState::Get()->context();
uint32_t lr = static_cast<uint32_t>(ctx->lr);
// Walk one PPC stack frame up from the shim's frame to recover the GUEST
// caller's LR (lr_enter is just the kernel-internal shim's return
// address; we want the function that called *it*). Same convention as
// the NtWaitForSingleObjectEx probe above.
uint32_t guest_lr = 0;
uint32_t sp = static_cast<uint32_t>(ctx->r[1]);
uint32_t back1 = xe::load_and_swap<uint32_t>(ctx->TranslateVirtual(sp));
if (back1) {
uint32_t back2 =
xe::load_and_swap<uint32_t>(ctx->TranslateVirtual(back1));
if (back2) {
guest_lr =
xe::load_and_swap<uint32_t>(ctx->TranslateVirtual(back2 - 8));
}
}
XELOGKERNEL(
"AUDIT-HLC ExCreateThread entry={:08X} start_ctx={:08X} xapi={:08X} "
"flags={:08X} lr={:08X} guest_lr={:08X}",
uint32_t(start_address), uint32_t(start_context),
uint32_t(xapi_thread_startup), uint32_t(creation_flags), lr, guest_lr);
}
return ExCreateThread(handle_ptr, stack_size, thread_id_ptr,
xapi_thread_startup, start_address, start_context,
creation_flags);
@@ -582,6 +611,48 @@ uint32_t xeKeSetEvent(X_KEVENT* event_ptr, uint32_t increment, uint32_t wait) {
dword_result_t KeSetEvent_entry(pointer_t<X_KEVENT> event_ptr,
dword_t increment, dword_t wait) {
if (cvars::audit_handle_lifecycle) {
uint32_t lr = static_cast<uint32_t>(cpu::ThreadState::Get()->context()->lr);
XELOGKERNEL("AUDIT-HLC KeSetEvent guest_ptr={:08X} lr={:08X}",
uint32_t(event_ptr.guest_address()), lr);
// AUDIT-HLC round5: one-shot hexdump of the silph::WorkerCtx context when
// KeSetEvent first fires into the silph UI PKEVENT cluster
// (0xBCE25214/24/34/44 in current builds; widened a bit for allocator
// drift). Used by iterate 2.BF context-replication.
uint32_t ev_addr = uint32_t(event_ptr.guest_address());
if (ev_addr >= 0xBCE25200 && ev_addr < 0xBCE25300) {
if (!g_audit_silph_ctx_dumped.exchange(true)) {
// Events live at ctx+0x54, +0x64, +0x74, +0x84 (16-byte stride).
// Compute ctx_base assuming the canonical layout (lowest event at
// ctx+0x54 → ctx_base = 0xBCE251C0 when ev_addr == 0xBCE25214).
uint32_t event_offset_in_ctx = ev_addr - 0xBCE251C0;
uint32_t ctx_base = ev_addr - event_offset_in_ctx;
auto* ctx = cpu::ThreadState::Get()->context();
uint8_t* host = ctx->TranslateVirtual(ctx_base);
XELOGKERNEL(
"AUDIT-HLC silph_ctx_dump ctx_base={:08X} (event {:08X} at +{:02X})",
ctx_base, ev_addr, event_offset_in_ctx);
for (uint32_t off = 0; off < 0x300; off += 16) {
uint32_t d0 = xe::load_and_swap<uint32_t>(host + off + 0);
uint32_t d1 = xe::load_and_swap<uint32_t>(host + off + 4);
uint32_t d2 = xe::load_and_swap<uint32_t>(host + off + 8);
uint32_t d3 = xe::load_and_swap<uint32_t>(host + off + 12);
XELOGKERNEL("AUDIT-HLC DUMP {:08X}: {:08X} {:08X} {:08X} {:08X}",
ctx_base + off, d0, d1, d2, d3);
}
XELOGKERNEL("AUDIT-HLC silph_ctx event-slots:");
for (uint32_t i = 0; i < 8; ++i) {
uint32_t ev_off = 0x54 + i * 0x10;
uint32_t hdr = xe::load_and_swap<uint32_t>(host + ev_off + 0);
uint32_t state = xe::load_and_swap<uint32_t>(host + ev_off + 4);
XELOGKERNEL(
"AUDIT-HLC slot[{}] off=+{:02X} addr={:08X} hdr={:08X} "
"state={:08X}",
i, ev_off, ctx_base + ev_off, hdr, state);
}
}
}
}
return xeKeSetEvent(event_ptr, increment, wait);
}
DECLARE_XBOXKRNL_EXPORT2(KeSetEvent, kThreading, kImplemented, kHighFrequency);
@@ -639,6 +710,29 @@ dword_result_t NtCreateEvent_entry(
if (handle_ptr) {
*handle_ptr = ev->handle();
}
if (cvars::audit_handle_lifecycle) {
uint32_t lr = static_cast<uint32_t>(cpu::ThreadState::Get()->context()->lr);
uint32_t out_handle = handle_ptr ? uint32_t(*handle_ptr) : 0u;
XELOGKERNEL(
"AUDIT-HLC NtCreateEvent handle={:08X} type={} initial_state={} "
"lr={:08X}",
out_handle, uint32_t(event_type), uint32_t(initial_state), lr);
// Round-24: also log the underlying X_KEVENT guest VA for every
// NtCreateEvent so KeSetEvent probes can be cross-referenced by ptr.
XELOGKERNEL(
"AUDIT-HLC NtCreateEvent_inner handle={:08X} kevent_va={:08X} "
"lr={:08X}",
out_handle, ev->guest_object(), lr);
// When caller pinned a target handle, additionally emit the legacy
// _target line so older round-24 grep recipes still match.
if (cvars::audit_track_event_handle != 0 &&
out_handle == cvars::audit_track_event_handle) {
XELOGKERNEL(
"AUDIT-HLC NtCreateEvent_target handle={:08X} object_va={:08X} "
"lr={:08X}",
out_handle, ev->guest_object(), lr);
}
}
return X_STATUS_SUCCESS;
}
DECLARE_XBOXKRNL_EXPORT1(NtCreateEvent, kThreading, kImplemented);
@@ -664,6 +758,26 @@ uint32_t xeNtSetEvent(uint32_t handle, xe::be<uint32_t>* previous_state_ptr) {
}
dword_result_t NtSetEvent_entry(dword_t handle, lpdword_t previous_state_ptr) {
if (cvars::audit_handle_lifecycle) {
auto* ctx = cpu::ThreadState::Get()->context();
uint32_t lr = static_cast<uint32_t>(ctx->lr);
// Round-24: walk PPC back-chain for caller's guest LR (same idiom as
// NtWaitForSingleObjectEx probe).
uint32_t guest_lr = 0;
uint32_t sp = static_cast<uint32_t>(ctx->r[1]);
uint32_t back1 = xe::load_and_swap<uint32_t>(ctx->TranslateVirtual(sp));
if (back1) {
uint32_t back2 =
xe::load_and_swap<uint32_t>(ctx->TranslateVirtual(back1));
if (back2) {
guest_lr = xe::load_and_swap<uint32_t>(
ctx->TranslateVirtual(back2 - 8));
}
}
XELOGKERNEL(
"AUDIT-HLC NtSetEvent handle={:08X} lr={:08X} guest_lr={:08X}",
uint32_t(handle), lr, guest_lr);
}
return xeNtSetEvent(handle, previous_state_ptr);
}
DECLARE_XBOXKRNL_EXPORT2(NtSetEvent, kThreading, kImplemented, kHighFrequency);
@@ -1038,9 +1152,43 @@ dword_result_t NtWaitForSingleObjectEx_entry(dword_t object_handle,
dword_t wait_mode,
dword_t alertable,
lpqword_t timeout_ptr) {
uint32_t lr_enter = 0;
uint32_t guest_lr = 0;
if (cvars::audit_handle_lifecycle) {
auto* ctx = cpu::ThreadState::Get()->context();
lr_enter = static_cast<uint32_t>(ctx->lr);
// Walk one PPC stack frame up from the wait wrapper's frame to recover
// the GUEST caller's LR (lr_enter is just the kernel-internal wait
// wrapper's return address; we want the function that called *it*).
// Xbox 360 PPC convention: prologue stores caller's LR at [old_sp - 8]
// *before* bumping r1 to the new frame, so from any frame, the LR saved
// by that frame's prologue lives at (back_chain - 8). See xenia-rs
// walk_guest_back_chain in crates/xenia-kernel/src/state.rs.
uint32_t sp = static_cast<uint32_t>(ctx->r[1]);
uint32_t back1 = xe::load_and_swap<uint32_t>(ctx->TranslateVirtual(sp));
if (back1) {
uint32_t back2 =
xe::load_and_swap<uint32_t>(ctx->TranslateVirtual(back1));
if (back2) {
guest_lr = xe::load_and_swap<uint32_t>(
ctx->TranslateVirtual(back2 - 8));
}
}
XELOGKERNEL(
"AUDIT-HLC NtWaitForSingleObjectEx handle={:08X} alertable={} "
"lr={:08X} guest_lr={:08X}",
uint32_t(object_handle), uint32_t(alertable), lr_enter, guest_lr);
}
uint64_t timeout = timeout_ptr ? static_cast<uint64_t>(*timeout_ptr) : 0u;
return NtWaitForSingleObjectEx(object_handle, wait_mode, alertable,
timeout_ptr ? &timeout : nullptr);
uint32_t result = NtWaitForSingleObjectEx(object_handle, wait_mode, alertable,
timeout_ptr ? &timeout : nullptr);
if (cvars::audit_handle_lifecycle) {
XELOGKERNEL(
"AUDIT-HLC NtWaitForSingleObjectEx_done handle={:08X} result={:08X} "
"lr={:08X} guest_lr={:08X}",
uint32_t(object_handle), result, lr_enter, guest_lr);
}
return result;
}
DECLARE_XBOXKRNL_EXPORT3(NtWaitForSingleObjectEx, kThreading, kImplemented,
kBlocking, kHighFrequency);

View File

@@ -9,6 +9,7 @@
#include "xenia/kernel/xboxkrnl/xboxkrnl_video.h"
#include "xenia/base/guest_liveness.h"
#include "xenia/base/logging.h"
#include "xenia/emulator.h"
#include "xenia/gpu/graphics_system.h"
@@ -472,6 +473,10 @@ void VdSwap_entry(
lpdword_t frontbuffer_ptr, // ptr to frontbuffer address
lpdword_t texture_format_ptr, lpdword_t color_space_ptr, lpdword_t width,
lpdword_t height) {
// Guest-progress heartbeat for the hang watchdog: the game asking to present
// a frame is our "still alive" signal (diagnostics only).
xe::liveness::guest_swaps.fetch_add(1, std::memory_order_relaxed);
// All of these parameters are REQUIRED.
assert(buffer_ptr);
assert(fetch_ptr);

View File

@@ -9,6 +9,7 @@
#include "xenia/kernel/xconfig.h"
#include "xenia/base/cvar.h"
#include "xenia/base/logging.h"
#include "xenia/base/filesystem.h"
@@ -19,6 +20,17 @@
#include <ranges>
// Speaker configuration reported to the guest (XCONFIG_USER_AUDIO_FLAGS).
// Default = 0 (Digital Stereo): the Linux/ALSA APU driver's 5.1 (6-channel)
// path yields silence in some titles (e.g. Project Sylpheed missions), while
// stereo output works, so stereo is the safe default. Set to 0x00010001 for
// Dolby Digital + Pro Logic surround.
DEFINE_uint32(guest_audio_flags, 0,
"Speaker config reported to the guest (XCONFIG_USER_AUDIO_FLAGS): "
"0 = Digital Stereo (safe on Linux/ALSA), 0x00010001 = Dolby "
"Digital + Pro Logic surround.",
"APU");
namespace xe {
namespace kernel {
@@ -94,7 +106,7 @@ void XConfig::SetDefaults() {
xconfig_data_.user.language = static_cast<uint32_t>(XLanguage::kEnglish);
xconfig_data_.user.country =
static_cast<uint8_t>(XOnlineCountry::kUnitedStates);
xconfig_data_.user.audio_flags = DolbyDigital | DolbyProLogic;
xconfig_data_.user.audio_flags = cvars::guest_audio_flags;
xconfig_data_.user.av_pack_hdmi_sz = XHDTVResolution.at(1).to_host();
xconfig_data_.user.av_pack_component_sz = XHDTVResolution.at(1).to_host();
xconfig_data_.user.av_pack_vga_sz = XVGAResolution.at(3).to_host();

View File

@@ -11,6 +11,8 @@
#include "xenia/base/byte_stream.h"
#include "xenia/base/logging.h"
#include "xenia/cpu/thread_state.h"
#include "xenia/kernel/kernel_flags.h"
namespace xe {
namespace kernel {
@@ -58,6 +60,13 @@ void XEvent::InitializeNative(void* native_ptr, X_DISPATCH_HEADER* header) {
}
int32_t XEvent::Set(uint32_t priority_increment, bool wait) {
if (cvars::audit_handle_lifecycle) {
auto* ts = cpu::ThreadState::Get();
uint32_t lr = ts ? static_cast<uint32_t>(ts->context()->lr) : 0u;
XELOGKERNEL(
"AUDIT-HLC XEvent::Set handle={:08X} kevent_va={:08X} prio={} lr={:08X}",
handle(), guest_object(), priority_increment, lr);
}
set_priority_increment(priority_increment);
event_->Set();
return 1;

View File

@@ -21,6 +21,7 @@
#include "xenia/base/threading.h"
#include "xenia/cpu/processor.h"
#include "xenia/emulator.h"
#include "xenia/kernel/kernel_flags.h"
#include "xenia/kernel/kernel_state.h"
#include "xenia/kernel/user_module.h"
#include "xenia/kernel/xboxkrnl/xboxkrnl_threading.h"
@@ -116,6 +117,8 @@ XThread* XThread::GetCurrentThread() {
return thread;
}
XThread* XThread::TryGetCurrentThread() { return current_xthread_tls_; }
uint32_t XThread::GetCurrentThreadHandle() {
XThread* thread = XThread::GetCurrentThread();
return thread->handle();
@@ -544,6 +547,13 @@ X_STATUS XThread::Terminate(int exit_code) {
void XThread::Execute() {
XELOGKERNEL("XThread::Execute thid {} (handle={:08X}, '{}', native={:08X})",
thread_id_, handle(), thread_name_, thread_->system_id());
if (cvars::audit_handle_lifecycle) {
XELOGKERNEL(
"AUDIT-HLC XThread::Execute tid={} start_address={:08X} "
"start_context={:08X} xapi={:08X}",
thread_id_, creation_params_.start_address,
creation_params_.start_context, creation_params_.xapi_thread_startup);
}
// Let the kernel know we are starting.
kernel_state()->OnThreadExecute(this);

View File

@@ -408,6 +408,11 @@ class XThread : public XObject, public cpu::Thread {
static bool IsInThread(XThread* other);
static bool IsInThread();
static XThread* GetCurrentThread();
// Null-safe variant of GetCurrentThread: returns nullptr (instead of
// asserting) when the calling OS thread is not a guest XThread. Used by
// additive instrumentation that can fire from boot code before any XThread
// exists. Read-only accessor; no behaviour change.
static XThread* TryGetCurrentThread();
static uint32_t GetCurrentThreadHandle();
static uint32_t GetCurrentThreadId();

View File

@@ -1388,7 +1388,18 @@ bool BaseHeap::Release(uint32_t base_address, uint32_t* out_region_size) {
uint32_t base_page_number = (base_address - heap_base_) / page_size_;
auto base_page_entry = page_table_[base_page_number];
if (base_page_entry.base_address != base_page_number) {
XELOGE("BaseHeap::Release failed because address is not a region start");
// The guest asked us to free something we refuse to free -- it then
// believes that memory is gone while we still hold it. Say WHAT we
// refused: the address, the region we think it belongs to, and whether
// the page is even allocated. (Was a bare message with no data.)
const uint32_t owner_addr =
heap_base_ + base_page_entry.base_address * page_size_;
XELOGE(
"BaseHeap::Release failed because address is not a region start: "
"addr={:08X} heap_base={:08X} page={} owning_region_start={:08X} "
"region_page_count={} state={:02X}",
base_address, heap_base_, base_page_number, owner_addr,
base_page_entry.region_page_count, base_page_entry.state);
return false;
}

View File

@@ -332,7 +332,7 @@ else()
X86_AVX512VNNI
WITH_GZFILEOP
)
if(NOT MSVC)
if(NOT MSVC OR CMAKE_CXX_COMPILER_ID STREQUAL "Clang")
# GCC/Clang have native __builtin_ctz/__builtin_ctzll (MSVC gets these
# from fallback_builtins.h). Defining these enables optimized compare256
# and longest_match codepaths.

View File

@@ -73,6 +73,16 @@ def main():
# Start with base command — use wine on non-Windows platforms.
if sys.platform != "win32":
def _wineify(p):
try:
out = subprocess.check_output(["winepath", "-w", p],
stderr=subprocess.DEVNULL)
return out.decode("utf-8", "replace").strip()
except (OSError, subprocess.CalledProcessError):
return p
input_path = _wineify(input_path)
output_path = _wineify(output_path)
src_dir = _wineify(src_dir)
compiler_args = ["wine", fxc]
else:
compiler_args = [fxc]