Files
xenia-rs/crates/xenia-kernel/src/audit.rs
MechaCat02 2a9fd1fc86 feat(kernel): KRNBUG-AUDIT-002 — multi-frame guest stack capture at handle creation
Adds `walk_guest_back_chain` (PPC EABI back-chain walker) and a
`record_create_with_stack` audit hook gated on `--trace-handles-focus`.
NtCreateEvent / NtCreateSemaphore / NtCreateTimer / XamTaskSchedule now
route through the new helper so focused handles capture up to 6 stack
frames at allocation time. Diagnostic-only, read-only memory access:
unfocused handles pay one HashSet lookup, focused ones pay six
back-chain dereferences. Lockstep determinism preserved.

End-to-end finding: handles 0x1004 (8-instance pool via static ctor at
0x8280F810), 0x100c (singleton built inside main()), 0x15e0 (singleton
in distinct cluster) are silph-framework dispatcher objects whose
producer code is unreached at -n 500M. The producer hunt now has class
ownership; vtable/RTTI readout is the next step.

Tests: 576 → 581 green. `--stable-digest -n 100M` instructions=100000002
unchanged. Master HEAD prior: 9d45efe.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
2026-05-03 20:41:06 +02:00

331 lines
13 KiB
Rust

//! Per-handle audit trail for diagnosing HLE sync gaps.
//!
//! When enabled (via `--trace-handles` / `XENIA_TRACE_HANDLES=1`), the kernel
//! records every handle's create/signal/wait/wake events into a bounded
//! ring per handle. `dump_thread_diagnostic` (in `xenia-app`) prints the
//! trail at end-of-run, which lets a session see *who* signaled (or failed
//! to signal) a given handle and *who* parked on it.
//!
//! The harness is behavior-neutral: when `enabled = false` (the default),
//! every record method is an `#[inline]` no-op. When enabled, each record
//! costs an O(1) HashMap probe + a `VecDeque::push_back` with a bounded
//! `pop_front` to keep memory at ~32 KiB per handle worst case.
//!
//! See [project_xenia_rs_scheduler.md] note on the latent
//! `scheduler.deadlock_recoveries` event during boot — this harness exists
//! to identify which kernel API should signal handles
//! `0x10FC / 0x1014 / 0x1104 / 0x10DC / 0x10F0` but doesn't.
use std::collections::{HashMap, HashSet, VecDeque};
/// Maximum events per category per handle. Bounded so a long-running session
/// doesn't OOM if a handle is signaled millions of times.
pub const AUDIT_RING_CAPACITY: usize = 32;
/// One audit record. Captured at the export's call site so `lr` points at
/// the guest caller (one instruction past the `bl` to the kernel thunk).
#[derive(Debug, Clone, Copy)]
pub struct HandleAuditEntry {
/// Per-thread timebase tick at the time of the event. Useful for
/// ordering events across threads — same units as
/// `Scheduler::ctx(0).timebase`.
pub cycle: u64,
/// Guest thread id (NOT hw_id — `tid` survives migration).
pub tid: u32,
/// Caller's LR (the guest pc one past the `bl` to the export).
pub lr: u32,
/// Stable, kernel-internal label naming the source export. e.g.
/// "KeSetEvent", "NtSetEvent", "wake_eligible_waiters".
pub source: &'static str,
/// Free-form auxiliary data. For signals: previous_state. For waits:
/// `(alertable, timeout_ns_or_max)` packed. For wakes: `gpr[3]` set.
/// Read by callers as needed.
pub aux: u64,
}
/// Per-handle audit trail. Lives in `KernelState::audit.trails`.
#[derive(Debug)]
pub struct HandleAuditTrail {
/// Stable label: "Event/Manual", "Event/Auto", "Semaphore", "Timer/Manual",
/// "Timer/Auto", "Mutant", "Thread". Used for filtering in the dump.
pub kind: &'static str,
/// When/who/where the handle was minted.
pub created: HandleAuditEntry,
/// KRNBUG-AUDIT-002 producer-trace. Captured frames at allocation
/// time, only populated when the handle is in `HandleAudit::focus`
/// AND the create site routed through the `_with_stack` variant.
/// Frame layout: `(frame_pointer, saved_lr_for_caller_of_that_frame)`.
/// Index 0 is the live frame: `(ctx.gpr[1], ctx.lr)`. Index 1+ comes
/// from walking the PPC back-chain. An empty vec means either the
/// handle wasn't in focus or the create site didn't capture a stack.
pub created_stack: Vec<(u32, u32)>,
/// Bounded ring of signal events.
pub signals: VecDeque<HandleAuditEntry>,
/// Bounded ring of wait-entry events (one per `Wait*` call).
pub waits: VecDeque<HandleAuditEntry>,
/// Bounded ring of wake events (one per scheduler-side wake).
pub wakes: VecDeque<HandleAuditEntry>,
}
impl HandleAuditTrail {
fn new(kind: &'static str, created: HandleAuditEntry) -> Self {
Self {
kind,
created,
created_stack: Vec::new(),
signals: VecDeque::with_capacity(AUDIT_RING_CAPACITY),
waits: VecDeque::with_capacity(AUDIT_RING_CAPACITY),
wakes: VecDeque::with_capacity(AUDIT_RING_CAPACITY),
}
}
}
/// The audit table itself. Lives on `KernelState`; opt-in via `enabled`.
///
/// `focus` + `ghost_trails` form the **parked-waiter diagnostic** added for
/// audit-2026-05-fix Phase 2 (KRNBUG-AUDIT-001). When `focus` is non-empty,
/// `record_signal_attempt` keeps a "ghost trail" for handles in the focus
/// set even if no `record_create` ever observed them — i.e. the guest hand-
/// initialized a `KEVENT` (via `KeInitializeEvent` or a raw write) and the
/// existing `record_signal` would silently drop the attempt. Ghost trails
/// are the only way to distinguish "guest never called Nt/KeSetEvent on
/// this handle" from "signal landed but waiter wasn't woken".
#[derive(Debug, Default)]
pub struct HandleAudit {
pub trails: HashMap<u32, HandleAuditTrail>,
pub enabled: bool,
/// Focus set: when non-empty, signals targeting handles in this set are
/// captured even when no `record_create` exists. Populated from
/// `--trace-handles=0x1004,0x100c,...`. Empty = whole-table audit.
pub focus: HashSet<u32>,
/// Ghost trails for never-created handles whose signals we still want
/// to see. Keyed by handle. Only populated for handles in `focus`.
pub ghost_trails: HashMap<u32, GhostTrail>,
}
/// A ghost trail is a signal-only timeline for a handle that was never
/// `record_create`d. We don't have a `kind` because we never saw a creation;
/// callers rendering the report should label these as `<UNCREATED>`.
#[derive(Debug, Default)]
pub struct GhostTrail {
pub signals: VecDeque<HandleAuditEntry>,
}
impl HandleAudit {
/// Push an entry into a bounded ring, dropping the oldest when full.
#[inline]
fn push_bounded(ring: &mut VecDeque<HandleAuditEntry>, entry: HandleAuditEntry) {
if ring.len() == AUDIT_RING_CAPACITY {
ring.pop_front();
}
ring.push_back(entry);
}
#[inline]
pub fn record_create(&mut self, handle: u32, kind: &'static str, entry: HandleAuditEntry) {
if !self.enabled {
return;
}
self.trails
.insert(handle, HandleAuditTrail::new(kind, entry));
}
/// Same as `record_create`, but additionally stores a captured guest
/// stack trace on the trail (`created_stack`). Intended for handles
/// in `focus` so the dump can name the actual subsystem caller of the
/// kernel API rather than just the immediate wrapper return.
#[inline]
pub fn record_create_with_stack(
&mut self,
handle: u32,
kind: &'static str,
entry: HandleAuditEntry,
stack: Vec<(u32, u32)>,
) {
if !self.enabled {
return;
}
let mut trail = HandleAuditTrail::new(kind, entry);
trail.created_stack = stack;
self.trails.insert(handle, trail);
}
#[inline]
pub fn record_signal(&mut self, handle: u32, entry: HandleAuditEntry) {
if !self.enabled {
return;
}
if let Some(trail) = self.trails.get_mut(&handle) {
Self::push_bounded(&mut trail.signals, entry);
return;
}
// No primary trail. Fall through to ghost-trail logic so signals
// targeting focus-set handles are not silently dropped.
self.record_signal_attempt_ghost(handle, entry);
}
/// Record a signal attempt that targeted a focus-set handle but had no
/// primary trail (i.e. the handle was never `record_create`d via one
/// of our audit hook sites). Inserts into `ghost_trails`. Bounded by
/// `AUDIT_RING_CAPACITY` per handle. No-op when `enabled = false` or
/// `handle` is not in `focus`.
///
/// Public for direct invocation from internal kernel signal sites that
/// don't go through `record_signal` (e.g. `signal_io_completion_event`,
/// IRQ-callback paths) — those callers should both `record_signal`
/// (for the primary-trail case) AND fall through here.
#[inline]
pub fn record_signal_attempt_ghost(&mut self, handle: u32, entry: HandleAuditEntry) {
if !self.enabled || !self.focus.contains(&handle) {
return;
}
let ghost = self.ghost_trails.entry(handle).or_default();
Self::push_bounded(&mut ghost.signals, entry);
}
#[inline]
pub fn record_wait(&mut self, handle: u32, entry: HandleAuditEntry) {
if !self.enabled {
return;
}
if let Some(trail) = self.trails.get_mut(&handle) {
Self::push_bounded(&mut trail.waits, entry);
}
}
#[inline]
pub fn record_wake(&mut self, handle: u32, entry: HandleAuditEntry) {
if !self.enabled {
return;
}
if let Some(trail) = self.trails.get_mut(&handle) {
Self::push_bounded(&mut trail.wakes, entry);
}
}
/// Convenience: `(signal_count, wait_count, wake_count)` for a handle.
/// Returns `None` if no trail exists.
pub fn counts(&self, handle: u32) -> Option<(usize, usize, usize)> {
self.trails
.get(&handle)
.map(|t| (t.signals.len(), t.waits.len(), t.wakes.len()))
}
}
#[cfg(test)]
mod tests {
use super::*;
fn entry(cycle: u64, source: &'static str) -> HandleAuditEntry {
HandleAuditEntry { cycle, tid: 1, lr: 0x8200_0000, source, aux: 0 }
}
#[test]
fn disabled_audit_is_a_noop() {
let mut a = HandleAudit::default();
a.record_create(0x1000, "Event/Auto", entry(0, "NtCreateEvent"));
a.record_signal(0x1000, entry(1, "NtSetEvent"));
assert!(a.trails.is_empty());
}
#[test]
fn enabled_records_create_and_events() {
let mut a = HandleAudit { enabled: true, ..HandleAudit::default() };
a.record_create(0x1014, "Event/Auto", entry(0, "NtCreateEvent"));
a.record_signal(0x1014, entry(10, "NtSetEvent"));
a.record_wait(0x1014, entry(5, "NtWaitForSingleObjectEx"));
a.record_wake(0x1014, entry(11, "wake_eligible_waiters"));
let counts = a.counts(0x1014).unwrap();
assert_eq!(counts, (1, 1, 1));
}
#[test]
fn signal_for_unknown_handle_is_dropped() {
let mut a = HandleAudit { enabled: true, ..HandleAudit::default() };
// No `record_create` first → handle has no trail. Without focus,
// the signal is silently dropped (legacy behavior).
a.record_signal(0x9999, entry(1, "NtSetEvent"));
assert!(a.trails.is_empty());
assert!(a.ghost_trails.is_empty());
}
#[test]
fn signal_for_focus_handle_lands_in_ghost_trail() {
let mut a = HandleAudit { enabled: true, ..HandleAudit::default() };
a.focus.insert(0x1004);
// No `record_create` for 0x1004 — but it's in the focus set.
a.record_signal(0x1004, entry(1, "NtSetEvent"));
a.record_signal(0x1004, entry(2, "KeSetEvent"));
// 0x9999 NOT in focus → still dropped.
a.record_signal(0x9999, entry(3, "NtSetEvent"));
assert!(a.trails.is_empty());
let ghost = a.ghost_trails.get(&0x1004).expect("ghost trail expected");
assert_eq!(ghost.signals.len(), 2);
assert!(!a.ghost_trails.contains_key(&0x9999));
}
#[test]
fn ghost_trail_does_not_double_record_when_primary_exists() {
let mut a = HandleAudit { enabled: true, ..HandleAudit::default() };
a.focus.insert(0x1004);
a.record_create(0x1004, "Event/Manual", entry(0, "NtCreateEvent"));
a.record_signal(0x1004, entry(1, "NtSetEvent"));
assert_eq!(a.trails[&0x1004].signals.len(), 1);
assert!(a.ghost_trails.is_empty());
}
#[test]
fn ring_is_bounded_to_capacity() {
let mut a = HandleAudit { enabled: true, ..HandleAudit::default() };
a.record_create(0x10FC, "Event/Auto", entry(0, "NtCreateEvent"));
for i in 0..(AUDIT_RING_CAPACITY * 3) as u64 {
a.record_signal(0x10FC, entry(i, "NtSetEvent"));
}
let trail = &a.trails[&0x10FC];
assert_eq!(trail.signals.len(), AUDIT_RING_CAPACITY);
// Oldest should have been dropped — the first remaining entry is at
// cycle = 2 * AUDIT_RING_CAPACITY (i.e. 64 if capacity = 32).
let first = trail.signals.front().unwrap();
assert_eq!(first.cycle, (AUDIT_RING_CAPACITY * 2) as u64);
}
#[test]
fn unknown_handle_counts_returns_none() {
let a = HandleAudit::default();
assert!(a.counts(0x10FC).is_none());
}
#[test]
fn create_with_stack_stores_frames() {
let mut a = HandleAudit { enabled: true, ..HandleAudit::default() };
let frames = vec![
(0x7000_0100, 0x824a_9f6c),
(0x7000_0200, 0x824a_b020),
(0x7000_0300, 0x82bb_aa00),
];
a.record_create_with_stack(
0x1004,
"Event/Manual",
entry(0, "NtCreateEvent"),
frames.clone(),
);
let trail = &a.trails[&0x1004];
assert_eq!(trail.created_stack, frames);
}
#[test]
fn create_with_stack_disabled_is_noop() {
let mut a = HandleAudit::default();
a.record_create_with_stack(
0x1004,
"Event/Manual",
entry(0, "NtCreateEvent"),
vec![(0x7000_0000, 0x8200_0000)],
);
assert!(a.trails.is_empty());
}
}