Compare commits
6 Commits
f970a5173f
...
capture-sh
| Author | SHA1 | Date | |
|---|---|---|---|
|
|
3ba56a5005 | ||
|
|
87d02d59f1 | ||
|
|
201553aea3 | ||
|
|
7b6902e08f | ||
|
|
0aa3eadca7 | ||
|
|
a40bc50159 |
93
HANDOFF-crash-oracle-2026-07-16.md
Normal file
93
HANDOFF-crash-oracle-2026-07-16.md
Normal file
@@ -0,0 +1,93 @@
|
||||
# HANDOFF — Ready-Room crash: NEW ORACLE says it's OUR code, not the game (2026-07-16)
|
||||
|
||||
## TL;DR
|
||||
The mid-game **crash** (guest `std::out_of_range` from the cache-manager flush, seen in the
|
||||
**Ready Room** after a mission) is **introduced by our own changes**, not by the game and not by the
|
||||
build toolchain. A clean bisection of our 19 commits + uncommitted working tree will find it.
|
||||
|
||||
## The new oracle (this is the key result)
|
||||
We built **stock upstream `6e5b8324f` `[APU] Pace audio subsystem`** with our own toolchain and
|
||||
**zero custom code** (0 custom cvars in the binary — verified). The user ran it:
|
||||
|
||||
> **Stock `6e5b8324f` → NO crash, NO sound-stop, played through the Ready Room fine.**
|
||||
|
||||
This kills two earlier hypotheses and re-frames the whole problem:
|
||||
|
||||
| Hypothesis | Verdict |
|
||||
|---|---|
|
||||
| "Genuine game data race, unfixable without masking" | **WRONG.** Stock game code is stable. |
|
||||
| "Our build chain miscompiles (broken LTO) → crash" | **WRONG.** Same toolchain, stock source, no crash. |
|
||||
| "The crash is in OUR 19 commits + 16 working-tree files" | **This is where it is.** Bisect it. |
|
||||
|
||||
The out_of_range race is real, but it's **our timing changes** that push a concurrent cache-add into
|
||||
the flush's unlocked iteration window. Stock timing never lands there.
|
||||
|
||||
### Reproduce the oracle
|
||||
```bash
|
||||
cd "/home/fabi/RE - Project Sylpheed/xenia-canary-native"
|
||||
git stash push -u
|
||||
git checkout 6e5b8324f4101464de0f8c2334edb03cac8826c4
|
||||
git submodule update --init third_party/DirectXShaderCompiler third_party/snappy # sync to stock pins
|
||||
cmake --build build --config Release --target xenia_canary -j16 # reuses object cache
|
||||
# copy bin/Linux/Release/xenia_canary aside, then restore:
|
||||
git checkout <this-branch>
|
||||
git -C third_party/DirectXShaderCompiler checkout dc3e6c48d
|
||||
git -C third_party/snappy checkout 77c78fad
|
||||
git stash pop
|
||||
```
|
||||
A prebuilt stock binary from this session is at `../stock-oracle/xenia_canary_STOCK_6e5b832`
|
||||
(see "Artifacts" below). Run any binary through the launcher with `CANARY_BIN=<path> ./run-canary-native.sh`.
|
||||
|
||||
## Build-chain note (real, but NOT the crash cause)
|
||||
Our LTO is silently disabled: `clang++` is **LLVM 18.1.3** but the linker's gold LTO plugin is
|
||||
**LLVM 17.0.6**, so the plugin rejects clang-18 bitcode —
|
||||
`failed to create LTO module: Unknown attribute kind (91)` **×420** (≈ every TU). ThinLTO is not
|
||||
applied; our codegen differs from the fully-LTO'd official AppImage. Harmless for the crash (proven by
|
||||
the oracle) but worth fixing for release parity: install/point at a matching `LLVMgold.so` (llvm-18),
|
||||
or build `ld.lld`+`-fuse-ld=lld` which handles LTO in-tree, or disable LTO explicitly.
|
||||
|
||||
## Bisection plan (suspects ranked by how much they perturb guest thread timing)
|
||||
Each test = one build + one Ready-Room run. Do them in order; stop at the first that removes the crash.
|
||||
|
||||
1. **`mem_watch` polling thread — FREE, no rebuild.** `kernel_state.cc` adds a detached host thread
|
||||
(default **`--mem_watch=true`**) that wakes every 3 s and *reads the guest cache-manager memory* —
|
||||
the exact struct the crash is about. Test: run our binary with `--mem_watch=false`.
|
||||
→ no crash = default it off / remove it; keep every real fix. **Best case.**
|
||||
2. **Threading edits (uncommitted, load-bearing).** `threading_posix.cc` reap-once double-join fix +
|
||||
`xma_decoder.cc work_event_->Set()` in `Pause()`. These *cure* the mission-teardown freeze +
|
||||
permanent audio-death (see `project_audio_stall_freeze_diagnostics_2026_07_14`). Rebuild with them
|
||||
reverted to stock; test. → **If these are the trigger, it's a real trade-off** (crash vs
|
||||
freeze/audio-death) and needs a smarter fix, e.g. make the guest cache-flush loop
|
||||
(PC `0x8245A154..0x8245A1CC`) atomic w.r.t. other guest threads instead of reverting the reap fix.
|
||||
3. Other audio-fix files: `audio_system.cc` (+218), `xma_context_master.cc` (+44),
|
||||
`xboxkrnl_audio.cc`, `apu_flags.*`, `alsa_audio_driver.cc`.
|
||||
4. Committed audio fix `f10484834 [APU] Fix mission-audio silence`.
|
||||
5. event_log Phase-A trampoline per-export overhead (`shim_utils.h`, committed).
|
||||
|
||||
Faster alternative to 2–5: `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 1–17 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)
|
||||
@@ -1067,6 +1067,11 @@ void EmulatorWindow::OnKeyDown(ui::KeyEvent& e) {
|
||||
case ui::VirtualKey::kF12: {
|
||||
TakeScreenshot();
|
||||
} break;
|
||||
case ui::VirtualKey::kF10: {
|
||||
// RE: snapshot the next frame's draws (world-space vertex positions) to
|
||||
// xenia_ship_capture.log for capital-ship placement correlation.
|
||||
xe::gpu::RequestShipCaptureFrame();
|
||||
} break;
|
||||
|
||||
case ui::VirtualKey::kEscape: {
|
||||
// Allow users to escape fullscreen (but not enter it).
|
||||
|
||||
@@ -20,6 +20,7 @@
|
||||
#endif
|
||||
|
||||
#include "xenia/apu/apu_flags.h"
|
||||
#include "xenia/apu/audio_watchdog.h"
|
||||
#include "xenia/apu/conversion.h"
|
||||
#include "xenia/base/assert.h"
|
||||
#include "xenia/base/clock.h"
|
||||
@@ -315,6 +316,8 @@ void ALSAAudioDriver::WorkerThread() {
|
||||
snd_pcm_writei(pcm_handle_, silence.get(), silence_frames);
|
||||
|
||||
while (running_) {
|
||||
watchdog::alsa_state.store(static_cast<int>(snd_pcm_state(pcm_handle_)),
|
||||
std::memory_order_relaxed);
|
||||
if (paused_) {
|
||||
snd_pcm_drop(pcm_handle_);
|
||||
std::this_thread::sleep_for(std::chrono::milliseconds(10));
|
||||
@@ -356,6 +359,8 @@ void ALSAAudioDriver::WorkerThread() {
|
||||
snd_pcm_writei(pcm_handle_, silence.get(), period_size_);
|
||||
if (w < 0) {
|
||||
RecoverFromUnderrun(w);
|
||||
} else {
|
||||
watchdog::alsa_silence.fetch_add(1, std::memory_order_relaxed);
|
||||
}
|
||||
} else {
|
||||
std::this_thread::sleep_for(std::chrono::milliseconds(2));
|
||||
@@ -451,6 +456,7 @@ void ALSAAudioDriver::WorkerThread() {
|
||||
} else if (written != (snd_pcm_sframes_t)frames_to_write) {
|
||||
XELOGW("Partial write: {} of {} frames", written, frames_to_write);
|
||||
}
|
||||
watchdog::alsa_writes.fetch_add(1, std::memory_order_relaxed);
|
||||
|
||||
// Move to next frame in ring buffer
|
||||
// Use release semantics so writer thread sees this update
|
||||
@@ -470,6 +476,7 @@ void ALSAAudioDriver::WorkerThread() {
|
||||
}
|
||||
|
||||
bool ALSAAudioDriver::RecoverFromUnderrun(int err) {
|
||||
watchdog::alsa_xruns.fetch_add(1, std::memory_order_relaxed);
|
||||
if (err == -EPIPE) {
|
||||
// Underrun occurred
|
||||
XELOGW("ALSA underrun detected, recovering...");
|
||||
|
||||
@@ -10,3 +10,9 @@
|
||||
#include "xenia/apu/apu_flags.h"
|
||||
|
||||
DEFINE_bool(mute, false, "Mutes all audio output.", "APU")
|
||||
|
||||
DEFINE_bool(audio_watchdog, false,
|
||||
"Report which stage of the audio pipeline stopped when audio dies "
|
||||
"(guest callback / XMA decode / frame submit / ALSA write). "
|
||||
"Diagnostics only.",
|
||||
"APU")
|
||||
|
||||
@@ -12,5 +12,6 @@
|
||||
|
||||
#include "xenia/base/cvar.h"
|
||||
DECLARE_bool(mute)
|
||||
DECLARE_bool(audio_watchdog)
|
||||
|
||||
#endif // XENIA_APU_APU_FLAGS_H_
|
||||
|
||||
@@ -13,6 +13,7 @@
|
||||
|
||||
#include "xenia/apu/apu_flags.h"
|
||||
#include "xenia/apu/audio_driver.h"
|
||||
#include "xenia/apu/audio_watchdog.h"
|
||||
#include "xenia/apu/xma_decoder.h"
|
||||
#include "xenia/base/assert.h"
|
||||
#include "xenia/base/byte_stream.h"
|
||||
@@ -66,12 +67,173 @@ AudioSystem::~AudioSystem() {
|
||||
}
|
||||
}
|
||||
|
||||
namespace {
|
||||
|
||||
// --- audio watchdog (diagnostics, --audio_watchdog, default off) -------------
|
||||
// Samples the pipeline-stage counters in audio_watchdog.h once a second and
|
||||
// reports which stage stopped when audio dies. Deliberately near-silent while
|
||||
// healthy: log spam of its own would starve the very pipeline it watches.
|
||||
|
||||
std::atomic<bool> watchdog_running_{false};
|
||||
std::thread watchdog_thread_;
|
||||
|
||||
uint64_t WatchdogNowUs() {
|
||||
return static_cast<uint64_t>(
|
||||
std::chrono::duration_cast<std::chrono::microseconds>(
|
||||
std::chrono::steady_clock::now().time_since_epoch())
|
||||
.count());
|
||||
}
|
||||
|
||||
const char* AlsaStateName(int state) {
|
||||
// snd_pcm_state_t, kept as an int so we need no ALSA header here.
|
||||
static const char* kNames[] = {"OPEN", "SETUP", "PREPARED",
|
||||
"RUNNING", "XRUN", "DRAINING",
|
||||
"PAUSED", "SUSPENDED", "DISCONNECTED"};
|
||||
if (state < 0 || state >= static_cast<int>(xe::countof(kNames))) {
|
||||
return "?";
|
||||
}
|
||||
return kNames[state];
|
||||
}
|
||||
|
||||
void AudioWatchdogMain() {
|
||||
xe::threading::set_name("Audio Watchdog");
|
||||
|
||||
uint64_t last_pumps = 0, last_submits = 0, last_xma = 0;
|
||||
uint64_t last_writes = 0, last_silence = 0, last_xruns = 0;
|
||||
uint64_t last_loops = 0, last_skips = 0;
|
||||
bool was_alive = true;
|
||||
bool ever_alive = false;
|
||||
uint64_t dead_ticks = 0;
|
||||
|
||||
while (watchdog_running_) {
|
||||
std::this_thread::sleep_for(std::chrono::seconds(1));
|
||||
if (!watchdog_running_) {
|
||||
break;
|
||||
}
|
||||
|
||||
using namespace xe::apu::watchdog;
|
||||
const uint64_t pumps = guest_pumps.load(std::memory_order_relaxed);
|
||||
const uint64_t submits = frames_submitted.load(std::memory_order_relaxed);
|
||||
const uint64_t xma = xma_works.load(std::memory_order_relaxed);
|
||||
const uint64_t writes = alsa_writes.load(std::memory_order_relaxed);
|
||||
const uint64_t silence = alsa_silence.load(std::memory_order_relaxed);
|
||||
const uint64_t xruns = alsa_xruns.load(std::memory_order_relaxed);
|
||||
|
||||
const uint64_t d_pumps = pumps - last_pumps;
|
||||
const uint64_t d_submits = submits - last_submits;
|
||||
const uint64_t d_xma = xma - last_xma;
|
||||
const uint64_t d_writes = writes - last_writes;
|
||||
const uint64_t d_silence = silence - last_silence;
|
||||
const uint64_t d_xruns = xruns - last_xruns;
|
||||
last_pumps = pumps;
|
||||
last_submits = submits;
|
||||
last_xma = xma;
|
||||
last_writes = writes;
|
||||
last_silence = silence;
|
||||
last_xruns = xruns;
|
||||
|
||||
// How long has the APU worker been stuck inside guest code? The guest
|
||||
// callback runs on the pump thread, so a guest block here kills audio
|
||||
// permanently -- this is the prime suspect for "sound never comes back".
|
||||
const uint64_t in_guest_since =
|
||||
in_guest_callback_since_us.load(std::memory_order_relaxed);
|
||||
const double stuck_s =
|
||||
in_guest_since ? (WatchdogNowUs() - in_guest_since) / 1000000.0 : 0.0;
|
||||
|
||||
// "Alive" = the guest is still producing audio. Prefer real frames reaching
|
||||
// the device, but fall back to pumps so this also works under --apu=nop
|
||||
// (silent stress runs, where there is no host device to write to).
|
||||
const bool alive = d_writes > 0 || d_pumps > 0;
|
||||
|
||||
const uint64_t loops = worker_loops.load(std::memory_order_relaxed);
|
||||
const uint64_t skips = pump_skips.load(std::memory_order_relaxed);
|
||||
const int clients = clients_in_use.load(std::memory_order_relaxed);
|
||||
const uint64_t regs = register_calls.load(std::memory_order_relaxed);
|
||||
const uint64_t unregs = unregister_calls.load(std::memory_order_relaxed);
|
||||
const uint64_t d_loops = loops - last_loops;
|
||||
const uint64_t d_skips = skips - last_skips;
|
||||
last_loops = loops;
|
||||
last_skips = skips;
|
||||
|
||||
const auto phase = worker_phase.load(std::memory_order_relaxed);
|
||||
|
||||
// Name the culprit stage, walking the pipeline from the guest outward. The
|
||||
// worker's own recorded phase beats any inference we could make from the
|
||||
// outside, so trust it first.
|
||||
const char* culprit = "";
|
||||
if (!alive) {
|
||||
if (stuck_s >= 1.0) {
|
||||
culprit = "guest audio callback BLOCKED (pump thread stuck in guest)";
|
||||
} else if (d_loops == 0 &&
|
||||
phase == WorkerPhase::kAcquiringGlobalLock) {
|
||||
culprit =
|
||||
"APU worker BLOCKED on the kernel global lock (someone else holds "
|
||||
"it)";
|
||||
} else if (d_loops == 0 && phase == WorkerPhase::kParkedNoClient) {
|
||||
culprit =
|
||||
"NO AUDIO CLIENT: guest unregistered it and never re-registered";
|
||||
} else if (d_pumps == 0 && d_loops == 0) {
|
||||
culprit = "worker stalled -- see phase=";
|
||||
} else if (d_pumps == 0 && d_skips > 0) {
|
||||
culprit = "worker looping but never gets a free output slot (semaphore)";
|
||||
} else if (d_pumps == 0) {
|
||||
culprit = "APU worker not pumping the guest callback";
|
||||
} else if (d_submits == 0) {
|
||||
culprit = "guest pumping but submitting no frames (starved upstream)";
|
||||
} else if (d_xma == 0 && xma > 0) {
|
||||
culprit = "XMA decoder stopped doing work";
|
||||
} else {
|
||||
culprit = "frames submitted but host driver is not writing them";
|
||||
}
|
||||
}
|
||||
|
||||
if (!alive) {
|
||||
dead_ticks++;
|
||||
}
|
||||
if (alive) {
|
||||
ever_alive = true;
|
||||
}
|
||||
|
||||
// Stay quiet until audio has actually played once: silence during boot /
|
||||
// menus is not the bug. Then log every transition and once a second while
|
||||
// dead -- "it was playing and then it stopped" is precisely the event.
|
||||
if (!ever_alive) {
|
||||
was_alive = alive;
|
||||
continue;
|
||||
}
|
||||
|
||||
if (alive != was_alive || !alive) {
|
||||
XELOGW(
|
||||
"AUDIO-WD [{}] +pumps={} +submits={} +xma={} +writes={} "
|
||||
"+silence={} +xruns={} +loops={} +skips={} clients={} reg={} "
|
||||
"unreg={} phase={} pcm={} guest_cb_stuck={:.1f}s dead={}s {}",
|
||||
alive ? "OK" : "DEAD", d_pumps, d_submits, d_xma, d_writes, d_silence,
|
||||
d_xruns, d_loops, d_skips, clients, regs, unregs,
|
||||
WorkerPhaseName(phase),
|
||||
AlsaStateName(alsa_state.load(std::memory_order_relaxed)), stuck_s,
|
||||
dead_ticks, culprit);
|
||||
}
|
||||
if (alive) {
|
||||
dead_ticks = 0;
|
||||
}
|
||||
was_alive = alive;
|
||||
}
|
||||
}
|
||||
|
||||
} // namespace
|
||||
|
||||
X_STATUS AudioSystem::Setup(kernel::KernelState* kernel_state) {
|
||||
X_STATUS result = xma_decoder_->Setup(kernel_state);
|
||||
if (result) {
|
||||
return result;
|
||||
}
|
||||
|
||||
if (cvars::audio_watchdog && !watchdog_running_) {
|
||||
watchdog_running_ = true;
|
||||
watchdog_thread_ = std::thread(AudioWatchdogMain);
|
||||
XELOGW("AUDIO-WD watchdog armed (reports the stage that stops on silence)");
|
||||
}
|
||||
|
||||
worker_running_ = true;
|
||||
worker_thread_ =
|
||||
kernel::object_ref<kernel::XHostThread>(new kernel::XHostThread(
|
||||
@@ -102,6 +264,8 @@ void AudioSystem::WorkerThreadMain() {
|
||||
// a host output slot is free, otherwise it is dropped (the host queue
|
||||
// is full, so it is already well buffered).
|
||||
while (worker_running_) {
|
||||
watchdog::worker_loops.fetch_add(1, std::memory_order_relaxed);
|
||||
|
||||
const uint64_t now = static_cast<uint64_t>(
|
||||
std::chrono::duration_cast<std::chrono::microseconds>(
|
||||
std::chrono::steady_clock::now().time_since_epoch())
|
||||
@@ -112,9 +276,17 @@ void AudioSystem::WorkerThreadMain() {
|
||||
uint32_t client_callback = 0;
|
||||
uint32_t client_callback_arg = 0;
|
||||
{
|
||||
watchdog::worker_phase.store(watchdog::WorkerPhase::kAcquiringGlobalLock,
|
||||
std::memory_order_relaxed);
|
||||
auto global_lock = global_critical_region_.Acquire();
|
||||
watchdog::worker_phase.store(watchdog::WorkerPhase::kStart,
|
||||
std::memory_order_relaxed);
|
||||
|
||||
int in_use_count = 0;
|
||||
for (size_t i = 0; i < kMaximumClientCount; ++i) {
|
||||
if (clients_[i].in_use) {
|
||||
++in_use_count;
|
||||
}
|
||||
if (!clients_[i].in_use ||
|
||||
clients_[i].next_pump_us >= earliest_pump_us) {
|
||||
continue;
|
||||
@@ -122,6 +294,7 @@ void AudioSystem::WorkerThreadMain() {
|
||||
earliest_pump_us = clients_[i].next_pump_us;
|
||||
client_index = i;
|
||||
}
|
||||
watchdog::clients_in_use.store(in_use_count, std::memory_order_relaxed);
|
||||
|
||||
if (client_index != kMaximumClientCount) {
|
||||
client_callback = clients_[client_index].callback;
|
||||
@@ -138,6 +311,8 @@ void AudioSystem::WorkerThreadMain() {
|
||||
|
||||
// No clients yet: park until one registers or we're told to stop.
|
||||
if (client_index == kMaximumClientCount) {
|
||||
watchdog::worker_phase.store(watchdog::WorkerPhase::kParkedNoClient,
|
||||
std::memory_order_relaxed);
|
||||
xe::threading::Wait(pending_work_event_.get(), true);
|
||||
if (paused_) {
|
||||
pause_fence_.Signal();
|
||||
@@ -151,6 +326,8 @@ void AudioSystem::WorkerThreadMain() {
|
||||
? earliest_pump_us - kAudioIntervalSlack
|
||||
: 0;
|
||||
if (wake_target_us > now) {
|
||||
watchdog::worker_phase.store(watchdog::WorkerPhase::kPacingSleep,
|
||||
std::memory_order_relaxed);
|
||||
const std::chrono::milliseconds timeout((wake_target_us - now) / 1000);
|
||||
auto result =
|
||||
xe::threading::Wait(pending_work_event_.get(), true, timeout);
|
||||
@@ -172,14 +349,30 @@ void AudioSystem::WorkerThreadMain() {
|
||||
}
|
||||
|
||||
// Submit only if the host has a free output slot;
|
||||
if (client_callback &&
|
||||
const bool have_slot =
|
||||
client_callback &&
|
||||
xe::threading::Wait(client_semaphores_[client_index].get(), false,
|
||||
std::chrono::milliseconds(0)) ==
|
||||
xe::threading::WaitResult::kSuccess) {
|
||||
xe::threading::WaitResult::kSuccess;
|
||||
if (!have_slot) {
|
||||
watchdog::pump_skips.fetch_add(1, std::memory_order_relaxed);
|
||||
}
|
||||
if (have_slot) {
|
||||
SCOPE_profile_cpu_i("apu", "xe::apu::AudioSystem->client_callback");
|
||||
uint64_t args[] = {client_callback_arg};
|
||||
// The guest callback runs in-line on this pump thread: if it blocks, the
|
||||
// pump stops forever and audio never recovers. Bracket it so the
|
||||
// watchdog can see (and name) that case.
|
||||
watchdog::in_guest_callback_since_us.store(WatchdogNowUs(),
|
||||
std::memory_order_relaxed);
|
||||
watchdog::worker_phase.store(watchdog::WorkerPhase::kInGuestCallback,
|
||||
std::memory_order_relaxed);
|
||||
processor_->Execute(worker_thread_->thread_state(), client_callback, args,
|
||||
xe::countof(args));
|
||||
watchdog::worker_phase.store(watchdog::WorkerPhase::kStart,
|
||||
std::memory_order_relaxed);
|
||||
watchdog::in_guest_callback_since_us.store(0, std::memory_order_relaxed);
|
||||
watchdog::guest_pumps.fetch_add(1, std::memory_order_relaxed);
|
||||
}
|
||||
}
|
||||
worker_running_ = false;
|
||||
@@ -201,6 +394,13 @@ int AudioSystem::FindFreeClient() {
|
||||
void AudioSystem::Initialize() {}
|
||||
|
||||
void AudioSystem::Shutdown() {
|
||||
if (watchdog_running_) {
|
||||
watchdog_running_ = false;
|
||||
if (watchdog_thread_.joinable()) {
|
||||
watchdog_thread_.join();
|
||||
}
|
||||
}
|
||||
|
||||
worker_running_ = false;
|
||||
pending_work_event_->Set();
|
||||
if (worker_thread_) {
|
||||
@@ -261,6 +461,12 @@ X_STATUS AudioSystem::RegisterClient(uint32_t callback, uint32_t callback_arg,
|
||||
clients_[index].wrapped_callback_arg = ptr;
|
||||
clients_[index].in_use = true;
|
||||
|
||||
watchdog::register_calls.fetch_add(1, std::memory_order_relaxed);
|
||||
if (cvars::audio_watchdog) {
|
||||
XELOGW("AUDIO-WD RegisterClient(index={}) callback={:08X} -- audio client back",
|
||||
index, callback);
|
||||
}
|
||||
|
||||
// Wake the worker so it re-scans and starts pacing this client immediately.
|
||||
pending_work_event_->Set();
|
||||
|
||||
@@ -277,6 +483,8 @@ X_STATUS AudioSystem::RegisterClient(uint32_t callback, uint32_t callback_arg,
|
||||
void AudioSystem::SubmitFrame(size_t index, float* samples) {
|
||||
SCOPE_profile_cpu_f("apu");
|
||||
|
||||
watchdog::frames_submitted.fetch_add(1, std::memory_order_relaxed);
|
||||
|
||||
auto global_lock = global_critical_region_.Acquire();
|
||||
assert_true(index < kMaximumClientCount);
|
||||
if (index >= kMaximumClientCount || !clients_[index].in_use ||
|
||||
@@ -302,6 +510,12 @@ void AudioSystem::SubmitFrame(size_t index, float* samples) {
|
||||
void AudioSystem::UnregisterClient(size_t index) {
|
||||
SCOPE_profile_cpu_f("apu");
|
||||
|
||||
watchdog::unregister_calls.fetch_add(1, std::memory_order_relaxed);
|
||||
if (cvars::audio_watchdog) {
|
||||
XELOGW("AUDIO-WD UnregisterClient(index={}) -- guest dropped its audio client",
|
||||
index);
|
||||
}
|
||||
|
||||
auto global_lock = global_critical_region_.Acquire();
|
||||
assert_true(index < kMaximumClientCount);
|
||||
DestroyDriver(clients_[index].driver);
|
||||
|
||||
104
src/xenia/apu/audio_watchdog.h
Normal file
104
src/xenia/apu/audio_watchdog.h
Normal file
@@ -0,0 +1,104 @@
|
||||
/**
|
||||
******************************************************************************
|
||||
* Xenia : Xbox 360 Emulator Research Project *
|
||||
******************************************************************************
|
||||
* Copyright 2026 Ben Vanik. All rights reserved. *
|
||||
* Released under the BSD license - see LICENSE in the root for more details. *
|
||||
******************************************************************************
|
||||
*/
|
||||
|
||||
#ifndef XENIA_APU_AUDIO_WATCHDOG_H_
|
||||
#define XENIA_APU_AUDIO_WATCHDOG_H_
|
||||
|
||||
#include <atomic>
|
||||
#include <cstdint>
|
||||
|
||||
// Read-only diagnostics for "audio stops mid-mission and never recovers".
|
||||
//
|
||||
// The audio pipeline has four stages, each of which can die independently:
|
||||
//
|
||||
// guest XAudio callback -> SubmitFrame -> ring buffer -> ALSA write
|
||||
// (guest_pumps) (frames_submitted) (alsa_writes)
|
||||
// XMA decoding feeds the guest (xma_works)
|
||||
//
|
||||
// Each stage bumps a counter here. The watchdog thread in audio_system.cc
|
||||
// samples them once a second and, when audio dies, reports which stage stopped
|
||||
// advancing -- turning "no sound" into a named culprit.
|
||||
//
|
||||
// Note the APU worker runs the guest's audio callback IN-LINE
|
||||
// (AudioSystem::WorkerThreadMain -> processor_->Execute). If that guest call
|
||||
// ever blocks, pumping stops forever and audio can never recover, so we also
|
||||
// track how long we have been inside guest code.
|
||||
//
|
||||
// Everything here is counters only: cvar-gated (--audio_watchdog), no
|
||||
// behaviour change.
|
||||
|
||||
namespace xe {
|
||||
namespace apu {
|
||||
namespace watchdog {
|
||||
|
||||
// Pumps of the guest XAudio callback (AudioSystem worker).
|
||||
inline std::atomic<uint64_t> guest_pumps{0};
|
||||
// steady_clock microseconds at which the worker entered guest code; 0 = not
|
||||
// currently inside the guest callback.
|
||||
inline std::atomic<uint64_t> in_guest_callback_since_us{0};
|
||||
// Frames the guest handed to the driver (AudioSystem::SubmitFrame).
|
||||
inline std::atomic<uint64_t> frames_submitted{0};
|
||||
// XMA decoder Work() calls that actually decoded something.
|
||||
inline std::atomic<uint64_t> xma_works{0};
|
||||
// ALSA: periods of real guest audio written, silence keepalive periods
|
||||
// written, and underruns recovered.
|
||||
inline std::atomic<uint64_t> alsa_writes{0};
|
||||
inline std::atomic<uint64_t> alsa_silence{0};
|
||||
inline std::atomic<uint64_t> alsa_xruns{0};
|
||||
// Last observed snd_pcm_state_t (-1 = unknown / driver not ALSA).
|
||||
inline std::atomic<int> alsa_state{-1};
|
||||
|
||||
// Why is the APU worker not pumping? Three very different causes look the same
|
||||
// from outside the process, so distinguish them here:
|
||||
// worker_loops == 0 && clients_in_use == 0 -> no client (guest unregistered)
|
||||
// worker_loops == 0 && clients_in_use > 0 -> parked despite a client (pacing)
|
||||
// worker_loops > 0 && pump_skips > 0 -> looping, but no free output slot
|
||||
inline std::atomic<uint64_t> worker_loops{0};
|
||||
inline std::atomic<uint64_t> pump_skips{0};
|
||||
inline std::atomic<int> clients_in_use{-1};
|
||||
inline std::atomic<uint64_t> register_calls{0};
|
||||
inline std::atomic<uint64_t> unregister_calls{0};
|
||||
|
||||
// Exactly where the APU worker thread is sitting. A parked worker and a worker
|
||||
// blocked on the kernel global lock are indistinguishable from outside the
|
||||
// process (both are futex waits with zero context switches), so record it.
|
||||
enum class WorkerPhase : int {
|
||||
kStart = 0,
|
||||
kAcquiringGlobalLock, // blocked here => a kernel lock is held elsewhere
|
||||
kParkedNoClient, // blocked here => guest has no audio client
|
||||
kPacingSleep, // normal: waiting for the next 5.33ms deadline
|
||||
kInGuestCallback, // normal: running the game's mixer
|
||||
kSubmitting,
|
||||
};
|
||||
inline std::atomic<WorkerPhase> worker_phase{WorkerPhase::kStart};
|
||||
|
||||
inline const char* WorkerPhaseName(WorkerPhase p) {
|
||||
switch (p) {
|
||||
case WorkerPhase::kStart:
|
||||
return "start";
|
||||
case WorkerPhase::kAcquiringGlobalLock:
|
||||
return "ACQUIRING-GLOBAL-LOCK";
|
||||
case WorkerPhase::kParkedNoClient:
|
||||
return "PARKED-NO-CLIENT";
|
||||
case WorkerPhase::kPacingSleep:
|
||||
return "pacing";
|
||||
case WorkerPhase::kInGuestCallback:
|
||||
return "in-guest-callback";
|
||||
case WorkerPhase::kSubmitting:
|
||||
return "submitting";
|
||||
default:
|
||||
return "?";
|
||||
}
|
||||
}
|
||||
|
||||
} // namespace watchdog
|
||||
} // namespace apu
|
||||
} // namespace xe
|
||||
|
||||
#endif // XENIA_APU_AUDIO_WATCHDOG_H_
|
||||
@@ -9,7 +9,18 @@
|
||||
|
||||
#include "xenia/apu/xma_context_master.h"
|
||||
|
||||
#include <cstdio>
|
||||
#include <cstring>
|
||||
#include <mutex>
|
||||
#include <set>
|
||||
|
||||
#include "xenia/base/cvar.h"
|
||||
|
||||
// [Phase-A / audio RE] Log each XMA stream's true params (channels/sample rate)
|
||||
// + head bytes so raw sound.pak entries can be matched to real decode params.
|
||||
DEFINE_bool(xma_param_probe, false,
|
||||
"Log XMA per-stream params (channels/rate/head bytes) for audio RE.",
|
||||
"APU");
|
||||
|
||||
#include "xenia/apu/xma_decoder.h"
|
||||
#include "xenia/apu/xma_helpers.h"
|
||||
@@ -317,6 +328,39 @@ void XmaContextMaster::Decode(XMA_CONTEXT_DATA* data) {
|
||||
: nullptr;
|
||||
uint8_t* current_input_buffer = data->current_buffer ? in1 : in0;
|
||||
|
||||
// [Phase-A / audio RE] Additive, cvar-gated probe: capture the true XMA
|
||||
// per-stream parameters (channels + sample rate) the game supplies, keyed by
|
||||
// the stream's head bytes so they can be matched back to a sound.pak entry
|
||||
// offline. One line per unique stream (deduped on the first 8 bytes). No
|
||||
// behaviour change — read-only, default-off.
|
||||
if (cvars::xma_param_probe && in0 && data->input_buffer_0_valid &&
|
||||
data->input_buffer_0_packet_count) {
|
||||
static std::mutex xma_probe_mu;
|
||||
static std::set<uint64_t> xma_probe_seen;
|
||||
uint64_t key;
|
||||
std::memcpy(&key, in0, sizeof(key));
|
||||
bool fresh;
|
||||
{
|
||||
std::lock_guard<std::mutex> lock(xma_probe_mu);
|
||||
fresh = xma_probe_seen.insert(key).second;
|
||||
}
|
||||
if (fresh) {
|
||||
char head[65];
|
||||
for (int i = 0; i < 32; ++i) {
|
||||
std::snprintf(head + i * 2, 3, "%02x", in0[i]);
|
||||
}
|
||||
// Warning level so it surfaces even at the audio-safe --log_level=1 the
|
||||
// interactive runner uses (Info/Debug would starve the audio thread).
|
||||
XELOGW(
|
||||
"XMA-PARAM stereo={} channels={} rate_id={} rate={} packets={} "
|
||||
"head={}",
|
||||
static_cast<uint32_t>(data->is_stereo),
|
||||
data->is_stereo ? 2 : 1, static_cast<uint32_t>(data->sample_rate),
|
||||
GetSampleRate(data->sample_rate),
|
||||
static_cast<uint32_t>(data->input_buffer_0_packet_count), head);
|
||||
}
|
||||
}
|
||||
|
||||
// XELOGAPU("Processing context {} (offset {}, buffer {}, ptr {:p})", id(),
|
||||
// data->input_buffer_read_offset, data->current_buffer,
|
||||
// current_input_buffer);
|
||||
|
||||
@@ -10,10 +10,19 @@
|
||||
#include "xenia/apu/xma_context_new.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/platform.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" {
|
||||
#if XE_COMPILER_MSVC
|
||||
#pragma warning(push)
|
||||
@@ -392,6 +401,66 @@ void XmaContextNew::Decode(XMA_CONTEXT_DATA* 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);
|
||||
|
||||
// Detect if we're about to decode the loop end frame (before
|
||||
|
||||
@@ -9,6 +9,7 @@
|
||||
|
||||
#include "xenia/apu/xma_decoder.h"
|
||||
|
||||
#include "xenia/apu/audio_watchdog.h"
|
||||
#include "xenia/apu/xma_context.h"
|
||||
#include "xenia/apu/xma_context_fake.h"
|
||||
#include "xenia/apu/xma_context_master.h"
|
||||
@@ -199,6 +200,7 @@ void XmaDecoder::WorkerThreadMain() {
|
||||
for (uint32_t n = 0; n < kContextCount; n++) {
|
||||
bool worked = contexts_[n]->Work();
|
||||
if (worked) {
|
||||
watchdog::xma_works.fetch_add(1, std::memory_order_relaxed);
|
||||
contexts_[n]->SignalWorkDone();
|
||||
}
|
||||
did_work = did_work || worked;
|
||||
@@ -409,6 +411,13 @@ void XmaDecoder::Pause() {
|
||||
}
|
||||
paused_ = true;
|
||||
|
||||
// Wake the worker so it actually observes paused_. When no context is
|
||||
// decoding, the worker sleeps in an infinite Wait(work_event_) and would
|
||||
// never re-check the flag, never signal pause_fence_, and this would block
|
||||
// forever -- deadlocking whoever paused us (e.g. the crash handler), which
|
||||
// left audio permanently dead while the game kept running.
|
||||
work_event_->Set();
|
||||
|
||||
pause_fence_.Wait();
|
||||
}
|
||||
|
||||
|
||||
35
src/xenia/base/guest_liveness.h
Normal file
35
src/xenia/base/guest_liveness.h
Normal file
@@ -0,0 +1,35 @@
|
||||
/**
|
||||
******************************************************************************
|
||||
* Xenia : Xbox 360 Emulator Research Project *
|
||||
******************************************************************************
|
||||
* Copyright 2026 Ben Vanik. All rights reserved. *
|
||||
* Released under the BSD license - see LICENSE in the root for more details. *
|
||||
******************************************************************************
|
||||
*/
|
||||
|
||||
#ifndef XENIA_BASE_GUEST_LIVENESS_H_
|
||||
#define XENIA_BASE_GUEST_LIVENESS_H_
|
||||
|
||||
#include <atomic>
|
||||
#include <cstdint>
|
||||
|
||||
// Guest-progress signal for the hang watchdog (--hang_watchdog_secs).
|
||||
//
|
||||
// A frozen guest is not the same as a frozen host: in the Project Sylpheed
|
||||
// tutorial->menu freeze the host is fine (threads scheduled, GPU idle) while
|
||||
// the guest main thread spins at 100% CPU on a memory flag that never changes.
|
||||
// The cheapest honest "the game is still alive" signal is the guest presenting
|
||||
// frames, i.e. calling VdSwap. If that stops, the game has stopped rendering.
|
||||
//
|
||||
// Counter only; no behaviour change.
|
||||
|
||||
namespace xe {
|
||||
namespace liveness {
|
||||
|
||||
// Bumped by VdSwap (xboxkrnl_video.cc) -- the guest asking to present a frame.
|
||||
inline std::atomic<uint64_t> guest_swaps{0};
|
||||
|
||||
} // namespace liveness
|
||||
} // namespace xe
|
||||
|
||||
#endif // XENIA_BASE_GUEST_LIVENESS_H_
|
||||
@@ -14,6 +14,7 @@
|
||||
#include "xenia/base/platform.h"
|
||||
#include "xenia/base/threading_timer_queue.h"
|
||||
|
||||
#include <atomic>
|
||||
#include <pthread.h>
|
||||
#include <sched.h>
|
||||
#include <semaphore.h>
|
||||
@@ -981,11 +982,22 @@ class PosixCondition<Thread> final : public PosixConditionBase {
|
||||
static void* ThreadStartRoutine(void* parameter);
|
||||
bool signaled() const override { return signaled_; }
|
||||
void post_execution() override {
|
||||
// Reap exactly once. post_execution() runs on EVERY successful Wait(), and
|
||||
// a thread object stays signaled forever once it has exited -- so every
|
||||
// later wait on the same handle would pthread_join() a pthread_t that the
|
||||
// first join already reaped and freed, faulting inside pthread_join. The
|
||||
// guest does exactly this at mission teardown (several waiters on one
|
||||
// thread handle), which crashed the waiting guest thread in a permanent
|
||||
// fault loop: audio died and the game froze.
|
||||
if (reaped_.exchange(true)) {
|
||||
return;
|
||||
}
|
||||
if (thread_) {
|
||||
pthread_join(thread_, nullptr);
|
||||
}
|
||||
sem_destroy(&suspend_sem_);
|
||||
}
|
||||
std::atomic<bool> reaped_{false};
|
||||
pthread_t thread_;
|
||||
pid_t tid_ = 0; // Kernel TID for setpriority() fallback
|
||||
mutable bool fifo_failed_ = false; // True after SCHED_FIFO was rejected
|
||||
|
||||
@@ -57,3 +57,34 @@ DEFINE_bool(break_condition_truncate, true, "truncate value to 32-bits", "CPU");
|
||||
|
||||
DEFINE_bool(break_on_debugbreak, true, "int3 on JITed __debugbreak requests.",
|
||||
"CPU");
|
||||
|
||||
// Phase A — expansive extraction tracing (game-data RE); see kernel/event_log.h.
|
||||
// All default-off so instrument-current behaviour is unchanged when unused.
|
||||
DEFINE_string(phase_a_event_log_path, "",
|
||||
"Phase A: write schema-v1 JSONL event log to this path. "
|
||||
"Empty (default) = disabled.",
|
||||
"Audit");
|
||||
DEFINE_bool(phase_a_event_log_mem_writes, false,
|
||||
"Phase A: include mem.write events in the JSONL log. RESERVED — "
|
||||
"not wired in this phase. Default false.",
|
||||
"Audit");
|
||||
DEFINE_bool(phase_a_trace_args, false,
|
||||
"Phase A extraction: populate the kernel.call args (raw r3..r10) and "
|
||||
"args_resolved (file I/O path/offset/length/buffer, alloc size, "
|
||||
"handle names) fields, and emit file.read events. Default false.",
|
||||
"Audit");
|
||||
DEFINE_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");
|
||||
|
||||
@@ -35,4 +35,11 @@ DECLARE_bool(break_condition_truncate);
|
||||
|
||||
DECLARE_bool(break_on_debugbreak);
|
||||
|
||||
// Phase A — expansive extraction tracing; see kernel/event_log.h.
|
||||
DECLARE_string(phase_a_event_log_path);
|
||||
DECLARE_bool(phase_a_event_log_mem_writes);
|
||||
DECLARE_bool(phase_a_trace_args);
|
||||
DECLARE_string(phase_a_hash_probe);
|
||||
DECLARE_bool(kernel_emit_contention);
|
||||
|
||||
#endif // XENIA_CPU_CPU_FLAGS_H_
|
||||
|
||||
@@ -1568,18 +1568,101 @@ std::vector<uint32_t> XexModule::PreanalyzeCode() {
|
||||
}
|
||||
}
|
||||
|
||||
for (auto&& sec : pe_sections_) {
|
||||
XELOGE("PESEC name={} addr={:08X} size={}", sec.name, sec.address,
|
||||
sec.size);
|
||||
}
|
||||
// EH-CONFIRM: scan .rdata for MSVC C++ FuncInfo (magic 0x19930520) and, for
|
||||
// any whose IP2State map points into the cache-flush chain, dump its catch
|
||||
// TypeDescriptor names -- this tells us if the flush's out_of_range is
|
||||
// CAUGHT (vs only cleaned up). Layout (Xenon, 32-bit full VAs, big-endian):
|
||||
// FuncInfo: +0 magic, +4 maxState, +8 pUnwindMap, +12 nTryBlocks,
|
||||
// +16 pTryBlockMap, +20 nIPMap, +24 pIP2StateMap
|
||||
// TryBlockMapEntry(20B): +0 tryLow,+4 tryHigh,+8 catchHigh,+12 nCatches,
|
||||
// +16 pHandlerArray
|
||||
// HandlerType(16B): +0 adjectives,+4 pType(TypeDescriptor),+8 dispCatch,
|
||||
// +12 addressOfHandler
|
||||
// TypeDescriptor: +0 vfptr,+4 spare,+8 name(mangled, e.g. ".?AV...@")
|
||||
// IP2StateMapEntry(8B): +0 Ip(VA), +4 State
|
||||
{
|
||||
auto rd = [&](uint32_t va) -> uint32_t {
|
||||
auto p = memory()->TranslateVirtual<xe::be<uint32_t>*>(va);
|
||||
return p ? (uint32_t)*p : 0;
|
||||
};
|
||||
auto valid = [](uint32_t va) { return va >= 0x82000000 && va < 0x82920000; };
|
||||
auto rdata = GetPESection(".rdata");
|
||||
if (rdata) {
|
||||
uint32_t magic_hits = 0, raw_logged = 0;
|
||||
for (uint32_t a = rdata->address; a < rdata->address + rdata->size;
|
||||
a += 4) {
|
||||
if (rd(a) != 0x19930522u) continue; // FuncInfo magic (newer MSVC)
|
||||
uint32_t nTry = rd(a + 12), pTry = rd(a + 16);
|
||||
uint32_t nIP = rd(a + 20), pIP = rd(a + 24);
|
||||
++magic_hits;
|
||||
if (!valid(pIP) || nIP > 4096 || !nIP) continue;
|
||||
// which function? use first + last IP in the IP2State map.
|
||||
uint32_t firstIp = rd(pIP), lastIp = rd(pIP + (nIP - 1) * 8);
|
||||
if (raw_logged < 6) {
|
||||
XELOGE("EH-RAW FuncInfo@{:08X} nTry={} ip[{:08X}..{:08X}]", a, nTry,
|
||||
firstIp, lastIp);
|
||||
++raw_logged;
|
||||
}
|
||||
// Log EVERY function that has a CATCH (nTry>=1) across the whole
|
||||
// binary, so any stack frame can be mapped to a catch. (cleanup-only
|
||||
// nTry=0 frames just re-propagate -- skip them to cut noise.)
|
||||
if (!nTry || !valid(pTry) || nTry > 64) continue;
|
||||
std::string cat;
|
||||
for (uint32_t t = 0; t < nTry; ++t) {
|
||||
uint32_t te = pTry + t * 20;
|
||||
uint32_t nCatch = rd(te + 12), pH = rd(te + 16);
|
||||
for (uint32_t c = 0; c < nCatch && c < 32 && valid(pH); ++c) {
|
||||
uint32_t pType = rd(pH + c * 16 + 4);
|
||||
uint32_t dispCatchObj = rd(pH + c * 16 + 8);
|
||||
uint32_t funclet = rd(pH + c * 16 + 12);
|
||||
std::string nm;
|
||||
if (!pType) {
|
||||
nm = "...";
|
||||
} else {
|
||||
auto s = memory()->TranslateVirtual<const char*>(pType + 8);
|
||||
for (int i = 0; s && i < 96 && s[i]; ++i) nm.push_back(s[i]);
|
||||
}
|
||||
cat += fmt::format(" catch({} obj@fp+{:X} funclet={:08X})", nm,
|
||||
dispCatchObj, funclet);
|
||||
}
|
||||
}
|
||||
XELOGE("EH-CONFIRM FuncInfo@{:08X} ip[{:08X}..{:08X}] nTry={}{}", a,
|
||||
firstIp, lastIp, nTry, cat);
|
||||
}
|
||||
XELOGE("EH-CONFIRM scan done; magic_hits={}", magic_hits);
|
||||
}
|
||||
}
|
||||
auto pdata = this->GetPESection(".pdata");
|
||||
XELOGE("PDATA-SCAN reached; pdata_section={}",
|
||||
pdata ? "FOUND" : "NULL");
|
||||
|
||||
if (pdata) {
|
||||
uint32_t* pdata_base =
|
||||
(uint32_t*)this->memory()->TranslateVirtual(pdata->address);
|
||||
|
||||
uint32_t n_pdata_entries = pdata->raw_size / 8;
|
||||
XELOGE("PDATA-SCAN addr={:08X} raw_size={} entries={}", pdata->address,
|
||||
pdata->raw_size, n_pdata_entries);
|
||||
|
||||
for (uint32_t i = 0; i < n_pdata_entries; ++i) {
|
||||
uint32_t funcaddr = xe::load_and_swap<uint32_t>(&pdata_base[i * 2]);
|
||||
if (funcaddr >= low_address_ && funcaddr <= highest_exec_addr) {
|
||||
add_new_func(funcaddr);
|
||||
// DIAGNOSTIC: dump the unwind Flags word for the cache-flush region
|
||||
// (Xbox360 PPC RUNTIME_FUNCTION: BeginAddress, then Flags with
|
||||
// PrologLen:8, FuncLen:22, 32bit:1, ExceptionFlag:1[bit31]). The
|
||||
// ExceptionFlag tells us whether a function has a language handler
|
||||
// (C++ catch/cleanup) -- i.e. whether the game can CATCH the flush's
|
||||
// out_of_range throw. Remove once the A-vs-B fix decision is settled.
|
||||
if (funcaddr >= 0x82459000u && funcaddr <= 0x8245B200u) {
|
||||
uint32_t flags = xe::load_and_swap<uint32_t>(&pdata_base[i * 2 + 1]);
|
||||
XELOGE("PDATA fn={:08X} flags={:08X} funclen={} excflag={}",
|
||||
funcaddr, flags, (flags >> 2) & 0x3FFFFF, (flags & 1));
|
||||
}
|
||||
} else {
|
||||
// we hit 0 for func addr, that means we're done
|
||||
break;
|
||||
|
||||
@@ -30,10 +30,13 @@
|
||||
#include "xenia/base/platform.h"
|
||||
#include "xenia/base/string.h"
|
||||
#include "xenia/base/system.h"
|
||||
#include "xenia/base/guest_liveness.h"
|
||||
#include "xenia/cpu/backend/code_cache.h"
|
||||
#include "xenia/cpu/backend/null_backend.h"
|
||||
#include "xenia/cpu/cpu_flags.h"
|
||||
#include "xenia/cpu/ppc/ppc_context.h"
|
||||
#include "xenia/cpu/thread_state.h"
|
||||
#include "xenia/kernel/xthread.h"
|
||||
#include "xenia/gpu/command_processor.h"
|
||||
#include "xenia/gpu/graphics_system.h"
|
||||
#include "xenia/hid/input_driver.h"
|
||||
@@ -92,6 +95,12 @@ DEFINE_int32(priority_class, 0,
|
||||
"values: 0 - Normal, 1 - Above normal, 2 - High",
|
||||
"General");
|
||||
|
||||
DEFINE_int32(hang_watchdog_secs, 0,
|
||||
"If the guest stops presenting frames for this many seconds, dump "
|
||||
"every guest thread's registers and guest call stack to the log "
|
||||
"(0 = off). Diagnostics only; requires no debugger.",
|
||||
"General");
|
||||
|
||||
namespace xe {
|
||||
using namespace xe::literals;
|
||||
|
||||
@@ -166,6 +175,13 @@ Emulator::Emulator(const std::filesystem::path& command_line,
|
||||
Emulator::~Emulator() {
|
||||
// Note that we delete things in the reverse order they were initialized.
|
||||
|
||||
if (hang_watchdog_running_) {
|
||||
hang_watchdog_running_ = false;
|
||||
if (hang_watchdog_thread_.joinable()) {
|
||||
hang_watchdog_thread_.join();
|
||||
}
|
||||
}
|
||||
|
||||
// Give the systems time to shutdown before we delete them.
|
||||
if (graphics_system_) {
|
||||
graphics_system_->Shutdown();
|
||||
@@ -308,6 +324,53 @@ X_STATUS Emulator::Setup(
|
||||
XELOGI("{}: Initializing Kernel...", __func__);
|
||||
// Shared kernel state.
|
||||
kernel_state_ = std::make_unique<xe::kernel::KernelState>(this);
|
||||
|
||||
// Hang watchdog (--hang_watchdog_secs, diagnostics, default off).
|
||||
//
|
||||
// The tutorial->menu freeze is a GUEST hang, not a host deadlock: the host
|
||||
// keeps running while a guest thread spins on a memory flag nobody sets. A
|
||||
// host debugger is awkward to attach to that (ptrace is locked down, and the
|
||||
// window may die before we get to it), but the emulator can simply read its
|
||||
// own guest state. When the guest stops presenting frames, dump every guest
|
||||
// thread's registers plus a walk of its guest stack -- enough to name the
|
||||
// spinning function and the address it is polling.
|
||||
if (cvars::hang_watchdog_secs > 0) {
|
||||
hang_watchdog_running_ = true;
|
||||
hang_watchdog_thread_ = std::thread([this]() {
|
||||
xe::threading::set_name("Hang Watchdog");
|
||||
const uint64_t limit =
|
||||
static_cast<uint64_t>(cvars::hang_watchdog_secs);
|
||||
uint64_t last_swaps = 0;
|
||||
uint64_t stalled_s = 0;
|
||||
bool dumped = false;
|
||||
while (hang_watchdog_running_) {
|
||||
std::this_thread::sleep_for(std::chrono::seconds(1));
|
||||
if (!hang_watchdog_running_) {
|
||||
break;
|
||||
}
|
||||
const uint64_t swaps =
|
||||
xe::liveness::guest_swaps.load(std::memory_order_relaxed);
|
||||
if (swaps != last_swaps) {
|
||||
last_swaps = swaps;
|
||||
if (stalled_s >= limit) {
|
||||
XELOGE("HANG-WD guest recovered after {}s (swaps resumed)",
|
||||
stalled_s);
|
||||
}
|
||||
stalled_s = 0;
|
||||
dumped = false;
|
||||
continue;
|
||||
}
|
||||
// Nothing presented for another second.
|
||||
if (++stalled_s < limit || dumped) {
|
||||
continue;
|
||||
}
|
||||
dumped = true; // one dump per hang, not one per second
|
||||
DumpGuestHang(stalled_s);
|
||||
}
|
||||
});
|
||||
XELOGI("HANG-WD armed: dump guest state after {}s without a frame",
|
||||
cvars::hang_watchdog_secs);
|
||||
}
|
||||
#define LOAD_KERNEL_MODULE(t) \
|
||||
static_cast<void>(kernel_state_->LoadKernelModule<kernel::t>())
|
||||
// HLE kernel modules.
|
||||
@@ -532,6 +595,72 @@ Emulator::FileSignatureType Emulator::GetFileSignature(
|
||||
return FileSignatureType::Unknown;
|
||||
}
|
||||
|
||||
void Emulator::DumpGuestHang(uint64_t stalled_s) {
|
||||
// Read-only autopsy of a hung guest. Racy by nature (the threads keep
|
||||
// running); that is fine -- a spinning thread's stack pointer and link
|
||||
// register are stable, which is exactly what we need.
|
||||
constexpr uint32_t kCodeLo = 0x82000000u;
|
||||
constexpr uint32_t kCodeHi = 0x84000000u;
|
||||
|
||||
XELOGE("=========================== HANG-WD ===========================");
|
||||
XELOGE("HANG-WD no frame presented for {}s -- dumping guest threads.",
|
||||
stalled_s);
|
||||
|
||||
auto threads =
|
||||
kernel_state()->object_table()->GetObjectsByType<kernel::XThread>();
|
||||
for (const auto& thread : threads) {
|
||||
if (!thread || !thread->is_guest_thread()) {
|
||||
continue;
|
||||
}
|
||||
auto thread_state = thread->thread_state();
|
||||
if (!thread_state) {
|
||||
continue;
|
||||
}
|
||||
auto ctx = thread_state->context();
|
||||
if (!ctx) {
|
||||
continue;
|
||||
}
|
||||
|
||||
XELOGE(
|
||||
"HANG-WD tid={:04X} '{}' running={} lr={:08X} ctr={:08X} r1={:08X}",
|
||||
thread->thread_id(), thread->name(), thread->is_running(),
|
||||
static_cast<uint32_t>(ctx->lr), static_cast<uint32_t>(ctx->ctr),
|
||||
static_cast<uint32_t>(ctx->r[1]));
|
||||
XELOGE(
|
||||
"HANG-WD r3={:08X} r4={:08X} r5={:08X} r6={:08X} r7={:08X} "
|
||||
"r8={:08X} r9={:08X} r10={:08X} r11={:08X} r12={:08X}",
|
||||
static_cast<uint32_t>(ctx->r[3]), static_cast<uint32_t>(ctx->r[4]),
|
||||
static_cast<uint32_t>(ctx->r[5]), static_cast<uint32_t>(ctx->r[6]),
|
||||
static_cast<uint32_t>(ctx->r[7]), static_cast<uint32_t>(ctx->r[8]),
|
||||
static_cast<uint32_t>(ctx->r[9]), static_cast<uint32_t>(ctx->r[10]),
|
||||
static_cast<uint32_t>(ctx->r[11]), static_cast<uint32_t>(ctx->r[12]));
|
||||
|
||||
// Walk the guest stack: PowerPC back chain -- [sp] = caller sp,
|
||||
// [sp+4] = saved LR. Stop on anything that stops looking like a frame.
|
||||
std::string frames;
|
||||
uint32_t sp = static_cast<uint32_t>(ctx->r[1]);
|
||||
for (int depth = 0; depth < 16; ++depth) {
|
||||
if (sp < 0x1000 || !memory()->TranslateVirtual(sp)) {
|
||||
break;
|
||||
}
|
||||
auto frame = memory()->TranslateVirtual(sp);
|
||||
const uint32_t next_sp = xe::load_and_swap<uint32_t>(frame);
|
||||
const uint32_t saved_lr = xe::load_and_swap<uint32_t>(frame + 4);
|
||||
if (saved_lr >= kCodeLo && saved_lr < kCodeHi) {
|
||||
frames += fmt::format(" {:08X}", saved_lr);
|
||||
}
|
||||
if (next_sp <= sp || next_sp - sp > 0x10000) {
|
||||
break; // not a plausible back chain anymore
|
||||
}
|
||||
sp = next_sp;
|
||||
}
|
||||
if (!frames.empty()) {
|
||||
XELOGE("HANG-WD guest stack:{}", frames);
|
||||
}
|
||||
}
|
||||
XELOGE("HANG-WD ==== resolve these PCs with: zq.py fn <pc> ====");
|
||||
}
|
||||
|
||||
X_STATUS Emulator::LaunchPath(const std::filesystem::path& path) {
|
||||
X_STATUS mount_result = X_STATUS_SUCCESS;
|
||||
|
||||
|
||||
@@ -10,11 +10,13 @@
|
||||
#ifndef XENIA_EMULATOR_H_
|
||||
#define XENIA_EMULATOR_H_
|
||||
|
||||
#include <atomic>
|
||||
#include <cstddef>
|
||||
#include <cstdint>
|
||||
#include <functional>
|
||||
#include <optional>
|
||||
#include <string>
|
||||
#include <thread>
|
||||
#include <vector>
|
||||
|
||||
#include "xenia/apu/audio_media_player.h"
|
||||
@@ -309,6 +311,12 @@ class Emulator {
|
||||
xe::Delegate<> on_exit;
|
||||
|
||||
private:
|
||||
// Hang watchdog (--hang_watchdog_secs): when the guest stops presenting
|
||||
// frames, dump every guest thread's registers + guest stack. Diagnostics.
|
||||
void DumpGuestHang(uint64_t stalled_s);
|
||||
std::atomic<bool> hang_watchdog_running_{false};
|
||||
std::thread hang_watchdog_thread_;
|
||||
|
||||
enum : uint64_t { EmulatorFlagDisclaimerAcknowledged = 1ULL << 0 };
|
||||
static uint64_t GetPersistentEmulatorFlags();
|
||||
static void SetPersistentEmulatorFlags(uint64_t new_flags);
|
||||
|
||||
@@ -125,8 +125,138 @@ const char* ReVertexFormatName(xenos::VertexFormat f) {
|
||||
}
|
||||
} // namespace
|
||||
|
||||
// ── Ship-placement capture (RE) ─────────────────────────────────────────────
|
||||
// A hotkey (F10 in the emulator window) requests a one-shot snapshot: 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, so these positions are ground truth for the assembled placement — a
|
||||
// tool correlates each draw to a decoded .xpr part (vertex count → affine fit).
|
||||
// De-duped by buffer address, so a static ship's parts collapse to one record
|
||||
// each even across the few frames the budget spans.
|
||||
namespace {
|
||||
constexpr int kShipCaptureBudget = 8000; // draws to scan per request
|
||||
std::atomic<uint32_t> g_ship_capture_gen{0};
|
||||
std::atomic<int> g_ship_capture_remaining{0};
|
||||
} // namespace
|
||||
|
||||
void RequestShipCaptureFrame() {
|
||||
g_ship_capture_gen.fetch_add(1, std::memory_order_relaxed);
|
||||
g_ship_capture_remaining.store(kShipCaptureBudget, std::memory_order_relaxed);
|
||||
XELOGI("[SHIP-CAP] capture armed → xenia_ship_capture.log");
|
||||
}
|
||||
|
||||
void CommandProcessor::CaptureShipDrawForRE(
|
||||
uint32_t vgt_draw_initiator_value,
|
||||
const IndexBufferInfo* index_buffer_info) {
|
||||
if (g_ship_capture_remaining.load(std::memory_order_relaxed) <= 0) {
|
||||
return;
|
||||
}
|
||||
static std::mutex cap_mutex;
|
||||
static std::ofstream cap_out;
|
||||
static std::unordered_set<uint32_t> cap_seen; // by vertex-buffer address
|
||||
static uint32_t cap_gen = 0;
|
||||
std::lock_guard<std::mutex> lock(cap_mutex);
|
||||
if (g_ship_capture_remaining.load(std::memory_order_relaxed) <= 0) {
|
||||
return;
|
||||
}
|
||||
// A new request (fresh generation) reopens the file and clears the de-dup set.
|
||||
uint32_t gen = g_ship_capture_gen.load(std::memory_order_relaxed);
|
||||
if (gen != cap_gen || !cap_out.is_open()) {
|
||||
cap_out.open("xenia_ship_capture.log", std::ios::out | std::ios::trunc);
|
||||
cap_seen.clear();
|
||||
cap_gen = gen;
|
||||
XELOGI("[SHIP-CAP] writing xenia_ship_capture.log");
|
||||
}
|
||||
g_ship_capture_remaining.fetch_sub(1, std::memory_order_relaxed);
|
||||
if (!cap_out.is_open()) {
|
||||
return;
|
||||
}
|
||||
|
||||
reg::VGT_DRAW_INITIATOR init;
|
||||
init.value = vgt_draw_initiator_value;
|
||||
Shader* vs = active_vertex_shader_;
|
||||
if (!vs || !vs->is_ucode_analyzed() || vs->vertex_bindings().empty()) {
|
||||
return;
|
||||
}
|
||||
const auto& binding = vs->vertex_bindings()[0];
|
||||
xenos::xe_gpu_vertex_fetch_t fetch =
|
||||
register_file_->GetVertexFetch(binding.fetch_constant);
|
||||
int32_t pos_off_bytes = -1;
|
||||
for (const auto& attr : binding.attributes) {
|
||||
if (attr.fetch_instr.attributes.data_format ==
|
||||
xenos::VertexFormat::k_32_32_32_FLOAT) {
|
||||
pos_off_bytes = attr.fetch_instr.attributes.offset * 4;
|
||||
break;
|
||||
}
|
||||
}
|
||||
uint32_t stride = binding.stride_words * 4;
|
||||
uint32_t vbase = uint32_t(fetch.address) << 2;
|
||||
uint32_t buf_bytes = uint32_t(fetch.size) * 4;
|
||||
if (pos_off_bytes < 0 || stride == 0 || vbase == 0) {
|
||||
return; // no float-position stream (UI/effects) — skip
|
||||
}
|
||||
// One record per distinct vertex buffer.
|
||||
if (!cap_seen.insert(vbase).second) {
|
||||
return;
|
||||
}
|
||||
if (cap_seen.size() > 4096) {
|
||||
return;
|
||||
}
|
||||
uint32_t vcount = buf_bytes / stride;
|
||||
cap_out << fmt::format(
|
||||
"DRAW vbase=0x{:08X} stride={} vcount={} indices={} prim={} vs=0x{:016X}\n",
|
||||
vbase, stride, vcount, uint32_t(init.num_indices),
|
||||
uint32_t(init.prim_type), vs->ucode_data_hash());
|
||||
uint32_t n = vcount < 64 ? vcount : 64;
|
||||
cap_out << " pos:";
|
||||
auto be_f32 = [](const uint8_t* q) {
|
||||
uint32_t w = (uint32_t(q[0]) << 24) | (uint32_t(q[1]) << 16) |
|
||||
(uint32_t(q[2]) << 8) | uint32_t(q[3]);
|
||||
float f;
|
||||
std::memcpy(&f, &w, 4);
|
||||
return f;
|
||||
};
|
||||
for (uint32_t v = 0; v < n; ++v) {
|
||||
uint32_t a = vbase + v * stride + uint32_t(pos_off_bytes);
|
||||
const uint8_t* p = memory_->TranslatePhysical<const uint8_t*>(a);
|
||||
if (!p) {
|
||||
break;
|
||||
}
|
||||
cap_out << fmt::format(" ({:.4f},{:.4f},{:.4f})", be_f32(p), be_f32(p + 4),
|
||||
be_f32(p + 8));
|
||||
}
|
||||
cap_out << "\n";
|
||||
|
||||
// Vertex-shader float constants: the buffer holds LOCAL positions, so the
|
||||
// per-part world (or world-view-projection) matrix that places the part lives
|
||||
// here as a run of float4 constants. Diffing two parts' constants isolates the
|
||||
// matrix (the camera VP block is shared). Dump the first 48 vec4 from the VS
|
||||
// constant base as host-float (the register file stores them host-endian).
|
||||
auto vsc = register_file_->Get<reg::SQ_VS_CONST>();
|
||||
uint32_t cbase = vsc.base; // starting float4 index
|
||||
cap_out << fmt::format(" vsconst base={}:", cbase);
|
||||
for (uint32_t i = 0; i < 48; ++i) {
|
||||
uint32_t idx = cbase + i;
|
||||
if (idx >= 256) {
|
||||
break;
|
||||
}
|
||||
uint32_t r = XE_GPU_REG_SHADER_CONSTANT_000_X + 4 * idx;
|
||||
float cx = register_file_->Get<float>(r);
|
||||
float cy = register_file_->Get<float>(r + 1);
|
||||
float cz = register_file_->Get<float>(r + 2);
|
||||
float cw = register_file_->Get<float>(r + 3);
|
||||
cap_out << fmt::format(" c{}=({:.4f},{:.4f},{:.4f},{:.4f})", i, cx, cy, cz,
|
||||
cw);
|
||||
}
|
||||
cap_out << "\n";
|
||||
cap_out.flush();
|
||||
}
|
||||
|
||||
void CommandProcessor::LogDrawForRE(uint32_t vgt_draw_initiator_value,
|
||||
const IndexBufferInfo* index_buffer_info) {
|
||||
// One-shot ship-placement capture runs independently of the log_draws cvar.
|
||||
CaptureShipDrawForRE(vgt_draw_initiator_value, index_buffer_info);
|
||||
if (!cvars::log_draws) {
|
||||
return;
|
||||
}
|
||||
|
||||
@@ -35,6 +35,10 @@ class ByteStream;
|
||||
|
||||
namespace gpu {
|
||||
|
||||
// Arm a one-shot ship-placement capture (see CommandProcessor::CaptureShipDrawForRE).
|
||||
// Called from the UI thread (F10 hotkey); thread-safe. Defined in command_processor.cc.
|
||||
void RequestShipCaptureFrame();
|
||||
|
||||
enum class GPUSetting { ClearMemoryPageState, ReadbackMemexport };
|
||||
|
||||
enum class ReadbackResolveMode {
|
||||
@@ -453,6 +457,14 @@ class CommandProcessor {
|
||||
void LogDrawForRE(uint32_t vgt_draw_initiator_value,
|
||||
const IndexBufferInfo* index_buffer_info);
|
||||
|
||||
// Ship-placement capture (RE): a one-shot snapshot armed by RequestShipCaptureFrame()
|
||||
// (F10 hotkey). Dumps each draw's guest vertex-buffer address, vertex/index
|
||||
// counts, and up to 64 WORLD-space positions to xenia_ship_capture.log, so a
|
||||
// correlator can recover each capital-ship part's exact placement. Defined in
|
||||
// command_processor.cc.
|
||||
void CaptureShipDrawForRE(uint32_t vgt_draw_initiator_value,
|
||||
const IndexBufferInfo* index_buffer_info);
|
||||
|
||||
// "Actual" is for the command processor thread, to be read by the
|
||||
// implementations.
|
||||
SwapPostEffect GetActualSwapPostEffect() const {
|
||||
|
||||
726
src/xenia/kernel/event_log.cc
Normal file
726
src/xenia/kernel/event_log.cc
Normal file
@@ -0,0 +1,726 @@
|
||||
/**
|
||||
******************************************************************************
|
||||
* 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
|
||||
191
src/xenia/kernel/event_log.h
Normal file
191
src/xenia/kernel/event_log.h
Normal file
@@ -0,0 +1,191 @@
|
||||
/**
|
||||
******************************************************************************
|
||||
* Xenia : Xbox 360 Emulator Research Project *
|
||||
******************************************************************************
|
||||
* Phase A event-log emitter. Cvar-gated (default off). Schema v1.
|
||||
* Companion: xenia-rs/audit-runs/phase-a-diff-harness/schema-v1.md
|
||||
******************************************************************************
|
||||
*/
|
||||
|
||||
#ifndef XENIA_KERNEL_EVENT_LOG_H_
|
||||
#define XENIA_KERNEL_EVENT_LOG_H_
|
||||
|
||||
#include <cstdint>
|
||||
|
||||
namespace xe {
|
||||
namespace kernel {
|
||||
namespace phase_a {
|
||||
|
||||
// Object-type codes (must match ours's enum exactly — see schema-v1.md).
|
||||
enum ObjectType : uint32_t {
|
||||
kObjUnknown = 0x00,
|
||||
kObjEvent = 0x01,
|
||||
kObjMutant = 0x02,
|
||||
kObjSemaphore = 0x03,
|
||||
kObjTimer = 0x04,
|
||||
kObjThread = 0x05,
|
||||
kObjFile = 0x06,
|
||||
kObjIoCompletion = 0x07,
|
||||
kObjModule = 0x08,
|
||||
kObjEnumState = 0x09,
|
||||
kObjSection = 0x0A,
|
||||
kObjNotification = 0x0B,
|
||||
// Phase D Stage 1: pseudo-type used as the `object_type` input to
|
||||
// `ComputeSharedGlobalSemanticId` for RTL_CRITICAL_SECTION pointers. CS
|
||||
// is not a regular `XObject` (it lives as a guest-memory struct, not a
|
||||
// handle-tabled kernel object), but the `site_sid` field of
|
||||
// `contention.observed` reuses the shared-global SID recipe so the
|
||||
// Stage-3 manifest loader can compute the same SID in both engines.
|
||||
kObjCriticalSection = 0x0C,
|
||||
};
|
||||
|
||||
// Fast bool check (default off). Inlinable so we can guard hot paths cheaply.
|
||||
bool IsEnabled();
|
||||
|
||||
// Emitted once at startup if enabled (first line of the JSONL).
|
||||
void EmitSchemaHeader();
|
||||
|
||||
// FNV-1a 64-bit identity (see schema-v1.md). Both engines compute identically.
|
||||
uint64_t ComputeSemanticId(uint32_t create_site_pc, uint32_t creating_tid,
|
||||
uint64_t tid_event_idx_at_creation,
|
||||
uint32_t object_type);
|
||||
|
||||
// One emit per imported kernel function invocation. Emitted by the export
|
||||
// trampoline before the kernel.call event.
|
||||
void EmitImportCall(const char* module_name, uint16_t ordinal,
|
||||
const char* fn_name);
|
||||
|
||||
// Kernel call entry / return. args/args_resolved are deferred to a later
|
||||
// phase; v1 emits the name + return value only (sufficient for the diff
|
||||
// tool to align by sequence).
|
||||
void EmitKernelCall(const char* name);
|
||||
// Phase C+10: schema-v1 extension — emit kernel.call whose
|
||||
// `args_resolved` field carries a resolved `"path"` value (see
|
||||
// schema-v1.md kernel.call payload). `path == nullptr || *path == '\0'`
|
||||
// degrades to the existing empty-args_resolved form.
|
||||
void EmitKernelCallWithPath(const char* name, const char* path);
|
||||
void EmitKernelReturn(const char* name, uint64_t return_value);
|
||||
|
||||
// Handle lifecycle. raw_handle_id is engine-local; the diff key is the
|
||||
// FNV-1a semantic id.
|
||||
void EmitHandleCreate(uint64_t semantic_id, uint32_t object_type,
|
||||
uint32_t raw_handle_id, const char* object_name);
|
||||
void EmitHandleDestroy(uint64_t semantic_id, uint32_t raw_handle_id,
|
||||
uint32_t prior_refcount);
|
||||
|
||||
// Thread create/exit. parent_tid is the caller; entry_pc is the spawned
|
||||
// thread's first instruction.
|
||||
void EmitThreadCreate(uint64_t semantic_id, uint32_t parent_tid,
|
||||
uint32_t entry_pc, uint32_t ctx_ptr, uint32_t priority,
|
||||
uint32_t affinity, uint32_t stack_size, bool suspended);
|
||||
void EmitThreadExit(uint32_t exit_code);
|
||||
|
||||
// Wait begin/end. handles_count + handles_semantic_ids array.
|
||||
void EmitWaitBegin(const uint64_t* handles_semantic_ids, uint32_t count,
|
||||
int64_t timeout_ns, bool alertable, bool wait_all);
|
||||
void EmitWaitEnd(uint32_t status, uint64_t woken_by_semantic_id_or_zero);
|
||||
|
||||
// Returns the next per-tid event index (post-increment). Useful for
|
||||
// `tid_event_idx_at_creation` capture before calling ComputeSemanticId.
|
||||
uint64_t PeekTidEventIdx();
|
||||
|
||||
// Phase C+15-α: handle-semantic-ID registry. Maps raw handle id ->
|
||||
// FNV-1a 64-bit SID assigned at handle creation, so subsequent
|
||||
// `handle.destroy` / `wait.begin` / etc. events can emit a stable
|
||||
// cross-engine identity. No-op when event_log is disabled.
|
||||
void RegisterHandleSemanticId(uint32_t raw_handle_id, uint64_t sid);
|
||||
uint64_t LookupHandleSemanticId(uint32_t raw_handle_id);
|
||||
uint64_t ForgetHandleSemanticId(uint32_t raw_handle_id);
|
||||
|
||||
// Convenience: at handle creation time, peek tid_event_idx, compute
|
||||
// the FNV-1a SID, register it for `raw_handle_id`, and emit a
|
||||
// `handle.create` event. Returns the SID. `create_site_pc` is set to
|
||||
// 0 by callers that cannot resolve a guest LR — both engines agree
|
||||
// on `0` for canonicalization at v1.1.
|
||||
uint64_t EmitHandleCreateAuto(uint32_t create_site_pc, uint32_t object_type,
|
||||
uint32_t raw_handle_id,
|
||||
const char* object_name);
|
||||
|
||||
// Convenience: forget mapping + emit `handle.destroy` with the
|
||||
// previously registered SID.
|
||||
void EmitHandleDestroyAuto(uint32_t raw_handle_id, uint32_t prior_refcount);
|
||||
|
||||
// Phase C+18: marker constant used as `create_site_pc` in shared-global
|
||||
// SID computation. Both engines must use exactly this value. See
|
||||
// schema-v1.md §"Shared-global SIDs".
|
||||
constexpr uint32_t kSharedGlobalSidMarker = 0xC01AB005;
|
||||
|
||||
// Phase C+18: compute the scheduling-invariant SID for a
|
||||
// **process-global** kernel dispatcher (canary's
|
||||
// `XObject::GetNativeObject` lazy-wrap on first guest-thread touch).
|
||||
// Keyed on `(SHARED_GLOBAL_SID_MARKER, 0, pointer, object_type)` so the
|
||||
// SID depends only on the object's identity, not on the scheduling order.
|
||||
uint64_t ComputeSharedGlobalSemanticId(uint32_t pointer, uint32_t object_type);
|
||||
|
||||
// Phase C+18: emit `handle.create` with a scheduling-invariant SID for
|
||||
// a process-global kernel dispatcher synthesized by
|
||||
// `XObject::GetNativeObject`. The SID is computed via
|
||||
// `ComputeSharedGlobalSemanticId(pointer, object_type)` so the same
|
||||
// dispatcher yields the same SID in both engines regardless of which
|
||||
// guest thread happens to be the first toucher. `raw_handle_id` is the
|
||||
// XObject's allocated handle; `pointer` is the guest dispatcher
|
||||
// (`X_DISPATCH_HEADER*`) pointer (used only to derive the SID).
|
||||
//
|
||||
// Caller MUST avoid the regular AddHandle emit for this XObject (set
|
||||
// the in-flight thread-local marker around the `new XEvent` /
|
||||
// `new XSemaphore` ctor and have the AddHandle hook short-circuit).
|
||||
void EmitHandleCreateSharedGlobal(uint32_t pointer, uint32_t object_type,
|
||||
uint32_t raw_handle_id,
|
||||
const char* object_name);
|
||||
|
||||
// Phase C+18: thread-local flag indicating the current host thread is
|
||||
// inside `XObject::GetNativeObject` lazy-wrap, which constructs a new
|
||||
// XEvent/XSemaphore wrapper for a process-global guest dispatcher.
|
||||
// `AddHandle` consults this to skip its regular per-thread
|
||||
// `handle.create` emit; the explicit shared-global emit happens in
|
||||
// `GetNativeObject` after `StashHandle`. The flag is a single
|
||||
// host-thread-local bool — re-entrancy is not expected (the global
|
||||
// critical region is held throughout).
|
||||
void SetInGetNativeObject(bool active);
|
||||
bool IsInGetNativeObject();
|
||||
|
||||
// Phase D Stage 1: emit a `contention.observed` event from
|
||||
// `RtlEnterCriticalSection_entry` when the spin-loop is exhausted and
|
||||
// control falls through to `xeKeWaitForSingleObject`. The Stage-2 manifest
|
||||
// builder filters on `contended=true` and keys on `(tid, tid_event_idx)`
|
||||
// so the Stage-3 replay loop in ours can park its own `rtl_enter_critical_section`
|
||||
// at exactly the same per-tid ordinal.
|
||||
//
|
||||
// `cs_guest_ptr` is the guest VA of the `X_RTL_CRITICAL_SECTION` (the
|
||||
// argument to RtlEnterCS). `site_sid` is computed via
|
||||
// `ComputeSharedGlobalSemanticId(cs_guest_ptr, kObjCriticalSection)` so
|
||||
// both engines agree on the SID for the same CS pointer.
|
||||
//
|
||||
// Gated on `cvars::kernel_emit_contention && IsEnabled()`. Default
|
||||
// behavior (cvar off) is byte-identical to pre-Stage-1 canary.
|
||||
void EmitContentionObserved(uint32_t cs_guest_ptr, bool contended);
|
||||
|
||||
// ── Expansive extraction tracing (game-data RE; gated by phase_a_trace_args /
|
||||
// phase_a_hash_probe, default off) ─────────────────────────────────────────
|
||||
|
||||
// kernel.call with populated `args` (raw r3..r10 from the PPCContext, passed
|
||||
// as void*) and `args_resolved` (the resolved file path when known).
|
||||
void EmitKernelCallArgs(const char* name, void* ppc_context,
|
||||
const char* resolved_path);
|
||||
|
||||
// file.read — a guest read from an open file handle (path resolved from the
|
||||
// handle via the object table). Enables correlating .pak reads to TOC entries.
|
||||
void EmitFileRead(uint32_t handle, const char* path, uint64_t offset,
|
||||
uint32_t length, uint32_t buffer_va);
|
||||
|
||||
// guest.call — emitted by the guest-PC hash probe: `arg_str` is r3 dereferenced
|
||||
// as a guest C-string (the archive path being hashed). Used to recover the
|
||||
// custom IPFB/IDXD name-hash by observing (string -> hash) pairs.
|
||||
void EmitGuestCall(uint32_t pc, const char* arg_str, uint32_t r3, uint32_t r4,
|
||||
uint32_t r5, uint32_t r6);
|
||||
|
||||
} // namespace phase_a
|
||||
} // namespace kernel
|
||||
} // namespace xe
|
||||
|
||||
#endif // XENIA_KERNEL_EVENT_LOG_H_
|
||||
@@ -9,6 +9,14 @@
|
||||
|
||||
#include <ranges>
|
||||
|
||||
#include <atomic>
|
||||
#include <chrono>
|
||||
#include <cstdio>
|
||||
#include <thread>
|
||||
#if defined(__linux__)
|
||||
#include <malloc.h>
|
||||
#endif
|
||||
|
||||
#include "xenia/kernel/kernel_state.h"
|
||||
|
||||
#include "xenia/base/byte_stream.h"
|
||||
@@ -41,9 +49,69 @@ DEFINE_uint32(kernel_build_version, 1888, "Define current kernel version",
|
||||
|
||||
DECLARE_string(cl);
|
||||
|
||||
DEFINE_bool(mem_watch, true,
|
||||
"Periodically log host RSS / malloc-vs-mmap / guest-physical / "
|
||||
"cache-deque size to localize the mission memory leak.", "Kernel");
|
||||
DEFINE_uint32(mem_watch_secs, 3, "MEM-WATCH sample interval (seconds).",
|
||||
"Kernel");
|
||||
|
||||
namespace xe {
|
||||
namespace kernel {
|
||||
|
||||
// Diagnostic: a detached sampler that periodically logs where host memory is
|
||||
// going, so a SHORT mission run localizes the leak (host malloc vs mmap vs
|
||||
// guest-physical vs the cache work-queue). Gated by --mem_watch.
|
||||
static std::atomic<bool> g_mem_watch_run{false};
|
||||
|
||||
static void MemWatchLoop(Memory* memory) {
|
||||
uint64_t peak_rss_kb = 0;
|
||||
while (g_mem_watch_run.load(std::memory_order_relaxed)) {
|
||||
// Host RSS / VmSize from /proc/self/statm (fields in pages).
|
||||
uint64_t rss_kb = 0, vsz_kb = 0;
|
||||
if (FILE* f = std::fopen("/proc/self/statm", "r")) {
|
||||
unsigned long vsz_pg = 0, rss_pg = 0;
|
||||
if (std::fscanf(f, "%lu %lu", &vsz_pg, &rss_pg) == 2) {
|
||||
rss_kb = static_cast<uint64_t>(rss_pg) * 4; // 4KB pages
|
||||
vsz_kb = static_cast<uint64_t>(vsz_pg) * 4;
|
||||
}
|
||||
std::fclose(f);
|
||||
}
|
||||
if (rss_kb > peak_rss_kb) peak_rss_kb = rss_kb;
|
||||
|
||||
// Host allocator breakdown: malloc-in-use vs mmap'd bytes.
|
||||
uint64_t malloc_kb = 0, mmap_kb = 0;
|
||||
#if defined(__linux__)
|
||||
struct mallinfo2 mi = mallinfo2();
|
||||
malloc_kb = static_cast<uint64_t>(mi.uordblks) / 1024;
|
||||
mmap_kb = static_cast<uint64_t>(mi.hblkhd) / 1024;
|
||||
#endif
|
||||
|
||||
// Cache work-queue (guest): deque count OBJ+0x58 / list count OBJ+0x38,
|
||||
// only once the singleton is initialized (once-flag 0x828F48B4 bit0).
|
||||
uint32_t deque = 0, listc = 0;
|
||||
auto rd = [&](uint32_t va) -> uint32_t {
|
||||
auto p = memory->TranslateVirtual<xe::be<uint32_t>*>(va);
|
||||
return p ? static_cast<uint32_t>(*p) : 0;
|
||||
};
|
||||
if (rd(0x828F48B4u) & 1u) {
|
||||
deque = rd(0x828F4890u);
|
||||
listc = rd(0x828F4870u);
|
||||
}
|
||||
|
||||
XELOGE(
|
||||
"MEM-WATCH rss={}MB (peak {}MB) vsz={}MB malloc_inuse={}MB mmap={}MB "
|
||||
"cache_deque={} cache_list={}",
|
||||
rss_kb / 1024, peak_rss_kb / 1024, vsz_kb / 1024, malloc_kb / 1024,
|
||||
mmap_kb / 1024, deque, listc);
|
||||
|
||||
for (uint32_t i = 0; i < cvars::mem_watch_secs * 10 &&
|
||||
g_mem_watch_run.load(std::memory_order_relaxed);
|
||||
++i) {
|
||||
std::this_thread::sleep_for(std::chrono::milliseconds(100));
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
constexpr std::chrono::milliseconds kDeferredOverlappedDelayMillis(25);
|
||||
|
||||
// This is a global object initialized with the XboxkrnlModule.
|
||||
@@ -78,9 +146,16 @@ KernelState::KernelState(Emulator* emulator)
|
||||
kMemoryProtectRead | kMemoryProtectWrite);
|
||||
|
||||
xenia_assert(fixed_alloc_worked);
|
||||
|
||||
if (cvars::mem_watch) {
|
||||
g_mem_watch_run.store(true, std::memory_order_relaxed);
|
||||
Memory* mem = memory_;
|
||||
std::thread([mem]() { MemWatchLoop(mem); }).detach();
|
||||
}
|
||||
}
|
||||
|
||||
KernelState::~KernelState() {
|
||||
g_mem_watch_run.store(false, std::memory_order_relaxed);
|
||||
SetExecutableModule(nullptr);
|
||||
|
||||
if (dispatch_thread_running_) {
|
||||
|
||||
@@ -479,6 +479,29 @@ enum class KernelModuleId {
|
||||
xbdm,
|
||||
};
|
||||
|
||||
// Phase A bridge — see kernel/event_log.h. Declared inline here to avoid
|
||||
// pulling the event_log / PPCContext headers into shim_utils.h's transitive
|
||||
// include set. Zero-cost when --phase_a_event_log_path is unset (Enabled()
|
||||
// returns false and the hooks are skipped).
|
||||
namespace phase_a_bridge {
|
||||
constexpr const char* KernelModuleIdName(KernelModuleId m) {
|
||||
switch (m) {
|
||||
case KernelModuleId::xboxkrnl: return "xboxkrnl.exe";
|
||||
case KernelModuleId::xam: return "xam.xex";
|
||||
case KernelModuleId::xbdm: return "xbdm.xex";
|
||||
}
|
||||
return "unknown";
|
||||
}
|
||||
bool Enabled();
|
||||
void EmitReturn(const char* name, uint64_t return_value);
|
||||
// Resolves path-bearing export args (OBJECT_ATTRIBUTES*, handles) from the PPC
|
||||
// context and, under --phase_a_trace_args, fills args/args_resolved and emits
|
||||
// file.read events. `ppc_context` is a void* to keep PPCContext out of this
|
||||
// header's transitive includes.
|
||||
void EmitImportAndCallWithCtx(const char* module_name, uint16_t ord,
|
||||
const char* name, void* ppc_context);
|
||||
} // namespace phase_a_bridge
|
||||
|
||||
template <size_t I = 0, typename... Ps>
|
||||
requires(I == sizeof...(Ps))
|
||||
void AppendKernelCallParams(StringBuffer& string_buffer,
|
||||
@@ -558,14 +581,26 @@ struct ExportRegistrerHelper {
|
||||
cvars::log_high_frequency_kernel_calls)) {
|
||||
PrintKernelCall(export_entry, params);
|
||||
}
|
||||
const bool phase_a_on = phase_a_bridge::Enabled();
|
||||
if (phase_a_on) {
|
||||
phase_a_bridge::EmitImportAndCallWithCtx(
|
||||
phase_a_bridge::KernelModuleIdName(MODULE), ORDINAL,
|
||||
export_entry->name, ppc_context);
|
||||
}
|
||||
if constexpr (std::is_void<R>::value) {
|
||||
KernelTrampoline(fn, std::forward<std::tuple<Ps...>>(params),
|
||||
std::make_index_sequence<sizeof...(Ps)>());
|
||||
if (phase_a_on) {
|
||||
phase_a_bridge::EmitReturn(export_entry->name, 0);
|
||||
}
|
||||
} else {
|
||||
auto result =
|
||||
KernelTrampoline(fn, std::forward<std::tuple<Ps...>>(params),
|
||||
std::make_index_sequence<sizeof...(Ps)>());
|
||||
result.Store(ppc_context);
|
||||
if (phase_a_on) {
|
||||
phase_a_bridge::EmitReturn(export_entry->name, 0);
|
||||
}
|
||||
if (TAGS &
|
||||
(xe::cpu::ExportTag::kLog | xe::cpu::ExportTag::kLogResult)) {
|
||||
// TODO(benvanik): log result.
|
||||
|
||||
@@ -7,7 +7,9 @@
|
||||
******************************************************************************
|
||||
*/
|
||||
|
||||
#include "xenia/apu/apu_flags.h"
|
||||
#include "xenia/apu/audio_system.h"
|
||||
#include "xenia/base/logging.h"
|
||||
#include "xenia/emulator.h"
|
||||
#include "xenia/kernel/kernel_state.h"
|
||||
#include "xenia/kernel/util/shim_utils.h"
|
||||
@@ -55,8 +57,13 @@ DECLARE_XBOXKRNL_EXPORT2(XAudioGetVoiceCategoryVolume, kAudio, kStub,
|
||||
dword_result_t XAudioEnableDucker_entry(dword_t unk) { return X_ERROR_SUCCESS; }
|
||||
DECLARE_XBOXKRNL_EXPORT1(XAudioEnableDucker, kAudio, kStub);
|
||||
|
||||
dword_result_t XAudioRegisterRenderDriverClient_entry(lpdword_t callback_ptr,
|
||||
lpdword_t driver_ptr) {
|
||||
dword_result_t XAudioRegisterRenderDriverClient_entry(
|
||||
lpdword_t callback_ptr, lpdword_t driver_ptr,
|
||||
const ppc_context_t& ppc_context) {
|
||||
if (cvars::audio_watchdog) {
|
||||
XELOGW("AUDIO-WD guest called XAudioRegisterRenderDriverClient lr={:08X}",
|
||||
static_cast<uint32_t>(ppc_context->lr));
|
||||
}
|
||||
if (!callback_ptr) {
|
||||
return X_E_INVALIDARG;
|
||||
}
|
||||
@@ -84,9 +91,17 @@ DECLARE_XBOXKRNL_EXPORT1(XAudioRegisterRenderDriverClient, kAudio,
|
||||
kImplemented);
|
||||
|
||||
dword_result_t XAudioUnregisterRenderDriverClient_entry(
|
||||
lpunknown_t driver_ptr) {
|
||||
lpunknown_t driver_ptr, const ppc_context_t& ppc_context) {
|
||||
assert_true((driver_ptr.guest_address() & 0xFFFF0000) == 0x41550000);
|
||||
|
||||
// Who tore audio down? The guest's return address names the game code path
|
||||
// (resolve with zq.py fn <lr>) -- the game only does this on its own error /
|
||||
// teardown logic, which is what we are hunting. Diagnostics only.
|
||||
if (cvars::audio_watchdog) {
|
||||
XELOGW("AUDIO-WD guest called XAudioUnregisterRenderDriverClient lr={:08X}",
|
||||
static_cast<uint32_t>(ppc_context->lr));
|
||||
}
|
||||
|
||||
auto audio_system = kernel_state()->emulator()->audio_system();
|
||||
audio_system->UnregisterClient(driver_ptr.guest_address() & 0x0000FFFF);
|
||||
return X_ERROR_SUCCESS;
|
||||
|
||||
@@ -7,8 +7,17 @@
|
||||
******************************************************************************
|
||||
*/
|
||||
|
||||
#include <algorithm>
|
||||
#include <map>
|
||||
#include <set>
|
||||
#include <vector>
|
||||
|
||||
#include "xenia/base/cvar.h"
|
||||
#include "xenia/base/debugging.h"
|
||||
#include "xenia/base/logging.h"
|
||||
#include "xenia/cpu/backend/backend.h"
|
||||
#include "xenia/cpu/function.h"
|
||||
#include "xenia/cpu/processor.h"
|
||||
#include "xenia/emulator.h"
|
||||
#include "xenia/kernel/kernel_state.h"
|
||||
#include "xenia/kernel/util/shim_utils.h"
|
||||
@@ -19,6 +28,22 @@
|
||||
#include "xenia/ui/window.h"
|
||||
#include "xenia/ui/windowed_app_context.h"
|
||||
|
||||
DEFINE_bool(
|
||||
cache_throw_diag, false,
|
||||
"Run the heavy guest-throw diagnostics (LogGuestThrow / cache-manager dump / "
|
||||
"catch-frame walk) on every guest C++ throw. OFF by default: in missions the "
|
||||
"cache throws constantly and these dumps allocate gigabytes -- they are for "
|
||||
"targeted debugging only.",
|
||||
"Kernel");
|
||||
|
||||
DEFINE_bool(
|
||||
eh_dispatch, false,
|
||||
"Dispatch guest C++ exceptions (0xE06D7363) to their catch handler instead "
|
||||
"of letting the throw fall through. NOTE: disproven as a fix for the Project "
|
||||
"Sylpheed cache crash (that throw is uncaught by design -- its stack ends at "
|
||||
"the thread-entry Execute boundary); kept as inert infra + diagnostics.",
|
||||
"Kernel");
|
||||
|
||||
namespace xe {
|
||||
namespace kernel {
|
||||
namespace xboxkrnl {
|
||||
@@ -104,6 +129,468 @@ typedef struct {
|
||||
xe::be<uint32_t> catchable_type_array_ptr;
|
||||
} x_s__ThrowInfo;
|
||||
|
||||
// Read a guest C-string, bounded.
|
||||
static std::string GuestCString(uint32_t guest_ptr, size_t max_len = 128) {
|
||||
if (!guest_ptr) {
|
||||
return {};
|
||||
}
|
||||
auto p = kernel_memory()->TranslateVirtual<const char*>(guest_ptr);
|
||||
if (!p) {
|
||||
return {};
|
||||
}
|
||||
std::string s;
|
||||
for (size_t i = 0; i < max_len && p[i]; ++i) {
|
||||
s.push_back(p[i]);
|
||||
}
|
||||
return s;
|
||||
}
|
||||
|
||||
// Name the thrown C++ type via the MSVC RTTI chain hanging off its vtable:
|
||||
// object -> vtable ; vtable[-1] -> CompleteObjectLocator ; COL+0xC ->
|
||||
// TypeDescriptor ; TypeDescriptor+8 -> mangled name (".?AVout_of_range@std@@")
|
||||
static std::string ThrownTypeName(uint32_t thrown_ptr) {
|
||||
if (!thrown_ptr) {
|
||||
return "<null>";
|
||||
}
|
||||
auto rd32 = [](uint32_t va) -> uint32_t {
|
||||
auto p = kernel_memory()->TranslateVirtual<xe::be<uint32_t>*>(va);
|
||||
return p ? static_cast<uint32_t>(*p) : 0;
|
||||
};
|
||||
const uint32_t vtable = rd32(thrown_ptr);
|
||||
if (!vtable) {
|
||||
return "<no vtable>";
|
||||
}
|
||||
const uint32_t col = rd32(vtable - 4);
|
||||
if (!col) {
|
||||
return "<no RTTI>";
|
||||
}
|
||||
const uint32_t type_desc = rd32(col + 0x0C);
|
||||
if (!type_desc) {
|
||||
return "<no type descriptor>";
|
||||
}
|
||||
return GuestCString(type_desc + 8);
|
||||
}
|
||||
|
||||
// Diagnostics for the swallowed-throw crash: xenia does NOT dispatch guest C++
|
||||
// exceptions (see below), so a throw returns and the game crashes in the
|
||||
// unreachable code after it. By then the crash dump's registers are already
|
||||
// clobbered. Capture the guest state HERE, while the throwing call frame is
|
||||
// still intact -- the thrown type, the registers (the failing lookup's key and
|
||||
// loop state live in these), and the guest call stack.
|
||||
// Dump the asset-cache-manager LRU state at the moment it throws out_of_range,
|
||||
// so we can see WHICH access-order deque hash-pair is missing from the entry
|
||||
// map (the desync that crashes in sub_8245A098). r25 survives the throw and
|
||||
// holds the cache-manager global (guest VA 0x828F4838). Layout (from RE):
|
||||
// OBJ+0x30 = std::list<Entry> (map is rebuilt from this, keyed by hash-pair)
|
||||
// OBJ+0x48 = std::deque<hashpair(8B)>: +0x4C block-map ptr, +0x50 map_size,
|
||||
// +0x54 start off, +0x58 element count. Element i (8-byte, 2/block):
|
||||
// bi=((start+i)/2); if bi>=map_size bi-=map_size; addr=blockmap[bi]+(i&1)*8
|
||||
static void DumpCacheManagerOnThrow(const ppc_context_t& ctx) {
|
||||
const uint32_t OBJ = 0x828F4838u;
|
||||
if (static_cast<uint32_t>(ctx->r[25]) != OBJ) {
|
||||
return; // not the cache-manager map::at that threw
|
||||
}
|
||||
auto rd = [](uint32_t va) -> uint32_t {
|
||||
auto p = kernel_memory()->TranslateVirtual<xe::be<uint32_t>*>(va);
|
||||
return p ? static_cast<uint32_t>(*p) : 0;
|
||||
};
|
||||
const uint32_t deque_count = rd(OBJ + 0x58);
|
||||
const uint32_t list_count = rd(OBJ + 0x38);
|
||||
const uint32_t blockmap = rd(OBJ + 0x4C);
|
||||
const uint32_t map_size = rd(OBJ + 0x50);
|
||||
const uint32_t start = rd(OBJ + 0x54);
|
||||
XELOGE(
|
||||
"CACHE-DUMP deque_count={} list_count={} blockmap={:08X} map_size={} "
|
||||
"start={}",
|
||||
deque_count, list_count, blockmap, map_size, start);
|
||||
// Raw header words -- resolve the real container layout without guessing.
|
||||
auto rawrow = [&](const char* tag, uint32_t base, int words) {
|
||||
std::string s;
|
||||
for (int i = 0; i < words; ++i)
|
||||
s += fmt::format(" +{:X}={:08X}", i * 4, rd(base + i * 4));
|
||||
XELOGE("CACHE-RAW {} @{:08X}:{}", tag, base, s);
|
||||
};
|
||||
rawrow("mgr+0x28", OBJ + 0x28, 16); // map(+0x30) + deque(+0x48) headers
|
||||
// deque hash-pairs (access order)
|
||||
std::string dq;
|
||||
const uint32_t n = deque_count > 512 ? 512 : deque_count; // sanity cap
|
||||
for (uint32_t i = 0; i < n; ++i) {
|
||||
uint32_t bi = (start + i) / 2;
|
||||
if (map_size && bi >= map_size) {
|
||||
bi -= map_size;
|
||||
}
|
||||
const uint32_t block = rd(blockmap + bi * 4);
|
||||
const uint32_t addr = block + (i & 1) * 8;
|
||||
dq += fmt::format(" [{}]{:08X}:{:08X}", i, rd(addr), rd(addr + 4));
|
||||
}
|
||||
XELOGE("CACHE-DUMP deque hashpairs:{}", dq);
|
||||
|
||||
// Walk the entry map at OBJ+0x30 (MSVC _Tree, CONFIRMED by live raw dump:
|
||||
// _Left@+0, _Parent@+4, _Right@+8, keyLo@+12, keyHi@+16, _Isnil@+25). Map
|
||||
// object header is at OBJ+0x30; head=[OBJ+0x34]; root=head._Parent=[head+4].
|
||||
// This is the map sub_8245A098 queries per deque entry.
|
||||
std::set<uint64_t> map_keys;
|
||||
const uint32_t head = rd(OBJ + 0x34);
|
||||
const uint32_t root = head ? rd(head + 4) : 0;
|
||||
std::vector<uint32_t> stack;
|
||||
if (root && (rd(root + 25) & 0xFF) == 0) {
|
||||
stack.push_back(root);
|
||||
}
|
||||
// Hard guards: a corrupted map (cyclic/garbage node pointers -- common at the
|
||||
// moment it throws) would otherwise balloon this walk to gigabytes.
|
||||
uint32_t visits = 0;
|
||||
while (!stack.empty() && map_keys.size() < 4096 && ++visits < 100000 &&
|
||||
stack.size() < 100000) {
|
||||
const uint32_t nd = stack.back();
|
||||
stack.pop_back();
|
||||
const uint64_t key = (static_cast<uint64_t>(rd(nd + 12)) << 32) | rd(nd + 16);
|
||||
map_keys.insert(key);
|
||||
const uint32_t l = rd(nd + 0), r = rd(nd + 8);
|
||||
if (l && (rd(l + 25) & 0xFF) == 0) stack.push_back(l);
|
||||
if (r && (rd(r + 25) & 0xFF) == 0) stack.push_back(r);
|
||||
}
|
||||
// For each deque key, flag whether it exists in the persistent map. The
|
||||
// orphan(s) = deque keys absent from the map == the cause of the map::at miss.
|
||||
std::string orphans;
|
||||
uint32_t orphan_count = 0;
|
||||
for (uint32_t i = 0; i < n; ++i) {
|
||||
uint32_t bi = (start + i) / 2;
|
||||
if (map_size && bi >= map_size) bi -= map_size;
|
||||
const uint32_t block = rd(blockmap + bi * 4);
|
||||
const uint32_t addr = block + (i & 1) * 8;
|
||||
const uint64_t key =
|
||||
(static_cast<uint64_t>(rd(addr)) << 32) | rd(addr + 4);
|
||||
if (!map_keys.count(key)) {
|
||||
orphans += fmt::format(" [{}]{:08X}:{:08X}", i, rd(addr), rd(addr + 4));
|
||||
++orphan_count;
|
||||
}
|
||||
}
|
||||
XELOGE("CACHE-DUMP map_keys={} deque_orphans={} (deque keys NOT in map):{}",
|
||||
static_cast<uint32_t>(map_keys.size()), orphan_count, orphans);
|
||||
|
||||
// --- SNAPSHOT vs LIVE: prove the TOCTOU race. The flush (sub_8245A098) locks,
|
||||
// copies OBJ+0x30 into a temp map at [flush_r31+104], UNLOCKS (0x8245a150),
|
||||
// then iterates the live deque doing map::at on the FROZEN snapshot. A
|
||||
// concurrent LOCKED add (8245ABD8/8245AD00) pushes a deque + map entry during
|
||||
// the unlocked window -> that key is in the LIVE map but NOT the snapshot ->
|
||||
// map::at throws. Find the flush frame (its live PC is in the map::at loop);
|
||||
// its snapshot map object is at frame_sp+104 (== r26 at the throw).
|
||||
uint32_t flush_sp = 0;
|
||||
{
|
||||
uint32_t sp = static_cast<uint32_t>(ctx->r[1]);
|
||||
for (int depth = 0; depth < 128 && sp; ++depth) {
|
||||
auto f = kernel_memory()->TranslateVirtual(sp);
|
||||
if (!f) break;
|
||||
uint32_t nsp = xe::load_and_swap<uint32_t>(f);
|
||||
if (nsp <= sp || nsp - sp > 0x1000000) break;
|
||||
auto lp = kernel_memory()->TranslateVirtual(nsp - 8);
|
||||
uint32_t pc = lp ? xe::load_and_swap<uint32_t>(lp) : 0;
|
||||
if (pc >= 0x8245A154u && pc <= 0x8245A1D0u) { // flush deque/map::at loop
|
||||
flush_sp = nsp;
|
||||
break;
|
||||
}
|
||||
sp = nsp;
|
||||
}
|
||||
}
|
||||
if (!flush_sp) {
|
||||
XELOGE("CACHE-DUMP flush frame not found on stack (snapshot compare skipped)");
|
||||
return;
|
||||
}
|
||||
rawrow("snapshot@r31+104", flush_sp + 96, 16); // raw temp-map header region
|
||||
const uint32_t snap = flush_sp + 104; // temp map object [r31+104]
|
||||
std::set<uint64_t> snap_keys;
|
||||
const uint32_t shead = rd(snap + 4);
|
||||
const uint32_t sroot = shead ? rd(shead + 4) : 0;
|
||||
std::vector<uint32_t> st;
|
||||
if (sroot && (rd(sroot + 25) & 0xFF) == 0) st.push_back(sroot);
|
||||
uint32_t svisits = 0;
|
||||
while (!st.empty() && snap_keys.size() < 4096 && ++svisits < 100000 &&
|
||||
st.size() < 100000) {
|
||||
const uint32_t nd = st.back();
|
||||
st.pop_back();
|
||||
snap_keys.insert((static_cast<uint64_t>(rd(nd + 12)) << 32) | rd(nd + 16));
|
||||
const uint32_t l = rd(nd + 0), r = rd(nd + 8);
|
||||
if (l && (rd(l + 25) & 0xFF) == 0) st.push_back(l);
|
||||
if (r && (rd(r + 25) & 0xFF) == 0) st.push_back(r);
|
||||
}
|
||||
std::string miss;
|
||||
uint32_t miss_count = 0;
|
||||
for (uint32_t i = 0; i < n; ++i) {
|
||||
uint32_t bi = (start + i) / 2;
|
||||
if (map_size && bi >= map_size) bi -= map_size;
|
||||
const uint32_t addr = rd(blockmap + bi * 4) + (i & 1) * 8;
|
||||
const uint64_t key = (static_cast<uint64_t>(rd(addr)) << 32) | rd(addr + 4);
|
||||
if (!snap_keys.count(key)) {
|
||||
miss += fmt::format(" [{}]{:08X}:{:08X}(in_live_map={})", i,
|
||||
static_cast<uint32_t>(key >> 32),
|
||||
static_cast<uint32_t>(key), map_keys.count(key) ? 1 : 0);
|
||||
++miss_count;
|
||||
}
|
||||
}
|
||||
XELOGE(
|
||||
"CACHE-DUMP flush_sp={:08X} snapshot_keys={} deque_NOT_in_snapshot={} "
|
||||
"(these are what map::at throws on; in_live_map=1 => added during the "
|
||||
"flush's UNLOCKED window = the TOCTOU race):{}",
|
||||
flush_sp, static_cast<uint32_t>(snap_keys.size()), miss_count, miss);
|
||||
}
|
||||
|
||||
// ---------------------------------------------------------------------------
|
||||
// Fix-A analysis half (read-only): determine which guest stack frame WOULD catch
|
||||
// the current C++ throw and where it would resume, by parsing the guest's MSVC
|
||||
// C++ EH tables. Zero behaviour change -- logs WOULD-CATCH so the frame-finding
|
||||
// can be validated against a live crash before the control-transfer half is
|
||||
// wired in. Layout (all BE u32 unless noted):
|
||||
// FuncInfo (magic 0x19930522): +12 nTryBlocks, +16 pTryBlockMap,
|
||||
// +20 nIPMap, +24 pIP2StateMap
|
||||
// IP2StateMapEntry(8B): +0 Ip(VA), +4 State(int)
|
||||
// TryBlockMapEntry(20B): +0 tryLow, +4 tryHigh, +8 catchHigh, +12 nCatches,
|
||||
// +16 pHandlerArray
|
||||
// HandlerType(16B): +4 pType(TypeDescriptor; 0=catch(...)), +8 dispCatchObj,
|
||||
// +12 addressOfHandler(funclet)
|
||||
// CatchableTypeArray: +0 count, +4 CatchableType*[]; CatchableType: +4 type_ptr
|
||||
namespace {
|
||||
|
||||
struct EhFuncInfo {
|
||||
uint32_t funcinfo_va;
|
||||
uint32_t func_start; // xenia function containing this FuncInfo's code
|
||||
uint32_t first_ip, last_ip; // IP2State map coverage (fallback PC match)
|
||||
uint32_t p_ip, n_ip; // IP2State map
|
||||
uint32_t p_try, n_try; // try-block map
|
||||
};
|
||||
|
||||
static std::vector<EhFuncInfo>* g_eh_catch_index = nullptr;
|
||||
|
||||
static uint32_t EhRd(uint32_t va) {
|
||||
auto p = kernel_memory()->TranslateVirtual<xe::be<uint32_t>*>(va);
|
||||
return p ? static_cast<uint32_t>(*p) : 0;
|
||||
}
|
||||
|
||||
// xenia function-start containing pc, or 0. Non-analyzing lookup: every frame on
|
||||
// a live stack has already executed, so its function is known (no side effects).
|
||||
static uint32_t EhFuncStart(uint32_t pc) {
|
||||
auto* f = kernel_state()->processor()->LookupFunction(pc);
|
||||
return f ? f->address() : 0;
|
||||
}
|
||||
|
||||
// Build the catch index once: scan .rdata for FuncInfo(magic) with nTry>=1.
|
||||
static void EhBuildIndex() {
|
||||
if (g_eh_catch_index) return;
|
||||
g_eh_catch_index = new std::vector<EhFuncInfo>();
|
||||
// .rdata bounds from the PE section table (PESEC): addr 82000600 size 1142488.
|
||||
const uint32_t lo = 0x82000600u, hi = 0x82000600u + 1142488u;
|
||||
for (uint32_t a = lo; a + 28 < hi; a += 4) {
|
||||
if (EhRd(a) != 0x19930522u) continue;
|
||||
uint32_t n_try = EhRd(a + 12), p_try = EhRd(a + 16);
|
||||
uint32_t n_ip = EhRd(a + 20), p_ip = EhRd(a + 24);
|
||||
if (!n_try || !p_try || n_try > 64 || !n_ip || !p_ip) continue;
|
||||
uint32_t first_ip = EhRd(p_ip);
|
||||
uint32_t last_ip = EhRd(p_ip + (n_ip - 1) * 8);
|
||||
uint32_t fn = EhFuncStart(first_ip); // first IP -> its function
|
||||
if (!fn) fn = first_ip; // fall back to the IP itself
|
||||
g_eh_catch_index->push_back(
|
||||
{a, fn, first_ip, last_ip, p_ip, n_ip, p_try, n_try});
|
||||
}
|
||||
XELOGE("EH-INDEX built: {} catch-bearing FuncInfos",
|
||||
static_cast<uint32_t>(g_eh_catch_index->size()));
|
||||
}
|
||||
|
||||
// State at pc: State of the IP2State entry with the greatest Ip<=pc; -1 if pc
|
||||
// precedes the first entry (not inside any protected region).
|
||||
static int EhStateAt(const EhFuncInfo& fi, uint32_t pc) {
|
||||
int state = -1;
|
||||
uint32_t best_ip = 0;
|
||||
for (uint32_t i = 0; i < fi.n_ip; ++i) {
|
||||
uint32_t ip = EhRd(fi.p_ip + i * 8);
|
||||
if (ip <= pc && ip >= best_ip) {
|
||||
best_ip = ip;
|
||||
state = static_cast<int>(EhRd(fi.p_ip + i * 8 + 4));
|
||||
}
|
||||
}
|
||||
return state;
|
||||
}
|
||||
|
||||
} // namespace
|
||||
|
||||
// Sentinel return address ExecuteRaw() gives a guest function (matches
|
||||
// Processor::ExecuteRaw). We force the catching frame's saved-LR slot to this so
|
||||
// the catch funclet returns to us regardless of how it restores LR.
|
||||
static constexpr uint32_t kFuncletReturnSentinel = 0xBCBCBCBCu;
|
||||
|
||||
// Fix A. Dispatch the current guest C++ throw to the first stack frame that
|
||||
// catches it, then resume the guest as if that frame had caught-and-returned.
|
||||
// Returns true if dispatched -- in which case this does NOT return normally: it
|
||||
// calls XThread::Reenter, which throws FiberReentryException to unwind every
|
||||
// intervening host/JIT frame before resuming the guest at the catch frame's
|
||||
// return site. Returns false (falls through to the old crash path) when no
|
||||
// handler matches or --eh_dispatch=false.
|
||||
bool DispatchGuestCatch(pointer_t<X_EXCEPTION_RECORD> record,
|
||||
const ppc_context_t& ctx) {
|
||||
EhBuildIndex();
|
||||
|
||||
const uint32_t thrown_obj = record->exception_information[1];
|
||||
|
||||
// Every TypeDescriptor the throw can be caught as -> its base-subobject
|
||||
// displacement (x_PMD.mdisp), from the throw's CatchableTypeArray.
|
||||
std::map<uint32_t, int32_t> catchable;
|
||||
uint32_t cta = EhRd(record->exception_information[2] + 12);
|
||||
if (cta) {
|
||||
uint32_t n = EhRd(cta);
|
||||
for (uint32_t i = 0; i < n && i < 32; ++i) {
|
||||
uint32_t ct = EhRd(cta + 4 + i * 4);
|
||||
if (ct) catchable[EhRd(ct + 4)] = static_cast<int32_t>(EhRd(ct + 8));
|
||||
}
|
||||
}
|
||||
|
||||
uint32_t sp = static_cast<uint32_t>(ctx->r[1]);
|
||||
for (int depth = 0; depth < 128; ++depth) {
|
||||
auto frame = kernel_memory()->TranslateVirtual(sp);
|
||||
if (!sp || !frame) {
|
||||
XELOGE("EH-WALK stop depth={} sp={:08X} (untranslatable)", depth, sp);
|
||||
break;
|
||||
}
|
||||
uint32_t next_sp = xe::load_and_swap<uint32_t>(frame);
|
||||
// The cache flush runs on a fiber/task stack; the back-chain can jump a long
|
||||
// way (or to a different stack) when crossing into the dispatcher that has
|
||||
// the try/catch. Only require it to go UP; allow large gaps.
|
||||
if (next_sp <= sp) {
|
||||
XELOGE("EH-WALK stop depth={} sp={:08X} next_sp={:08X} (not ascending)",
|
||||
depth, sp, next_sp);
|
||||
break;
|
||||
}
|
||||
if (next_sp - sp > 0x1000000) {
|
||||
XELOGE("EH-WALK stop depth={} sp={:08X} next_sp={:08X} (gap>16M)", depth,
|
||||
sp, next_sp);
|
||||
break;
|
||||
}
|
||||
auto lrp = kernel_memory()->TranslateVirtual(next_sp - 8);
|
||||
uint32_t pc = lrp ? xe::load_and_swap<uint32_t>(lrp) : 0;
|
||||
uint32_t frame_sp = next_sp; // SP_F: the catching frame's running SP
|
||||
sp = next_sp;
|
||||
uint32_t fn = (pc >= 0x82150000 && pc < 0x8284A000) ? EhFuncStart(pc) : 0;
|
||||
XELOGE("EH-WALK depth={} SP_F={:08X} pc={:08X} fn={:08X}", depth, frame_sp,
|
||||
pc, fn);
|
||||
if (pc < 0x82150000 || pc >= 0x8284A000) continue;
|
||||
|
||||
for (const auto& fi : *g_eh_catch_index) {
|
||||
// Match the frame to a catch FuncInfo either by xenia's function-start or
|
||||
// (robust to xenia splitting funcs/funclets) by the FuncInfo's IP range.
|
||||
bool by_fn = fn && fi.func_start == fn;
|
||||
bool by_ip = pc >= fi.first_ip && pc <= fi.last_ip;
|
||||
if (!by_fn && !by_ip) continue;
|
||||
int state = EhStateAt(fi, pc);
|
||||
for (uint32_t t = 0; t < fi.n_try; ++t) {
|
||||
uint32_t te = fi.p_try + t * 20;
|
||||
int try_low = static_cast<int>(EhRd(te));
|
||||
int try_high = static_cast<int>(EhRd(te + 4));
|
||||
if (state < try_low || state > try_high) continue;
|
||||
uint32_t n_catch = EhRd(te + 12), pH = EhRd(te + 16);
|
||||
for (uint32_t c = 0; c < n_catch && c < 32; ++c) {
|
||||
uint32_t pType = EhRd(pH + c * 16 + 4);
|
||||
auto it = (pType == 0) ? catchable.end() : catchable.find(pType);
|
||||
if (pType != 0 && it == catchable.end()) continue;
|
||||
int32_t mdisp = (it == catchable.end()) ? 0 : it->second;
|
||||
uint32_t dispCatchObj = EhRd(pH + c * 16 + 8);
|
||||
uint32_t funclet = EhRd(pH + c * 16 + 12);
|
||||
|
||||
// Establisher frame = SP at F's entry = the back-chain word saved at
|
||||
// F's SP by its `stwu`. The funclet rebuilds its frame ptr as
|
||||
// r31 = r12 - N, and __save/restgprlr save/restore F's nonvolatiles +
|
||||
// return address at [establisher-8].
|
||||
uint32_t establisher = EhRd(frame_sp);
|
||||
uint32_t f_return = EhRd(establisher - 8); // F's real return address
|
||||
|
||||
XELOGE(
|
||||
"GUEST-CATCH frame_pc={:08X} fn={:08X} SP_F={:08X} est={:08X} "
|
||||
"f_return={:08X} state={} try{}[{}..{}] catch#{} pType={:08X} "
|
||||
"obj@est+{:X} funclet={:08X} dispatch={}",
|
||||
pc, fn, frame_sp, establisher, f_return, state, t, try_low,
|
||||
try_high, c, pType, dispCatchObj, funclet,
|
||||
cvars::eh_dispatch ? 1 : 0);
|
||||
|
||||
if (!cvars::eh_dispatch) return false;
|
||||
if (!establisher || !f_return) {
|
||||
XELOGE("GUEST-CATCH abort: bad establisher/return frame");
|
||||
return false;
|
||||
}
|
||||
|
||||
auto store32 = [](uint32_t va, uint32_t val) {
|
||||
auto p = kernel_memory()->TranslateVirtual<xe::be<uint32_t>*>(va);
|
||||
if (p) *p = val;
|
||||
};
|
||||
|
||||
// Hand the caught object (adjusted to the caught base) to the catch.
|
||||
// catch(...) (dispCatchObj==0) takes no object.
|
||||
if (dispCatchObj != 0) {
|
||||
store32(establisher + dispCatchObj,
|
||||
thrown_obj + static_cast<uint32_t>(mdisp));
|
||||
}
|
||||
// Force the funclet to return to us no matter how it restores LR.
|
||||
store32(establisher - 8, kFuncletReturnSentinel);
|
||||
|
||||
// Run the game's own catch funclet in F's frame: r12=r1=establisher.
|
||||
// It runs the catch body, restores F's inherited nonvolatiles, and
|
||||
// returns (r3 = F's return value).
|
||||
ctx->r[12] = establisher;
|
||||
ctx->r[1] = establisher;
|
||||
ctx->processor->ExecuteRaw(ctx->thread_state, funclet);
|
||||
|
||||
// F has effectively caught-and-returned: resume at F's caller with the
|
||||
// funclet's return value. Reenter unwinds all the throw's host/JIT
|
||||
// frames first. r1 is already the caller SP (establisher).
|
||||
ctx->processor->backend()->PrepareForReentry(ctx.value());
|
||||
XELOGE("GUEST-CATCH dispatched -> resuming at f_return={:08X} r3={:08X}",
|
||||
f_return, static_cast<uint32_t>(ctx->r[3]));
|
||||
XThread::GetCurrentThread()->Reenter(f_return);
|
||||
return true; // not reached
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
XELOGE("GUEST-CATCH none (no matching handler frame found)");
|
||||
return false;
|
||||
}
|
||||
|
||||
void LogGuestThrow(pointer_t<X_EXCEPTION_RECORD> record,
|
||||
const ppc_context_t& ctx) {
|
||||
const uint32_t thrown_ptr = record->exception_information[1];
|
||||
XELOGE("GUEST-THROW type={} object={:08X} lr={:08X}",
|
||||
ThrownTypeName(thrown_ptr), thrown_ptr,
|
||||
static_cast<uint32_t>(ctx->lr));
|
||||
DumpCacheManagerOnThrow(ctx);
|
||||
|
||||
std::string regs;
|
||||
for (int i = 3; i <= 31; ++i) {
|
||||
regs += fmt::format(" r{}={:08X}", i, static_cast<uint32_t>(ctx->r[i]));
|
||||
}
|
||||
XELOGE("GUEST-THROW regs:{}", regs);
|
||||
|
||||
// Walk the guest stack. Xenon prologues do `mfspr r12,LR; stw r12,-8(r1)`
|
||||
// BEFORE `stwu r1,-N(r1)`, so a frame's return address is stored at
|
||||
// [caller_sp - 8] = [([sp]) - 8], NOT [sp+4]. Back chain = [sp]. Filter to
|
||||
// .text (0x82150000..0x8284A000).
|
||||
std::string frames;
|
||||
uint32_t sp = static_cast<uint32_t>(ctx->r[1]);
|
||||
for (int depth = 0; depth < 64; ++depth) {
|
||||
auto frame = kernel_memory()->TranslateVirtual(sp);
|
||||
if (!sp || !frame) {
|
||||
break;
|
||||
}
|
||||
const uint32_t next_sp = xe::load_and_swap<uint32_t>(frame);
|
||||
if (next_sp <= sp || next_sp - sp > 0x40000) {
|
||||
break;
|
||||
}
|
||||
auto lrp = kernel_memory()->TranslateVirtual(next_sp - 8);
|
||||
if (lrp) {
|
||||
const uint32_t lr = xe::load_and_swap<uint32_t>(lrp);
|
||||
if (lr >= 0x82150000 && lr < 0x8284A000) {
|
||||
frames += fmt::format(" {:08X}", lr);
|
||||
}
|
||||
}
|
||||
sp = next_sp;
|
||||
}
|
||||
XELOGE("GUEST-THROW guest stack:{}", frames);
|
||||
}
|
||||
|
||||
void HandleCppException(pointer_t<X_EXCEPTION_RECORD> record) {
|
||||
// C++ exception.
|
||||
// https://blogs.msdn.com/b/oldnewthing/archive/2010/07/30/10044061.aspx
|
||||
@@ -128,13 +615,29 @@ void HandleCppException(pointer_t<X_EXCEPTION_RECORD> record) {
|
||||
XELOGE("Guest attempted to throw a C++ exception!");
|
||||
}
|
||||
|
||||
void RtlRaiseException_entry(pointer_t<X_EXCEPTION_RECORD> record) {
|
||||
void RtlRaiseException_entry(pointer_t<X_EXCEPTION_RECORD> record,
|
||||
const ppc_context_t& ppc_context) {
|
||||
switch (record->code) {
|
||||
case 0x406D1388: {
|
||||
HandleSetThreadName(record);
|
||||
return;
|
||||
}
|
||||
case 0xE06D7363: {
|
||||
// Heavy diagnostics are OFF by default: in a mission the cache flush
|
||||
// throws constantly, and these dumps (esp. the cache-manager tree walk on
|
||||
// a corrupted map) allocate gigabytes per throw. Stock behaviour is just
|
||||
// HandleCppException below.
|
||||
if (cvars::cache_throw_diag) {
|
||||
LogGuestThrow(record, ppc_context);
|
||||
}
|
||||
// Fix A: dispatch to the catch handler. On success this does not return
|
||||
// (it reenters the guest at the catch frame). Disproven for the cache
|
||||
// crash and default-off; also skip its (allocating) frame walk unless a
|
||||
// diagnostic/dispatch knob is set.
|
||||
if ((cvars::eh_dispatch || cvars::cache_throw_diag) &&
|
||||
DispatchGuestCatch(record, ppc_context)) {
|
||||
return;
|
||||
}
|
||||
HandleCppException(record);
|
||||
return;
|
||||
}
|
||||
|
||||
@@ -783,6 +783,15 @@ void IoDeleteDevice_entry(dword_t device_ptr, const ppc_context_t& ctx) {
|
||||
|
||||
DECLARE_XBOXKRNL_EXPORT1(IoDeleteDevice, kFileSystem, kStub);
|
||||
|
||||
// NOTE (2026-07-14): do NOT stub StfsCreateDevice / IoDismountVolumeByFileHandle
|
||||
// without testing an actual playthrough. They are deliberately left
|
||||
// unimplemented (the JIT's "undefined extern call" stub handles them, leaving
|
||||
// guest r3 untouched so the title reads back its own first argument as the
|
||||
// status). Implementing them -- even returning X_STATUS_NOT_SUPPORTED -- makes
|
||||
// the title hang at boot (black screen) right after the devkit-memory
|
||||
// allocation, before it ever calls StfsCreateDevice. Whatever the title keys
|
||||
// off here, it is not a plain NTSTATUS check.
|
||||
|
||||
} // namespace xboxkrnl
|
||||
} // namespace kernel
|
||||
} // namespace xe
|
||||
|
||||
@@ -9,6 +9,7 @@
|
||||
|
||||
#include "xenia/kernel/xboxkrnl/xboxkrnl_video.h"
|
||||
|
||||
#include "xenia/base/guest_liveness.h"
|
||||
#include "xenia/base/logging.h"
|
||||
#include "xenia/emulator.h"
|
||||
#include "xenia/gpu/graphics_system.h"
|
||||
@@ -472,6 +473,10 @@ void VdSwap_entry(
|
||||
lpdword_t frontbuffer_ptr, // ptr to frontbuffer address
|
||||
lpdword_t texture_format_ptr, lpdword_t color_space_ptr, lpdword_t width,
|
||||
lpdword_t height) {
|
||||
// Guest-progress heartbeat for the hang watchdog: the game asking to present
|
||||
// a frame is our "still alive" signal (diagnostics only).
|
||||
xe::liveness::guest_swaps.fetch_add(1, std::memory_order_relaxed);
|
||||
|
||||
// All of these parameters are REQUIRED.
|
||||
assert(buffer_ptr);
|
||||
assert(fetch_ptr);
|
||||
|
||||
@@ -117,6 +117,8 @@ XThread* XThread::GetCurrentThread() {
|
||||
return thread;
|
||||
}
|
||||
|
||||
XThread* XThread::TryGetCurrentThread() { return current_xthread_tls_; }
|
||||
|
||||
uint32_t XThread::GetCurrentThreadHandle() {
|
||||
XThread* thread = XThread::GetCurrentThread();
|
||||
return thread->handle();
|
||||
|
||||
@@ -408,6 +408,11 @@ class XThread : public XObject, public cpu::Thread {
|
||||
static bool IsInThread(XThread* other);
|
||||
static bool IsInThread();
|
||||
static XThread* GetCurrentThread();
|
||||
// Null-safe variant of GetCurrentThread: returns nullptr (instead of
|
||||
// asserting) when the calling OS thread is not a guest XThread. Used by
|
||||
// additive instrumentation that can fire from boot code before any XThread
|
||||
// exists. Read-only accessor; no behaviour change.
|
||||
static XThread* TryGetCurrentThread();
|
||||
static uint32_t GetCurrentThreadHandle();
|
||||
static uint32_t GetCurrentThreadId();
|
||||
|
||||
|
||||
@@ -1388,7 +1388,18 @@ bool BaseHeap::Release(uint32_t base_address, uint32_t* out_region_size) {
|
||||
uint32_t base_page_number = (base_address - heap_base_) / page_size_;
|
||||
auto base_page_entry = page_table_[base_page_number];
|
||||
if (base_page_entry.base_address != base_page_number) {
|
||||
XELOGE("BaseHeap::Release failed because address is not a region start");
|
||||
// The guest asked us to free something we refuse to free -- it then
|
||||
// believes that memory is gone while we still hold it. Say WHAT we
|
||||
// refused: the address, the region we think it belongs to, and whether
|
||||
// the page is even allocated. (Was a bare message with no data.)
|
||||
const uint32_t owner_addr =
|
||||
heap_base_ + base_page_entry.base_address * page_size_;
|
||||
XELOGE(
|
||||
"BaseHeap::Release failed because address is not a region start: "
|
||||
"addr={:08X} heap_base={:08X} page={} owning_region_start={:08X} "
|
||||
"region_page_count={} state={:02X}",
|
||||
base_address, heap_base_, base_page_number, owner_addr,
|
||||
base_page_entry.region_page_count, base_page_entry.state);
|
||||
return false;
|
||||
}
|
||||
|
||||
|
||||
2
third_party/DirectXShaderCompiler
vendored
2
third_party/DirectXShaderCompiler
vendored
Submodule third_party/DirectXShaderCompiler updated: 69e54e2908...dc3e6c48d4
Reference in New Issue
Block a user