7 Commits

Author SHA1 Message Date
15fe11d5d9 [HID] file-pad: implement GetKeystroke -- menus do not read GetState
Some checks failed
Orchestrator / Commit Message Validation (push) Has been skipped
Orchestrator / Lint (push) Failing after 2m3s
Orchestrator / Windows (x86-64) (push) Has been skipped
Orchestrator / Linux (x86-64) (push) Has been skipped
Orchestrator / Create Release (push) Has been skipped
The pad looked correct and did nothing. Its own log showed A arriving, the
emulator sat on "PRESS (A) BUTTON", and the title never advanced.

Cause: 360 front-ends poll XamInputGetKeystrokeEx, not XamInputGetState. This
title imports both, and its menus use the keystroke path; the driver returned
X_ERROR_EMPTY there, so every scripted press went into the void while GetState
faithfully reported a button nobody asked about.

Implement it edge-triggered, one event per call: KEYUPs for everything released
first, then KEYDOWNs, matching the SDL driver's ordering (so a thumb transition
clears before it sets). Deliberately NO auto-repeat -- scripted input wants
exactly one event per press, and repeat is precisely what makes menu steps
overshoot. Bits without a virtual key (guide, unused) are swallowed rather than
re-offered forever.

Verified on the real game: title -> main menu -> EXTRAS driven entirely from the
pad file, with `[file-pad] keystroke vk=5800 down/up` in the log for each press.
2026-08-13 20:27:38 +00:00
e3e17e4951 [HID] file-pad: nanosecond change detection, and log every state change
Some checks failed
Orchestrator / Commit Message Validation (push) Has been skipped
Orchestrator / Lint (push) Failing after 2m24s
Orchestrator / Windows (x86-64) (push) Has been skipped
Orchestrator / Linux (x86-64) (push) Has been skipped
Orchestrator / Create Release (push) Has been skipped
Two things that only show up once you actually script this pad.

st_mtime is whole seconds. Combined with size it looked like enough and is not:
a script stepping a menu writes several same-length states per second
(`press=A` then `press=B`, both 8 bytes), and every one after the first was
silently dropped -- the emulator simply did not react, with nothing in any log
to say why. Compare st_mtim.tv_nsec as well, and track whether the file existed
at all so a delete is registered once rather than every frame.

Also log one line per state change (not per frame, so it stays quiet). Driving
the emulator headless means there is nothing to watch; this line is the only
proof that a scripted press was picked up, which turns "did my input land?" from
a guess into a grep.
2026-08-13 20:14:29 +00:00
d15c8cfab6 [HID] file-pad: a controller driven by a text file, for scripted RE
Some checks failed
Orchestrator / Commit Message Validation (push) Has been skipped
Orchestrator / Lint (push) Failing after 2m24s
Orchestrator / Windows (x86-64) (push) Has been skipped
Orchestrator / Linux (x86-64) (push) Has been skipped
Orchestrator / Create Release (push) Has been skipped
The scripted-input tool this project uses for reverse engineering created its
pad through /dev/uinput. Input devices are NOT namespaced by the kernel, so a
uinput device created inside a container registers with the HOST's input stack:
every trigger hold and button press is delivered to whatever on the host reads
gamepads, not just to the emulator. That was noticed the hard way, and it made
every runtime experiment -- booting, menu navigation, unit harvesting, flight
measurement -- unusable from inside the box.

This driver takes the kernel out of the loop. Pad state lives in an ordinary
text file only the container can see; GetState re-reads it when it changes.
Nothing is registered with the host and no X server is involved. A bonus for RE:
analogue values are exact rather than whatever a virtual stick quantises to.

    press=A,START     buttons by name, comma separated
    buttons=0x1010    or the raw XINPUT mask
    lt=0 rt=255       triggers, 0..255
    lx=0 ly=0         thumbs, -32768..32767

Absent keys are neutral, so `press=A` alone is a valid file, and a missing or
empty file means no input -- the safe default if it is deleted mid-run.

Selected with --hid=file, path from --pad_file (default /tmp/xenia_pad.txt).
Deliberately NOT part of "any": this pad has to be asked for. Header-only, so it
adds no build target and no cost to anyone not using it.
2026-08-13 20:12:02 +00:00
31366e5cac [GPU] ship-capture: log each draw's index buffer, and key the de-dup on it
The offline XBG7 decoder can only assume where a block's index data lives; the
capture now states it. Each captured draw gains an `ib base=… count=… fmt=…
endian=… len=… delta_vb=… min=… max=… idx: …` line — the guest index base, the
draw's index count, and the min/max index value read out of guest memory, which
together say both where the index buffer sits relative to the vertex buffer and
how much of the vertex pool the draw covers.

Also mix the index range into the capture's de-dup key. The engine issues several
draws over one vertex buffer, each indexing a sub-range (a 119-vertex hull LOD
draws 21 indices first, then 225); keying on (vbase, transform) alone kept only
the first batch, which reads like a mysteriously short draw and cost an earlier
session a spurious "the capture disagrees with the descriptor" mystery.

Read-only diagnostics behind the existing F10 hotkey; no emulation behaviour
changes.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01NptfmpjdpNCKEez6d2xvA9
2026-08-13 05:58:02 +00:00
MechaCat02
a08526dff0 [GPU] ship-capture: numbered per-press snapshots + capture every instance
Some checks failed
Orchestrator / Commit Message Validation (push) Has been skipped
Orchestrator / Lint (push) Failing after 1m45s
Orchestrator / Windows (x86-64) (push) Has been skipped
Orchestrator / Linux (x86-64) (push) Has been skipped
Orchestrator / Create Release (push) Has been skipped
F10 now writes xenia_ship_capture_NN.log (NN = press number) so several angles
can be captured in one run without overwriting, and de-dups by (vertex-buffer
address, c0..c2 WVP hash) instead of address alone -- the same part buffer
drawn at different transforms (two engine nacelles, each ship of a fleet) now
yields one record per distinct placement. Seen-set cap raised to 8192.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
2026-07-27 20:35:20 +02:00
MechaCat02
93fe5d69df [GPU] ship-capture: also dump VS float constants (the placement matrix)
The captured vertex BUFFER holds LOCAL positions (byte-identical to the .xpr) —
capital-ship parts are placed entirely in the vertex shader, not in the buffer.
So the per-part world/WVP matrix lives in the VS float constants. Extend the F10
capture to dump the first 48 vec4 from the SQ_VS_CONST base per draw; diffing two
parts isolates the world matrix (the camera VP block is shared across draws).

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
2026-07-27 20:35:20 +02:00
MechaCat02
067a373734 [GPU] F10 ship-placement capture: dump world-space draw vertices for RE
One-shot snapshot for reversing capital-ship part placement. F10 arms
RequestShipCaptureFrame(); the next batch of draws is dumped to
xenia_ship_capture.log with each draw's guest vertex-buffer address, vertex/
index counts, and up to 64 WORLD-space vertex positions. Capital-ship parts are
transformed into world space before the draw (unlike stage geometry, which
matches the .xpr byte-for-byte), so these are ground truth for the assembled
placement; a reborn-side correlator affine-fits each decoded .xpr part to a
captured draw to recover its exact transform. De-duped by buffer address, gated
independently of the log_draws cvar, budget-capped at 8000 draws / 4096 buffers.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
2026-07-27 20:35:20 +02:00
31 changed files with 419 additions and 2439 deletions

View File

@@ -1,93 +0,0 @@
# 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

@@ -64,6 +64,12 @@
#include "xenia/hid/winkey/winkey_hid.h" #include "xenia/hid/winkey/winkey_hid.h"
#include "xenia/hid/xinput/xinput_hid.h" #include "xenia/hid/xinput/xinput_hid.h"
#endif // XE_PLATFORM_WIN32 #endif // XE_PLATFORM_WIN32
// RE aid: a controller driven by a text file instead of a kernel input device.
// A uinput pad created inside a container registers with the HOST's input stack
// (input devices are not namespaced), so scripted input leaks to the desktop.
// This one is visible only to whoever can read the file. Header-only on purpose:
// it adds no build target.
#include "xenia/hid/file/file_input_driver.h"
#if XE_PLATFORM_WIN32 #if XE_PLATFORM_WIN32
#define APU_OPTIONS "[any, nop, sdl, xaudio2]" #define APU_OPTIONS "[any, nop, sdl, xaudio2]"
@@ -72,7 +78,7 @@
#elif XE_PLATFORM_LINUX #elif XE_PLATFORM_LINUX
#define APU_OPTIONS "[any, alsa, nop, sdl]" #define APU_OPTIONS "[any, alsa, nop, sdl]"
#define GPU_OPTIONS "[any, vulkan, null]" #define GPU_OPTIONS "[any, vulkan, null]"
#define HID_OPTIONS "[any, nop, sdl]" #define HID_OPTIONS "[any, file, nop, sdl]"
#else #else
#define APU_OPTIONS "[any, nop, sdl]" #define APU_OPTIONS "[any, nop, sdl]"
#define GPU_OPTIONS "[any, vulkan, null]" #define GPU_OPTIONS "[any, vulkan, null]"
@@ -82,6 +88,11 @@
DEFINE_string(apu, "any", "Audio system. Use: " APU_OPTIONS, "APU"); DEFINE_string(apu, "any", "Audio system. Use: " APU_OPTIONS, "APU");
DEFINE_string(gpu, "any", "Graphics system. Use: " GPU_OPTIONS, "GPU"); DEFINE_string(gpu, "any", "Graphics system. Use: " GPU_OPTIONS, "GPU");
DEFINE_string(hid, "any", "Input system. Use: " HID_OPTIONS, "HID"); DEFINE_string(hid, "any", "Input system. Use: " HID_OPTIONS, "HID");
DEFINE_string(pad_file, "/tmp/xenia_pad.txt",
"Controller state file read by `--hid=file`: key=value pairs such "
"as `press=A,START lt=0 rt=255 lx=0 ly=0`. Absent keys are "
"neutral, a missing file means no input.",
"HID");
DEFINE_path( DEFINE_path(
storage_root, "", storage_root, "",
@@ -446,6 +457,10 @@ std::vector<std::unique_ptr<hid::InputDriver>> EmulatorApp::CreateInputDrivers(
if (cvars::hid.compare("nop") == 0) { if (cvars::hid.compare("nop") == 0) {
drivers.emplace_back( drivers.emplace_back(
xe::hid::nop::Create(window, EmulatorWindow::kZOrderHidInput)); xe::hid::nop::Create(window, EmulatorWindow::kZOrderHidInput));
} else if (cvars::hid.compare("file") == 0) {
// Explicit, never part of "any": this pad must be asked for.
drivers.emplace_back(
xe::hid::filepad::Create(window, EmulatorWindow::kZOrderHidInput));
} else { } else {
Factory<hid::InputDriver, ui::Window*, size_t> factory; Factory<hid::InputDriver, ui::Window*, size_t> factory;
#if XE_PLATFORM_WIN32 #if XE_PLATFORM_WIN32

View File

@@ -20,7 +20,6 @@
#endif #endif
#include "xenia/apu/apu_flags.h" #include "xenia/apu/apu_flags.h"
#include "xenia/apu/audio_watchdog.h"
#include "xenia/apu/conversion.h" #include "xenia/apu/conversion.h"
#include "xenia/base/assert.h" #include "xenia/base/assert.h"
#include "xenia/base/clock.h" #include "xenia/base/clock.h"
@@ -316,8 +315,6 @@ void ALSAAudioDriver::WorkerThread() {
snd_pcm_writei(pcm_handle_, silence.get(), silence_frames); snd_pcm_writei(pcm_handle_, silence.get(), silence_frames);
while (running_) { while (running_) {
watchdog::alsa_state.store(static_cast<int>(snd_pcm_state(pcm_handle_)),
std::memory_order_relaxed);
if (paused_) { if (paused_) {
snd_pcm_drop(pcm_handle_); snd_pcm_drop(pcm_handle_);
std::this_thread::sleep_for(std::chrono::milliseconds(10)); std::this_thread::sleep_for(std::chrono::milliseconds(10));
@@ -359,8 +356,6 @@ void ALSAAudioDriver::WorkerThread() {
snd_pcm_writei(pcm_handle_, silence.get(), period_size_); snd_pcm_writei(pcm_handle_, silence.get(), period_size_);
if (w < 0) { if (w < 0) {
RecoverFromUnderrun(w); RecoverFromUnderrun(w);
} else {
watchdog::alsa_silence.fetch_add(1, std::memory_order_relaxed);
} }
} else { } else {
std::this_thread::sleep_for(std::chrono::milliseconds(2)); std::this_thread::sleep_for(std::chrono::milliseconds(2));
@@ -456,7 +451,6 @@ void ALSAAudioDriver::WorkerThread() {
} else if (written != (snd_pcm_sframes_t)frames_to_write) { } else if (written != (snd_pcm_sframes_t)frames_to_write) {
XELOGW("Partial write: {} of {} frames", written, 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 // Move to next frame in ring buffer
// Use release semantics so writer thread sees this update // Use release semantics so writer thread sees this update
@@ -476,7 +470,6 @@ void ALSAAudioDriver::WorkerThread() {
} }
bool ALSAAudioDriver::RecoverFromUnderrun(int err) { bool ALSAAudioDriver::RecoverFromUnderrun(int err) {
watchdog::alsa_xruns.fetch_add(1, std::memory_order_relaxed);
if (err == -EPIPE) { if (err == -EPIPE) {
// Underrun occurred // Underrun occurred
XELOGW("ALSA underrun detected, recovering..."); XELOGW("ALSA underrun detected, recovering...");

View File

@@ -10,9 +10,3 @@
#include "xenia/apu/apu_flags.h" #include "xenia/apu/apu_flags.h"
DEFINE_bool(mute, false, "Mutes all audio output.", "APU") 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,6 +12,5 @@
#include "xenia/base/cvar.h" #include "xenia/base/cvar.h"
DECLARE_bool(mute) DECLARE_bool(mute)
DECLARE_bool(audio_watchdog)
#endif // XENIA_APU_APU_FLAGS_H_ #endif // XENIA_APU_APU_FLAGS_H_

View File

@@ -13,7 +13,6 @@
#include "xenia/apu/apu_flags.h" #include "xenia/apu/apu_flags.h"
#include "xenia/apu/audio_driver.h" #include "xenia/apu/audio_driver.h"
#include "xenia/apu/audio_watchdog.h"
#include "xenia/apu/xma_decoder.h" #include "xenia/apu/xma_decoder.h"
#include "xenia/base/assert.h" #include "xenia/base/assert.h"
#include "xenia/base/byte_stream.h" #include "xenia/base/byte_stream.h"
@@ -67,173 +66,12 @@ 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 AudioSystem::Setup(kernel::KernelState* kernel_state) {
X_STATUS result = xma_decoder_->Setup(kernel_state); X_STATUS result = xma_decoder_->Setup(kernel_state);
if (result) { if (result) {
return 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_running_ = true;
worker_thread_ = worker_thread_ =
kernel::object_ref<kernel::XHostThread>(new kernel::XHostThread( kernel::object_ref<kernel::XHostThread>(new kernel::XHostThread(
@@ -264,8 +102,6 @@ void AudioSystem::WorkerThreadMain() {
// a host output slot is free, otherwise it is dropped (the host queue // a host output slot is free, otherwise it is dropped (the host queue
// is full, so it is already well buffered). // is full, so it is already well buffered).
while (worker_running_) { while (worker_running_) {
watchdog::worker_loops.fetch_add(1, std::memory_order_relaxed);
const uint64_t now = static_cast<uint64_t>( const uint64_t now = static_cast<uint64_t>(
std::chrono::duration_cast<std::chrono::microseconds>( std::chrono::duration_cast<std::chrono::microseconds>(
std::chrono::steady_clock::now().time_since_epoch()) std::chrono::steady_clock::now().time_since_epoch())
@@ -276,17 +112,9 @@ void AudioSystem::WorkerThreadMain() {
uint32_t client_callback = 0; uint32_t client_callback = 0;
uint32_t client_callback_arg = 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(); 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) { for (size_t i = 0; i < kMaximumClientCount; ++i) {
if (clients_[i].in_use) {
++in_use_count;
}
if (!clients_[i].in_use || if (!clients_[i].in_use ||
clients_[i].next_pump_us >= earliest_pump_us) { clients_[i].next_pump_us >= earliest_pump_us) {
continue; continue;
@@ -294,7 +122,6 @@ void AudioSystem::WorkerThreadMain() {
earliest_pump_us = clients_[i].next_pump_us; earliest_pump_us = clients_[i].next_pump_us;
client_index = i; client_index = i;
} }
watchdog::clients_in_use.store(in_use_count, std::memory_order_relaxed);
if (client_index != kMaximumClientCount) { if (client_index != kMaximumClientCount) {
client_callback = clients_[client_index].callback; client_callback = clients_[client_index].callback;
@@ -311,8 +138,6 @@ void AudioSystem::WorkerThreadMain() {
// No clients yet: park until one registers or we're told to stop. // No clients yet: park until one registers or we're told to stop.
if (client_index == kMaximumClientCount) { if (client_index == kMaximumClientCount) {
watchdog::worker_phase.store(watchdog::WorkerPhase::kParkedNoClient,
std::memory_order_relaxed);
xe::threading::Wait(pending_work_event_.get(), true); xe::threading::Wait(pending_work_event_.get(), true);
if (paused_) { if (paused_) {
pause_fence_.Signal(); pause_fence_.Signal();
@@ -326,8 +151,6 @@ void AudioSystem::WorkerThreadMain() {
? earliest_pump_us - kAudioIntervalSlack ? earliest_pump_us - kAudioIntervalSlack
: 0; : 0;
if (wake_target_us > now) { 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); const std::chrono::milliseconds timeout((wake_target_us - now) / 1000);
auto result = auto result =
xe::threading::Wait(pending_work_event_.get(), true, timeout); xe::threading::Wait(pending_work_event_.get(), true, timeout);
@@ -349,30 +172,14 @@ void AudioSystem::WorkerThreadMain() {
} }
// Submit only if the host has a free output slot; // Submit only if the host has a free output slot;
const bool have_slot = if (client_callback &&
client_callback &&
xe::threading::Wait(client_semaphores_[client_index].get(), false, xe::threading::Wait(client_semaphores_[client_index].get(), false,
std::chrono::milliseconds(0)) == 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"); SCOPE_profile_cpu_i("apu", "xe::apu::AudioSystem->client_callback");
uint64_t args[] = {client_callback_arg}; 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, processor_->Execute(worker_thread_->thread_state(), client_callback, args,
xe::countof(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; worker_running_ = false;
@@ -394,13 +201,6 @@ int AudioSystem::FindFreeClient() {
void AudioSystem::Initialize() {} void AudioSystem::Initialize() {}
void AudioSystem::Shutdown() { void AudioSystem::Shutdown() {
if (watchdog_running_) {
watchdog_running_ = false;
if (watchdog_thread_.joinable()) {
watchdog_thread_.join();
}
}
worker_running_ = false; worker_running_ = false;
pending_work_event_->Set(); pending_work_event_->Set();
if (worker_thread_) { if (worker_thread_) {
@@ -461,12 +261,6 @@ X_STATUS AudioSystem::RegisterClient(uint32_t callback, uint32_t callback_arg,
clients_[index].wrapped_callback_arg = ptr; clients_[index].wrapped_callback_arg = ptr;
clients_[index].in_use = true; 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. // Wake the worker so it re-scans and starts pacing this client immediately.
pending_work_event_->Set(); pending_work_event_->Set();
@@ -483,8 +277,6 @@ X_STATUS AudioSystem::RegisterClient(uint32_t callback, uint32_t callback_arg,
void AudioSystem::SubmitFrame(size_t index, float* samples) { void AudioSystem::SubmitFrame(size_t index, float* samples) {
SCOPE_profile_cpu_f("apu"); SCOPE_profile_cpu_f("apu");
watchdog::frames_submitted.fetch_add(1, std::memory_order_relaxed);
auto global_lock = global_critical_region_.Acquire(); auto global_lock = global_critical_region_.Acquire();
assert_true(index < kMaximumClientCount); assert_true(index < kMaximumClientCount);
if (index >= kMaximumClientCount || !clients_[index].in_use || if (index >= kMaximumClientCount || !clients_[index].in_use ||
@@ -510,12 +302,6 @@ void AudioSystem::SubmitFrame(size_t index, float* samples) {
void AudioSystem::UnregisterClient(size_t index) { void AudioSystem::UnregisterClient(size_t index) {
SCOPE_profile_cpu_f("apu"); 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(); auto global_lock = global_critical_region_.Acquire();
assert_true(index < kMaximumClientCount); assert_true(index < kMaximumClientCount);
DestroyDriver(clients_[index].driver); DestroyDriver(clients_[index].driver);

View File

@@ -1,104 +0,0 @@
/**
******************************************************************************
* 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,18 +9,7 @@
#include "xenia/apu/xma_context_master.h" #include "xenia/apu/xma_context_master.h"
#include <cstdio>
#include <cstring> #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_decoder.h"
#include "xenia/apu/xma_helpers.h" #include "xenia/apu/xma_helpers.h"
@@ -328,39 +317,6 @@ void XmaContextMaster::Decode(XMA_CONTEXT_DATA* data) {
: nullptr; : nullptr;
uint8_t* current_input_buffer = data->current_buffer ? in1 : in0; 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(), // XELOGAPU("Processing context {} (offset {}, buffer {}, ptr {:p})", id(),
// data->input_buffer_read_offset, data->current_buffer, // data->input_buffer_read_offset, data->current_buffer,
// current_input_buffer); // current_input_buffer);

View File

@@ -10,19 +10,10 @@
#include "xenia/apu/xma_context_new.h" #include "xenia/apu/xma_context_new.h"
#include "xenia/apu/xma_helpers.h" #include "xenia/apu/xma_helpers.h"
#include <cstdio>
#include <mutex>
#include <set>
#include "xenia/base/cvar.h"
#include "xenia/base/logging.h" #include "xenia/base/logging.h"
#include "xenia/base/platform.h" #include "xenia/base/platform.h"
#include "xenia/base/profiling.h" #include "xenia/base/profiling.h"
// [Phase-A / audio RE] Defined in xma_context_master.cc; declared here so the
// probe fires in the DEFAULT ("new") decoder — the one the game actually uses.
DECLARE_bool(xma_param_probe);
extern "C" { extern "C" {
#if XE_COMPILER_MSVC #if XE_COMPILER_MSVC
#pragma warning(push) #pragma warning(push)
@@ -401,66 +392,6 @@ void XmaContextNew::Decode(XMA_CONTEXT_DATA* data) {
uint8_t* current_input_buffer = GetCurrentInputBuffer(data); uint8_t* current_input_buffer = GetCurrentInputBuffer(data);
// [Phase-A / audio RE] Additive, cvar-gated probe (default-off, read-only).
// Capture the true XMA per-stream parameters the game supplies, keyed by
// (input buffer ptr, packet count) — the pair is unique per sub-wave, so it
// tells us WHICH sub-wave of a movie's `.slb` the game actually decodes. No
// behaviour change. Lives in the DEFAULT decoder so it observes the real
// playback path; probes WHICHEVER buffer is current (0 or 1).
if (cvars::xma_param_probe) {
static std::once_flag xma_probe_alive;
std::call_once(xma_probe_alive, [this]() {
XELOGW("XMA-PROBE active (ctx {} first decode) — cvar parsed OK", id());
});
const uint32_t buf = data->current_buffer;
const uint32_t buf_ptr = buf ? data->input_buffer_1_ptr
: data->input_buffer_0_ptr;
const uint32_t buf_pkts = buf ? data->input_buffer_1_packet_count
: data->input_buffer_0_packet_count;
if (data->IsCurrentInputBufferValid() && buf_pkts) {
uint8_t* in = memory()->TranslatePhysical(buf_ptr);
if (in) {
static std::mutex xma_probe_mu;
static std::set<uint64_t> xma_probe_seen;
uint64_t key = (static_cast<uint64_t>(buf_ptr) << 20) ^
static_cast<uint64_t>(buf_pkts);
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", in[i]);
}
// Deep content signature: 48 bytes taken well into the stream (the
// first packet header is identical across all voices, so it can't
// discriminate). This uniquely fingerprints the actual recording, so
// the played voice can be matched back to a specific `.slb` blob
// regardless of the (scrambled) file name. `byte_size` = the XMA input
// size (packets * 2048), itself a strong discriminator.
const uint32_t byte_size = buf_pkts * 2048u;
const uint32_t sig_off = byte_size > 1088u ? 1024u : 0u;
char sig[97];
for (int i = 0; i < 48; ++i) {
std::snprintf(sig + i * 2, 3, "%02x", in[sig_off + i]);
}
XELOGW(
"XMA-PARAM ctx={} buf={} ptr=0x{:08x} read_off={} stereo={} "
"channels={} rate_id={} rate={} packets={} byte_size={} "
"sig_off={} head={} sig={}",
id(), buf, buf_ptr,
static_cast<uint32_t>(data->input_buffer_read_offset),
static_cast<uint32_t>(data->is_stereo), data->is_stereo ? 2 : 1,
static_cast<uint32_t>(data->sample_rate),
GetSampleRate(data->sample_rate), buf_pkts, byte_size, sig_off,
head, sig);
}
}
}
}
input_buffer_.fill(0); input_buffer_.fill(0);
// Detect if we're about to decode the loop end frame (before // Detect if we're about to decode the loop end frame (before

View File

@@ -9,7 +9,6 @@
#include "xenia/apu/xma_decoder.h" #include "xenia/apu/xma_decoder.h"
#include "xenia/apu/audio_watchdog.h"
#include "xenia/apu/xma_context.h" #include "xenia/apu/xma_context.h"
#include "xenia/apu/xma_context_fake.h" #include "xenia/apu/xma_context_fake.h"
#include "xenia/apu/xma_context_master.h" #include "xenia/apu/xma_context_master.h"
@@ -200,7 +199,6 @@ void XmaDecoder::WorkerThreadMain() {
for (uint32_t n = 0; n < kContextCount; n++) { for (uint32_t n = 0; n < kContextCount; n++) {
bool worked = contexts_[n]->Work(); bool worked = contexts_[n]->Work();
if (worked) { if (worked) {
watchdog::xma_works.fetch_add(1, std::memory_order_relaxed);
contexts_[n]->SignalWorkDone(); contexts_[n]->SignalWorkDone();
} }
did_work = did_work || worked; did_work = did_work || worked;
@@ -411,13 +409,6 @@ void XmaDecoder::Pause() {
} }
paused_ = true; 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(); pause_fence_.Wait();
} }

View File

@@ -1,35 +0,0 @@
/**
******************************************************************************
* 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

@@ -14,7 +14,6 @@
#include "xenia/base/platform.h" #include "xenia/base/platform.h"
#include "xenia/base/threading_timer_queue.h" #include "xenia/base/threading_timer_queue.h"
#include <atomic>
#include <pthread.h> #include <pthread.h>
#include <sched.h> #include <sched.h>
#include <semaphore.h> #include <semaphore.h>
@@ -982,22 +981,11 @@ class PosixCondition<Thread> final : public PosixConditionBase {
static void* ThreadStartRoutine(void* parameter); static void* ThreadStartRoutine(void* parameter);
bool signaled() const override { return signaled_; } bool signaled() const override { return signaled_; }
void post_execution() override { 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_) { if (thread_) {
pthread_join(thread_, nullptr); pthread_join(thread_, nullptr);
} }
sem_destroy(&suspend_sem_); sem_destroy(&suspend_sem_);
} }
std::atomic<bool> reaped_{false};
pthread_t thread_; pthread_t thread_;
pid_t tid_ = 0; // Kernel TID for setpriority() fallback pid_t tid_ = 0; // Kernel TID for setpriority() fallback
mutable bool fifo_failed_ = false; // True after SCHED_FIFO was rejected mutable bool fifo_failed_ = false; // True after SCHED_FIFO was rejected

View File

@@ -57,34 +57,3 @@ DEFINE_bool(break_condition_truncate, true, "truncate value to 32-bits", "CPU");
DEFINE_bool(break_on_debugbreak, true, "int3 on JITed __debugbreak requests.", DEFINE_bool(break_on_debugbreak, true, "int3 on JITed __debugbreak requests.",
"CPU"); "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_bool(phase_a_fileio_only, false,
"Phase A extraction (LIGHTWEIGHT): emit ONLY file opens (path) and "
"file.read events (path/offset/length) — no per-export import/kernel "
"call spam. Use to trace which sound.pak/movie bytes a title reads "
"(e.g. movie->voice mapping) without perturbing timing. 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,11 +35,4 @@ DECLARE_bool(break_condition_truncate);
DECLARE_bool(break_on_debugbreak); 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_ #endif // XENIA_CPU_CPU_FLAGS_H_

View File

@@ -1568,101 +1568,18 @@ 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"); auto pdata = this->GetPESection(".pdata");
XELOGE("PDATA-SCAN reached; pdata_section={}",
pdata ? "FOUND" : "NULL");
if (pdata) { if (pdata) {
uint32_t* pdata_base = uint32_t* pdata_base =
(uint32_t*)this->memory()->TranslateVirtual(pdata->address); (uint32_t*)this->memory()->TranslateVirtual(pdata->address);
uint32_t n_pdata_entries = pdata->raw_size / 8; 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) { for (uint32_t i = 0; i < n_pdata_entries; ++i) {
uint32_t funcaddr = xe::load_and_swap<uint32_t>(&pdata_base[i * 2]); uint32_t funcaddr = xe::load_and_swap<uint32_t>(&pdata_base[i * 2]);
if (funcaddr >= low_address_ && funcaddr <= highest_exec_addr) { if (funcaddr >= low_address_ && funcaddr <= highest_exec_addr) {
add_new_func(funcaddr); 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 { } else {
// we hit 0 for func addr, that means we're done // we hit 0 for func addr, that means we're done
break; break;

View File

@@ -30,13 +30,10 @@
#include "xenia/base/platform.h" #include "xenia/base/platform.h"
#include "xenia/base/string.h" #include "xenia/base/string.h"
#include "xenia/base/system.h" #include "xenia/base/system.h"
#include "xenia/base/guest_liveness.h"
#include "xenia/cpu/backend/code_cache.h" #include "xenia/cpu/backend/code_cache.h"
#include "xenia/cpu/backend/null_backend.h" #include "xenia/cpu/backend/null_backend.h"
#include "xenia/cpu/cpu_flags.h" #include "xenia/cpu/cpu_flags.h"
#include "xenia/cpu/ppc/ppc_context.h"
#include "xenia/cpu/thread_state.h" #include "xenia/cpu/thread_state.h"
#include "xenia/kernel/xthread.h"
#include "xenia/gpu/command_processor.h" #include "xenia/gpu/command_processor.h"
#include "xenia/gpu/graphics_system.h" #include "xenia/gpu/graphics_system.h"
#include "xenia/hid/input_driver.h" #include "xenia/hid/input_driver.h"
@@ -95,12 +92,6 @@ DEFINE_int32(priority_class, 0,
"values: 0 - Normal, 1 - Above normal, 2 - High", "values: 0 - Normal, 1 - Above normal, 2 - High",
"General"); "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 { namespace xe {
using namespace xe::literals; using namespace xe::literals;
@@ -175,13 +166,6 @@ Emulator::Emulator(const std::filesystem::path& command_line,
Emulator::~Emulator() { Emulator::~Emulator() {
// Note that we delete things in the reverse order they were initialized. // 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. // Give the systems time to shutdown before we delete them.
if (graphics_system_) { if (graphics_system_) {
graphics_system_->Shutdown(); graphics_system_->Shutdown();
@@ -324,53 +308,6 @@ X_STATUS Emulator::Setup(
XELOGI("{}: Initializing Kernel...", __func__); XELOGI("{}: Initializing Kernel...", __func__);
// Shared kernel state. // Shared kernel state.
kernel_state_ = std::make_unique<xe::kernel::KernelState>(this); 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) \ #define LOAD_KERNEL_MODULE(t) \
static_cast<void>(kernel_state_->LoadKernelModule<kernel::t>()) static_cast<void>(kernel_state_->LoadKernelModule<kernel::t>())
// HLE kernel modules. // HLE kernel modules.
@@ -595,72 +532,6 @@ Emulator::FileSignatureType Emulator::GetFileSignature(
return FileSignatureType::Unknown; 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 Emulator::LaunchPath(const std::filesystem::path& path) {
X_STATUS mount_result = X_STATUS_SUCCESS; X_STATUS mount_result = X_STATUS_SUCCESS;

View File

@@ -10,13 +10,11 @@
#ifndef XENIA_EMULATOR_H_ #ifndef XENIA_EMULATOR_H_
#define XENIA_EMULATOR_H_ #define XENIA_EMULATOR_H_
#include <atomic>
#include <cstddef> #include <cstddef>
#include <cstdint> #include <cstdint>
#include <functional> #include <functional>
#include <optional> #include <optional>
#include <string> #include <string>
#include <thread>
#include <vector> #include <vector>
#include "xenia/apu/audio_media_player.h" #include "xenia/apu/audio_media_player.h"
@@ -311,12 +309,6 @@ class Emulator {
xe::Delegate<> on_exit; xe::Delegate<> on_exit;
private: 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 }; enum : uint64_t { EmulatorFlagDisclaimerAcknowledged = 1ULL << 0 };
static uint64_t GetPersistentEmulatorFlags(); static uint64_t GetPersistentEmulatorFlags();
static void SetPersistentEmulatorFlags(uint64_t new_flags); static void SetPersistentEmulatorFlags(uint64_t new_flags);

View File

@@ -215,7 +215,19 @@ void CommandProcessor::CaptureShipDrawForRE(
uint32_t bits = register_file_->values[r]; uint32_t bits = register_file_->values[r];
th = (th ^ bits) * 1099511628211ull; th = (th ^ bits) * 1099511628211ull;
} }
uint64_t key = (uint64_t(vbase) << 32) ^ (th & 0xFFFFFFFFull) ^ (th >> 32); // Mix the index range into the key as well (added 2026-08-13). The engine
// issues SEVERAL draws over one vertex buffer, each with its own index
// sub-range (the first Stage_02 capture showed a 119-vertex hull LOD drawn
// with 21 indices) — keying on (vbase, transform) alone kept only the first
// batch, which reads like a mysteriously short draw. With the range in the key
// every batch is recorded, so the block's full index extent is observable.
uint64_t ib_key = 0;
if (index_buffer_info) {
ib_key = (uint64_t(index_buffer_info->guest_base) << 20) ^
uint64_t(index_buffer_info->count);
}
uint64_t key = (uint64_t(vbase) << 32) ^ (th & 0xFFFFFFFFull) ^ (th >> 32) ^
(ib_key * 1099511628211ull);
if (!cap_seen.insert(key).second) { if (!cap_seen.insert(key).second) {
return; return;
} }
@@ -227,6 +239,47 @@ void CommandProcessor::CaptureShipDrawForRE(
"DRAW vbase=0x{:08X} stride={} vcount={} indices={} prim={} vs=0x{:016X}\n", "DRAW vbase=0x{:08X} stride={} vcount={} indices={} prim={} vs=0x{:016X}\n",
vbase, stride, vcount, uint32_t(init.num_indices), vbase, stride, vcount, uint32_t(init.num_indices),
uint32_t(init.prim_type), vs->ucode_data_hash()); uint32_t(init.prim_type), vs->ucode_data_hash());
// The guest's INDEX buffer for this draw. Our offline mesh decoder only
// *assumes* the index buffer sits immediately before the vertex buffer; this
// line is the ground truth for that assumption (ib base vs vbase), and the
// decoded min/max index says how much of the vertex pool the draw really
// covers — which is what the `indices=` field alone cannot answer.
if (index_buffer_info) {
const auto& ib = *index_buffer_info;
bool i32 = ib.format == xenos::IndexFormat::kInt32;
uint32_t icount = ib.count;
cap_out << fmt::format(
" ib base=0x{:08X} count={} fmt={} endian={} len={} delta_vb={}",
ib.guest_base, icount, i32 ? "u32" : "u16", uint32_t(ib.endianness),
ib.length, int64_t(vbase) - int64_t(ib.guest_base));
const uint8_t* ip = memory_->TranslatePhysical<const uint8_t*>(ib.guest_base);
if (ip && icount) {
uint32_t scan = icount < 65536 ? icount : 65536;
uint32_t imin = 0xFFFFFFFFu, imax = 0;
auto rd = [&](uint32_t k) -> uint32_t {
// Guest index data is big-endian in memory (the endianness field says
// how the GPU swaps it); read it that way and record the field so the
// offline side can compensate if a draw ever differs.
const uint8_t* q = ip + (i32 ? k * 4 : k * 2);
return i32 ? (uint32_t(q[0]) << 24) | (uint32_t(q[1]) << 16) |
(uint32_t(q[2]) << 8) | uint32_t(q[3])
: (uint32_t(q[0]) << 8) | uint32_t(q[1]);
};
for (uint32_t k = 0; k < scan; ++k) {
uint32_t v = rd(k);
if (v < imin) imin = v;
if (v > imax) imax = v;
}
cap_out << fmt::format(" min={} max={} idx:", imin, imax);
uint32_t nd = icount < 24 ? icount : 24;
for (uint32_t k = 0; k < nd; ++k) {
cap_out << fmt::format(" {}", rd(k));
}
}
cap_out << "\n";
} else {
cap_out << " ib auto\n";
}
uint32_t n = vcount < 64 ? vcount : 64; uint32_t n = vcount < 64 ? vcount : 64;
cap_out << " pos:"; cap_out << " pos:";
auto be_f32 = [](const uint8_t* q) { auto be_f32 = [](const uint8_t* q) {

View File

@@ -0,0 +1,341 @@
/**
******************************************************************************
* Xenia : Xbox 360 Emulator Research Project *
******************************************************************************
* RE aid: a controller whose state comes from a FILE, not from a device.
******************************************************************************
*/
#ifndef XENIA_HID_FILE_FILE_INPUT_DRIVER_H_
#define XENIA_HID_FILE_FILE_INPUT_DRIVER_H_
// Why this exists
// ---------------
// The scripted-input tool used for reverse engineering created its pad through
// `/dev/uinput`. Input devices are NOT namespaced by the kernel, so a uinput
// device created inside a container is registered with the HOST's input stack:
// every trigger hold and button press is delivered to whatever on the host reads
// gamepads, not only to the emulator. That is a real leak, and it was noticed the
// hard way.
//
// This driver takes the kernel out of the loop entirely. The pad state lives in
// an ordinary text file that only this container can see, and `GetState` reads it
// (re-parsing only when the file changes). Nothing is registered with the host,
// no X server is involved either, and — a bonus for RE — the analogue values are
// exact rather than whatever a virtual stick quantises to.
//
// File format: one or more whitespace/newline separated `key=value` pairs.
//
// press=A,START buttons by name (see kButtonNames), comma separated
// buttons=0x1010 or the raw XINPUT mask, if you prefer
// lt=0 rt=255 triggers, 0..255
// lx=0 ly=0 left thumb, -32768..32767
// rx=0 ry=0 right thumb, -32768..32767
//
// Anything absent is neutral, so `press=A` alone is a valid file. An empty or
// missing file means "no input" — which is also the safe default if the file is
// deleted mid-run.
//
// Path: `--pad_file=<path>`, default `/tmp/xenia_pad.txt`. Only user 0 is
// connected; other slots report no device, as a single-pad console would.
#include <cstdint>
#include <cstdio>
#include <cstring>
#include <memory>
#include <string>
#include <sys/stat.h>
#include "xenia/base/cvar.h"
#include "xenia/base/logging.h"
#include "xenia/hid/input_driver.h"
#include "xenia/ui/virtual_key.h"
DECLARE_string(pad_file);
namespace xe {
namespace hid {
namespace filepad {
struct NamedButton {
const char* name;
uint16_t mask;
};
static constexpr NamedButton kButtonNames[] = {
{"UP", X_INPUT_GAMEPAD_DPAD_UP},
{"DOWN", X_INPUT_GAMEPAD_DPAD_DOWN},
{"LEFT", X_INPUT_GAMEPAD_DPAD_LEFT},
{"RIGHT", X_INPUT_GAMEPAD_DPAD_RIGHT},
{"START", X_INPUT_GAMEPAD_START},
{"BACK", X_INPUT_GAMEPAD_BACK},
{"LS", X_INPUT_GAMEPAD_LEFT_THUMB},
{"RS", X_INPUT_GAMEPAD_RIGHT_THUMB},
{"LB", X_INPUT_GAMEPAD_LEFT_SHOULDER},
{"RB", X_INPUT_GAMEPAD_RIGHT_SHOULDER},
{"A", X_INPUT_GAMEPAD_A},
{"B", X_INPUT_GAMEPAD_B},
{"X", X_INPUT_GAMEPAD_X},
{"Y", X_INPUT_GAMEPAD_Y},
};
class FileInputDriver final : public InputDriver {
public:
FileInputDriver(xe::ui::Window* window, size_t window_z_order)
: InputDriver(window, window_z_order) {}
~FileInputDriver() override = default;
X_STATUS Setup() override {
XELOGI("[file-pad] reading controller state from {}", cvars::pad_file);
return X_STATUS_SUCCESS;
}
X_RESULT GetCapabilities(uint32_t user_index, uint32_t flags,
X_INPUT_CAPABILITIES* out_caps) override {
if (user_index != 0) {
return X_ERROR_DEVICE_NOT_CONNECTED;
}
std::memset(out_caps, 0, sizeof(*out_caps));
out_caps->type = 0x01; // XINPUT_DEVTYPE_GAMEPAD
out_caps->sub_type = 0x01; // XINPUT_DEVSUBTYPE_GAMEPAD
out_caps->flags = 0;
out_caps->gamepad.buttons = 0xFFFF;
out_caps->gamepad.left_trigger = 0xFF;
out_caps->gamepad.right_trigger = 0xFF;
out_caps->gamepad.thumb_lx = static_cast<int16_t>(0xFFFFu);
out_caps->gamepad.thumb_ly = static_cast<int16_t>(0xFFFFu);
out_caps->gamepad.thumb_rx = static_cast<int16_t>(0xFFFFu);
out_caps->gamepad.thumb_ry = static_cast<int16_t>(0xFFFFu);
return X_ERROR_SUCCESS;
}
X_RESULT GetState(uint32_t user_index, X_INPUT_STATE* out_state) override {
if (user_index != 0) {
return X_ERROR_DEVICE_NOT_CONNECTED;
}
Refresh();
std::memset(out_state, 0, sizeof(*out_state));
out_state->packet_number = packet_;
out_state->gamepad.buttons = buttons_;
out_state->gamepad.left_trigger = lt_;
out_state->gamepad.right_trigger = rt_;
out_state->gamepad.thumb_lx = lx_;
out_state->gamepad.thumb_ly = ly_;
out_state->gamepad.thumb_rx = rx_;
out_state->gamepad.thumb_ry = ry_;
return X_ERROR_SUCCESS;
}
X_RESULT SetState(uint32_t user_index, X_INPUT_VIBRATION* vibration) override {
return user_index == 0 ? X_ERROR_SUCCESS : X_ERROR_DEVICE_NOT_CONNECTED;
}
// Menus do NOT read the pad through GetState. "PRESS (A) BUTTON" and most
// 360 front-ends poll XamInputGetKeystrokeEx, so a driver that only answers
// GetState looks completely dead on a title screen while its own log happily
// shows the button arriving. Returning X_ERROR_EMPTY here is what made the
// first scripted run press A into the void.
//
// One event per call, edge triggered: KEYUPs for everything released, then
// KEYDOWNs for everything pressed, exactly as the SDL driver orders them.
// Deliberately NO auto-repeat — scripted input wants precisely one event per
// press, and repeat is what makes menu steps overshoot.
X_RESULT GetKeystroke(uint32_t user_index, uint32_t flags,
X_INPUT_KEYSTROKE* out_keystroke) override {
const bool user_any = user_index == 0xFF || user_index == 0xFFFFFFFFu;
if (!user_any && user_index != 0) {
return X_ERROR_DEVICE_NOT_CONNECTED;
}
if (!out_keystroke) {
return X_ERROR_BAD_ARGUMENTS;
}
Refresh();
// Bit index in X_INPUT_GAMEPAD::buttons -> virtual key. Order matters: it is
// the order multiple simultaneous changes are reported in.
static constexpr uint16_t kVk[16] = {
uint16_t(ui::VirtualKey::kXInputPadDpadUp),
uint16_t(ui::VirtualKey::kXInputPadDpadDown),
uint16_t(ui::VirtualKey::kXInputPadDpadLeft),
uint16_t(ui::VirtualKey::kXInputPadDpadRight),
uint16_t(ui::VirtualKey::kXInputPadStart),
uint16_t(ui::VirtualKey::kXInputPadBack),
uint16_t(ui::VirtualKey::kXInputPadLThumbPress),
uint16_t(ui::VirtualKey::kXInputPadRThumbPress),
uint16_t(ui::VirtualKey::kXInputPadLShoulder),
uint16_t(ui::VirtualKey::kXInputPadRShoulder),
0, /* guide */
0, /* unused */
uint16_t(ui::VirtualKey::kXInputPadA),
uint16_t(ui::VirtualKey::kXInputPadB),
uint16_t(ui::VirtualKey::kXInputPadX),
uint16_t(ui::VirtualKey::kXInputPadY),
};
const uint16_t changed = static_cast<uint16_t>(buttons_ ^ reported_);
if (!changed) {
return X_ERROR_EMPTY;
}
for (int pass = 0; pass < 2; ++pass) {
const bool clear_pass = pass == 0;
for (uint8_t i = 0; i < 16; ++i) {
const uint16_t bit = static_cast<uint16_t>(1u << i);
if (!(changed & bit) || kVk[i] == 0) {
continue;
}
const bool pressed = (buttons_ & bit) != 0;
if (clear_pass == pressed) {
continue;
}
reported_ = static_cast<uint16_t>(pressed ? (reported_ | bit)
: (reported_ & ~bit));
out_keystroke->virtual_key = kVk[i];
out_keystroke->unicode = 0;
out_keystroke->flags =
pressed ? X_INPUT_KEYSTROKE_KEYDOWN : X_INPUT_KEYSTROKE_KEYUP;
out_keystroke->user_index = 0;
out_keystroke->hid_code = 0;
XELOGI("[file-pad] keystroke vk={:04X} {}", kVk[i],
pressed ? "down" : "up");
return X_ERROR_SUCCESS;
}
}
// Only bits without a virtual key changed (guide/unused): swallow them so
// the caller is not asked again forever.
reported_ = buttons_;
return X_ERROR_EMPTY;
}
InputType GetInputType() const override { return InputType::Controller; }
private:
// Re-parse only when the file actually changed: `GetState` is polled every
// frame and a stat is far cheaper than a read+parse.
//
// The change test uses **nanosecond** mtime, not `st_mtime`. Whole-second
// granularity plus size looked sufficient and is not: a script that steps a
// menu writes several same-length states per second (`press=A` then `press=B`,
// both 8 bytes), and every one of those after the first would be silently
// dropped. That failure is invisible — the emulator just does not react — so
// it is worth the extra field.
void Refresh() {
struct stat st;
if (::stat(cvars::pad_file.c_str(), &st) != 0) {
if (present_) {
present_ = false;
Neutral();
++packet_;
XELOGI("[file-pad] {} gone -> neutral", cvars::pad_file);
}
return;
}
if (present_ && st.st_mtim.tv_sec == mtime_sec_ &&
st.st_mtim.tv_nsec == mtime_nsec_ && st.st_size == size_) {
return;
}
present_ = true;
mtime_sec_ = st.st_mtim.tv_sec;
mtime_nsec_ = st.st_mtim.tv_nsec;
size_ = st.st_size;
std::FILE* f = std::fopen(cvars::pad_file.c_str(), "rb");
if (!f) {
Neutral();
return;
}
char buf[512] = {0};
size_t n = std::fread(buf, 1, sizeof(buf) - 1, f);
std::fclose(f);
buf[n] = '\0';
Parse(buf);
++packet_;
// One line per change (not per frame): with no display to watch, this log is
// the only proof that a scripted press was actually picked up.
XELOGI("[file-pad] #{} buttons={:04X} lt={} rt={} lx={} ly={} rx={} ry={}",
packet_, buttons_, lt_, rt_, lx_, ly_, rx_, ry_);
}
void Neutral() {
buttons_ = 0;
lt_ = rt_ = 0;
lx_ = ly_ = rx_ = ry_ = 0;
}
void Parse(const char* text) {
Neutral();
std::string s(text);
size_t pos = 0;
while (pos < s.size()) {
size_t end = s.find_first_of(" \t\r\n", pos);
if (end == std::string::npos) {
end = s.size();
}
std::string tok = s.substr(pos, end - pos);
pos = end + 1;
size_t eq = tok.find('=');
if (eq == std::string::npos) {
continue;
}
std::string key = tok.substr(0, eq), val = tok.substr(eq + 1);
if (key == "press") {
size_t p = 0;
while (p < val.size()) {
size_t c = val.find(',', p);
if (c == std::string::npos) {
c = val.size();
}
std::string name = val.substr(p, c - p);
p = c + 1;
for (const auto& b : kButtonNames) {
if (name == b.name) {
buttons_ |= b.mask;
break;
}
}
}
} else if (key == "buttons") {
buttons_ |= static_cast<uint16_t>(std::strtoul(val.c_str(), nullptr, 0));
} else if (key == "lt") {
lt_ = Clamp8(std::strtol(val.c_str(), nullptr, 0));
} else if (key == "rt") {
rt_ = Clamp8(std::strtol(val.c_str(), nullptr, 0));
} else if (key == "lx") {
lx_ = Clamp16(std::strtol(val.c_str(), nullptr, 0));
} else if (key == "ly") {
ly_ = Clamp16(std::strtol(val.c_str(), nullptr, 0));
} else if (key == "rx") {
rx_ = Clamp16(std::strtol(val.c_str(), nullptr, 0));
} else if (key == "ry") {
ry_ = Clamp16(std::strtol(val.c_str(), nullptr, 0));
}
}
}
static uint8_t Clamp8(long v) {
return static_cast<uint8_t>(v < 0 ? 0 : (v > 255 ? 255 : v));
}
static int16_t Clamp16(long v) {
return static_cast<int16_t>(v < -32768 ? -32768 : (v > 32767 ? 32767 : v));
}
uint16_t buttons_ = 0;
uint8_t lt_ = 0, rt_ = 0;
int16_t lx_ = 0, ly_ = 0, rx_ = 0, ry_ = 0;
uint32_t packet_ = 1;
// Buttons already reported through GetKeystroke; the edge detector's memory.
uint16_t reported_ = 0;
bool present_ = false;
time_t mtime_sec_ = 0;
long mtime_nsec_ = -1;
off_t size_ = -1;
};
inline std::unique_ptr<InputDriver> Create(xe::ui::Window* window,
size_t window_z_order) {
return std::make_unique<FileInputDriver>(window, window_z_order);
}
} // namespace filepad
} // namespace hid
} // namespace xe
#endif // XENIA_HID_FILE_FILE_INPUT_DRIVER_H_

View File

@@ -1,726 +0,0 @@
/**
******************************************************************************
* 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_bool(phase_a_fileio_only);
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) {
auto* ctx = reinterpret_cast<::xe::cpu::ppc::PPCContext*>(ppc_context);
if (cvars::phase_a_fileio_only) {
// Lightweight file-I/O-only mode: emit ONLY file opens (name + resolved
// path) and file.read events (path/offset/length). No import.call/kernel.call
// per-export spam, so a timing-sensitive title stays performant. For
// non-file exports both helpers early-out on a cheap name check.
std::string path = ResolvePathArg(name, ctx);
if (!path.empty()) {
::xe::kernel::phase_a::EmitKernelCallWithPath(name, path.c_str());
}
MaybeEmitFileRead(name, ctx);
return;
}
::xe::kernel::phase_a::EmitImportCall(module_name, ord, name);
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) {
// File-I/O-only tracing captures everything on the call side (opens + reads),
// so suppress the per-export return spam — it dominated the log (millions of
// lines / GBs) and perturbs timing.
if (cvars::phase_a_fileio_only) return;
::xe::kernel::phase_a::EmitKernelReturn(name, return_value);
}
} // namespace phase_a_bridge
} // namespace shim
} // namespace kernel
} // namespace xe

View File

@@ -1,191 +0,0 @@
/**
******************************************************************************
* 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

@@ -9,14 +9,6 @@
#include <ranges> #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/kernel/kernel_state.h"
#include "xenia/base/byte_stream.h" #include "xenia/base/byte_stream.h"
@@ -49,69 +41,9 @@ DEFINE_uint32(kernel_build_version, 1888, "Define current kernel version",
DECLARE_string(cl); 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 xe {
namespace kernel { 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); constexpr std::chrono::milliseconds kDeferredOverlappedDelayMillis(25);
// This is a global object initialized with the XboxkrnlModule. // This is a global object initialized with the XboxkrnlModule.
@@ -146,16 +78,9 @@ KernelState::KernelState(Emulator* emulator)
kMemoryProtectRead | kMemoryProtectWrite); kMemoryProtectRead | kMemoryProtectWrite);
xenia_assert(fixed_alloc_worked); 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() { KernelState::~KernelState() {
g_mem_watch_run.store(false, std::memory_order_relaxed);
SetExecutableModule(nullptr); SetExecutableModule(nullptr);
if (dispatch_thread_running_) { if (dispatch_thread_running_) {

View File

@@ -479,29 +479,6 @@ enum class KernelModuleId {
xbdm, 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> template <size_t I = 0, typename... Ps>
requires(I == sizeof...(Ps)) requires(I == sizeof...(Ps))
void AppendKernelCallParams(StringBuffer& string_buffer, void AppendKernelCallParams(StringBuffer& string_buffer,
@@ -581,26 +558,14 @@ struct ExportRegistrerHelper {
cvars::log_high_frequency_kernel_calls)) { cvars::log_high_frequency_kernel_calls)) {
PrintKernelCall(export_entry, params); 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) { if constexpr (std::is_void<R>::value) {
KernelTrampoline(fn, std::forward<std::tuple<Ps...>>(params), KernelTrampoline(fn, std::forward<std::tuple<Ps...>>(params),
std::make_index_sequence<sizeof...(Ps)>()); std::make_index_sequence<sizeof...(Ps)>());
if (phase_a_on) {
phase_a_bridge::EmitReturn(export_entry->name, 0);
}
} else { } else {
auto result = auto result =
KernelTrampoline(fn, std::forward<std::tuple<Ps...>>(params), KernelTrampoline(fn, std::forward<std::tuple<Ps...>>(params),
std::make_index_sequence<sizeof...(Ps)>()); std::make_index_sequence<sizeof...(Ps)>());
result.Store(ppc_context); result.Store(ppc_context);
if (phase_a_on) {
phase_a_bridge::EmitReturn(export_entry->name, 0);
}
if (TAGS & if (TAGS &
(xe::cpu::ExportTag::kLog | xe::cpu::ExportTag::kLogResult)) { (xe::cpu::ExportTag::kLog | xe::cpu::ExportTag::kLogResult)) {
// TODO(benvanik): log result. // TODO(benvanik): log result.

View File

@@ -7,9 +7,7 @@
****************************************************************************** ******************************************************************************
*/ */
#include "xenia/apu/apu_flags.h"
#include "xenia/apu/audio_system.h" #include "xenia/apu/audio_system.h"
#include "xenia/base/logging.h"
#include "xenia/emulator.h" #include "xenia/emulator.h"
#include "xenia/kernel/kernel_state.h" #include "xenia/kernel/kernel_state.h"
#include "xenia/kernel/util/shim_utils.h" #include "xenia/kernel/util/shim_utils.h"
@@ -57,13 +55,8 @@ DECLARE_XBOXKRNL_EXPORT2(XAudioGetVoiceCategoryVolume, kAudio, kStub,
dword_result_t XAudioEnableDucker_entry(dword_t unk) { return X_ERROR_SUCCESS; } dword_result_t XAudioEnableDucker_entry(dword_t unk) { return X_ERROR_SUCCESS; }
DECLARE_XBOXKRNL_EXPORT1(XAudioEnableDucker, kAudio, kStub); DECLARE_XBOXKRNL_EXPORT1(XAudioEnableDucker, kAudio, kStub);
dword_result_t XAudioRegisterRenderDriverClient_entry( dword_result_t XAudioRegisterRenderDriverClient_entry(lpdword_t callback_ptr,
lpdword_t callback_ptr, lpdword_t driver_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) { if (!callback_ptr) {
return X_E_INVALIDARG; return X_E_INVALIDARG;
} }
@@ -91,17 +84,9 @@ DECLARE_XBOXKRNL_EXPORT1(XAudioRegisterRenderDriverClient, kAudio,
kImplemented); kImplemented);
dword_result_t XAudioUnregisterRenderDriverClient_entry( dword_result_t XAudioUnregisterRenderDriverClient_entry(
lpunknown_t driver_ptr, const ppc_context_t& ppc_context) { lpunknown_t driver_ptr) {
assert_true((driver_ptr.guest_address() & 0xFFFF0000) == 0x41550000); 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(); auto audio_system = kernel_state()->emulator()->audio_system();
audio_system->UnregisterClient(driver_ptr.guest_address() & 0x0000FFFF); audio_system->UnregisterClient(driver_ptr.guest_address() & 0x0000FFFF);
return X_ERROR_SUCCESS; return X_ERROR_SUCCESS;

View File

@@ -7,17 +7,8 @@
****************************************************************************** ******************************************************************************
*/ */
#include <algorithm>
#include <map>
#include <set>
#include <vector>
#include "xenia/base/cvar.h"
#include "xenia/base/debugging.h" #include "xenia/base/debugging.h"
#include "xenia/base/logging.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/emulator.h"
#include "xenia/kernel/kernel_state.h" #include "xenia/kernel/kernel_state.h"
#include "xenia/kernel/util/shim_utils.h" #include "xenia/kernel/util/shim_utils.h"
@@ -28,22 +19,6 @@
#include "xenia/ui/window.h" #include "xenia/ui/window.h"
#include "xenia/ui/windowed_app_context.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 xe {
namespace kernel { namespace kernel {
namespace xboxkrnl { namespace xboxkrnl {
@@ -129,468 +104,6 @@ typedef struct {
xe::be<uint32_t> catchable_type_array_ptr; xe::be<uint32_t> catchable_type_array_ptr;
} x_s__ThrowInfo; } 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) { void HandleCppException(pointer_t<X_EXCEPTION_RECORD> record) {
// C++ exception. // C++ exception.
// https://blogs.msdn.com/b/oldnewthing/archive/2010/07/30/10044061.aspx // https://blogs.msdn.com/b/oldnewthing/archive/2010/07/30/10044061.aspx
@@ -615,29 +128,13 @@ void HandleCppException(pointer_t<X_EXCEPTION_RECORD> record) {
XELOGE("Guest attempted to throw a C++ exception!"); 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) { switch (record->code) {
case 0x406D1388: { case 0x406D1388: {
HandleSetThreadName(record); HandleSetThreadName(record);
return; return;
} }
case 0xE06D7363: { 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); HandleCppException(record);
return; return;
} }

View File

@@ -783,15 +783,6 @@ void IoDeleteDevice_entry(dword_t device_ptr, const ppc_context_t& ctx) {
DECLARE_XBOXKRNL_EXPORT1(IoDeleteDevice, kFileSystem, kStub); 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 xboxkrnl
} // namespace kernel } // namespace kernel
} // namespace xe } // namespace xe

View File

@@ -9,7 +9,6 @@
#include "xenia/kernel/xboxkrnl/xboxkrnl_video.h" #include "xenia/kernel/xboxkrnl/xboxkrnl_video.h"
#include "xenia/base/guest_liveness.h"
#include "xenia/base/logging.h" #include "xenia/base/logging.h"
#include "xenia/emulator.h" #include "xenia/emulator.h"
#include "xenia/gpu/graphics_system.h" #include "xenia/gpu/graphics_system.h"
@@ -473,10 +472,6 @@ void VdSwap_entry(
lpdword_t frontbuffer_ptr, // ptr to frontbuffer address lpdword_t frontbuffer_ptr, // ptr to frontbuffer address
lpdword_t texture_format_ptr, lpdword_t color_space_ptr, lpdword_t width, lpdword_t texture_format_ptr, lpdword_t color_space_ptr, lpdword_t width,
lpdword_t height) { 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. // All of these parameters are REQUIRED.
assert(buffer_ptr); assert(buffer_ptr);
assert(fetch_ptr); assert(fetch_ptr);

View File

@@ -117,8 +117,6 @@ XThread* XThread::GetCurrentThread() {
return thread; return thread;
} }
XThread* XThread::TryGetCurrentThread() { return current_xthread_tls_; }
uint32_t XThread::GetCurrentThreadHandle() { uint32_t XThread::GetCurrentThreadHandle() {
XThread* thread = XThread::GetCurrentThread(); XThread* thread = XThread::GetCurrentThread();
return thread->handle(); return thread->handle();

View File

@@ -408,11 +408,6 @@ class XThread : public XObject, public cpu::Thread {
static bool IsInThread(XThread* other); static bool IsInThread(XThread* other);
static bool IsInThread(); static bool IsInThread();
static XThread* GetCurrentThread(); 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 GetCurrentThreadHandle();
static uint32_t GetCurrentThreadId(); static uint32_t GetCurrentThreadId();

View File

@@ -1388,18 +1388,7 @@ bool BaseHeap::Release(uint32_t base_address, uint32_t* out_region_size) {
uint32_t base_page_number = (base_address - heap_base_) / page_size_; uint32_t base_page_number = (base_address - heap_base_) / page_size_;
auto base_page_entry = page_table_[base_page_number]; auto base_page_entry = page_table_[base_page_number];
if (base_page_entry.base_address != base_page_number) { if (base_page_entry.base_address != base_page_number) {
// The guest asked us to free something we refuse to free -- it then XELOGE("BaseHeap::Release failed because address is not a region start");
// 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; return false;
} }