[Phase A] Expansive extraction tracing: call args, file.read, name-hash probe
Some checks failed
Orchestrator / Commit Message Validation (push) Has been skipped
Orchestrator / Lint (push) Failing after 1m36s
Orchestrator / Windows (x86-64) (push) Has been skipped
Orchestrator / Linux (x86-64) (push) Has been skipped
Orchestrator / Create Release (push) Has been skipped

Extend the cvar-gated JSONL event_log tracer to extract Project Sylpheed
data/behaviour (reimplementation pivot). All additive, default-off, no
behaviour change (golden rule):

- Tier 1 (--phase_a_trace_args): fill the previously-empty kernel.call
  args (raw r3..r10 from PPCContext) + args_resolved.path, routed through
  the existing export bridge (shim trampoline body-only).
- Tier 2 (file.read): resolve NtReadFile handle->path via the object
  table (LookupObject<XFile>), emit {handle,path,offset,length,buffer_va}
  so runtime reads correlate to IPFB TOC entries.
- Tier 3 (--phase_a_hash_probe=<pc,...>): mirror audit_61 — a hashprobe
  HIR trap band (base 300, max 32 PCs) in ppc_hir_builder.cc + native
  handler TrapPhaseAHashProbe in x64_emitter.cc that derefs r3 as a
  bounded guest C-string and XELOGIs PHASE-A-HASHPROBE (log-only; cpu
  backend must not reach kernel event_log). Recovers the custom IPFB
  name-hash from observed (string -> hash) pairs.

New files event_log.{cc,h}; cpu_flags + ppc_hir_builder + x64_emitter
are whole-file snapshots (also carry the earlier uncommitted audit_*
probe plumbing they share). Cross-build and other instrumentation remain
uncommitted.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
This commit is contained in:
MechaCat02
2026-07-09 21:11:58 +02:00
parent 6de80dffe2
commit a154309022
6 changed files with 1384 additions and 0 deletions

View File

@@ -13,6 +13,8 @@
#include <climits>
#include <cstring>
#include <string>
#include <vector>
#include "third_party/fmt/include/fmt/format.h"
#include "xenia/base/assert.h"
@@ -63,6 +65,111 @@ DEFINE_bool(instrument_call_times, false,
"Compute time taken for functions, for profiling guest code",
"x64");
#endif
// AUDIT-061/067: forward decls of probe/watch tables (defined in
// ppc_hir_builder.cc).
namespace xe {
namespace cpu {
namespace audit61 {
const std::vector<uint32_t>& pcs();
} // namespace audit61
namespace audit67 {
const std::vector<uint32_t>& vals();
} // namespace audit67
namespace hashprobe {
const std::vector<uint32_t>& pcs();
} // namespace hashprobe
} // namespace cpu
} // namespace xe
// AUDIT-061: handler for trap codes [200, 232). arg0 carries trap idx
// (trap_code - 200), mapping to ::xe::cpu::audit61::pcs()[idx]. Emits one
// log line per fire with cr0/cr6 LGE flags + key GPRs + LR + tid.
static uint64_t TrapAudit61Branch(void* raw_context, uint64_t idx) {
auto* ctx = reinterpret_cast<xe::cpu::ppc::PPCContext_s*>(raw_context);
const auto& pcs = ::xe::cpu::audit61::pcs();
uint32_t pc = (idx < pcs.size()) ? pcs[static_cast<size_t>(idx)] : 0u;
uint32_t tid = 0;
if (ctx->thread_state) {
tid = ctx->thread_state->thread_id();
}
auto enc = [](uint8_t lt, uint8_t gt, uint8_t eq) {
char buf[4];
buf[0] = lt ? 'L' : '.';
buf[1] = gt ? 'G' : '.';
buf[2] = eq ? 'E' : '.';
buf[3] = '\0';
return std::string(buf);
};
XELOGI(
"AUDIT-061-BR pc={:08X} lr={:08X} cr0={} cr6={} r3={:08X} r4={:08X} "
"r5={:08X} r6={:08X} r31={:08X} tid={}",
pc, static_cast<uint32_t>(ctx->lr),
enc(ctx->cr0.cr0_lt, ctx->cr0.cr0_gt, ctx->cr0.cr0_eq),
enc(ctx->cr6.cr6_all_equal, ctx->cr6.cr6_1, ctx->cr6.cr6_none_equal),
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[31]), tid);
return 0;
}
// AUDIT-067: handler for trap codes [250, 254). arg0 carries trap idx
// (trap_code - 250), mapping to ::xe::cpu::audit67::vals()[idx]. Fired when
// a 4-byte guest store sees the configured value. The store-emit site stashed
// (pc << 32) | (ea & 0xFFFFFFFF) into ctx->scratch right before the trap.
static uint64_t TrapAudit67ValueWatch(void* raw_context, uint64_t idx) {
auto* ctx = reinterpret_cast<xe::cpu::ppc::PPCContext_s*>(raw_context);
const auto& vals = ::xe::cpu::audit67::vals();
uint32_t val =
(idx < vals.size()) ? vals[static_cast<size_t>(idx)] : 0u;
uint32_t pc = static_cast<uint32_t>(ctx->scratch >> 32);
uint32_t dst = static_cast<uint32_t>(ctx->scratch & 0xFFFFFFFFu);
uint32_t tid = 0;
if (ctx->thread_state) {
tid = ctx->thread_state->thread_id();
}
XELOGI(
"AUDIT-067-VAL pc={:08X} lr={:08X} val={:08X} dst={:08X} "
"r3={:08X} r4={:08X} r5={:08X} r6={:08X} r31={:08X} tid={}",
pc, static_cast<uint32_t>(ctx->lr), val, dst,
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[31]), tid);
return 0;
}
// PHASE-A hash probe: trap codes [300, 332). arg0 carries trap idx
// (trap_code - 300) -> ::xe::cpu::hashprobe::pcs()[idx]. Derefs r3 as a guest
// C-string (the archive path being hashed) and logs it with r3..r6 + LR + tid.
// Log-only; observes the same code path the retail binary runs.
static uint64_t TrapPhaseAHashProbe(void* raw_context, uint64_t idx) {
auto* ctx = reinterpret_cast<xe::cpu::ppc::PPCContext_s*>(raw_context);
const auto& pcs = ::xe::cpu::hashprobe::pcs();
uint32_t pc = (idx < pcs.size()) ? pcs[static_cast<size_t>(idx)] : 0u;
uint32_t r3 = static_cast<uint32_t>(ctx->r[3]);
// Deref r3 as a guest C-string via the flat virtual mapping (bounded).
std::string arg;
if (r3 && ctx->virtual_membase) {
const char* p =
reinterpret_cast<const char*>(ctx->virtual_membase) + r3;
for (size_t i = 0; i < 128 && p[i]; ++i) {
char c = p[i];
arg.push_back((c >= 0x20 && c < 0x7f) ? c : '.');
}
}
uint32_t tid = 0;
if (ctx->thread_state) {
tid = ctx->thread_state->thread_id();
}
XELOGI(
"PHASE-A-HASHPROBE pc={:08X} lr={:08X} arg=\"{}\" r3={:08X} r4={:08X} "
"r5={:08X} r6={:08X} tid={}",
pc, static_cast<uint32_t>(ctx->lr), arg, r3,
static_cast<uint32_t>(ctx->r[4]), static_cast<uint32_t>(ctx->r[5]),
static_cast<uint32_t>(ctx->r[6]), tid);
return 0;
}
namespace xe {
namespace cpu {
namespace backend {
@@ -455,6 +562,27 @@ void X64Emitter::Trap(uint16_t trap_type) {
// ?
break;
default:
// AUDIT-067: trap codes [250, 254) dispatch the value-watch handler.
// arg0 = idx into ::xe::cpu::audit67::vals().
if (trap_type >= 250 && trap_type < 254) {
CallNative(::TrapAudit67ValueWatch,
static_cast<uint64_t>(trap_type - 250));
break;
}
// AUDIT-061: trap codes [200, 232) dispatch the branch-probe handler.
// arg0 = idx into ::xe::cpu::audit61::pcs().
if (trap_type >= 200 && trap_type < 232) {
CallNative(::TrapAudit61Branch,
static_cast<uint64_t>(trap_type - 200));
break;
}
// PHASE-A hash probe: trap codes [300, 332).
// arg0 = idx into ::xe::cpu::hashprobe::pcs().
if (trap_type >= 300 && trap_type < 332) {
CallNative(::TrapPhaseAHashProbe,
static_cast<uint64_t>(trap_type - 300));
break;
}
XELOGW("Unknown trap type {}", trap_type);
db(0xCC);
break;

View File

@@ -57,3 +57,124 @@ DEFINE_bool(break_condition_truncate, true, "truncate value to 32-bits", "CPU");
DEFINE_bool(break_on_debugbreak, true, "int3 on JITed __debugbreak requests.",
"CPU");
// AUDIT-DEMO: smoke marker (memory entry: emulator.cc:225,283). Always-on bool.
DEFINE_bool(audit_demo_setup_trace, true,
"Audit smoke marker: log AUDIT-DEMO-SETUP-BEGIN at emulator setup.",
"Audit");
// AUDIT-061: comma-separated list of guest PCs to log on each fire.
// Format: "0xPC1,0xPC2,..." (max 32 PCs). Each fire emits
// AUDIT-061-BR pc=X lr=X cr0=LGE cr6=LGE r3=X r4=X r5=X r6=X r31=X tid=N.
// Default empty (off); no perf cost when empty.
DEFINE_string(audit_61_branch_probe_pcs, "",
"AUDIT-061: CSV of guest PCs to trace (cr0/cr6 + regs/tid).",
"Audit");
// AUDIT-067: comma-separated list of u32 values to watch. When non-empty,
// every 4-byte guest store (stw/stwu/stwx/stwux/stmw) emits a runtime
// equality check; matches log AUDIT-067-VAL pc=X lr=X val=X dst=X r3..r6 r31 tid=N.
// Max 4 values. Default empty (off); zero overhead when empty.
DEFINE_string(audit_67_value_watch, "",
"AUDIT-067: CSV of u32 values (max 4) — log every guest "
"store whose value matches.",
"Audit");
// AUDIT-068: host-side memory-write watch. See cpu_flags.h header for format.
// Mirrors AUDIT-067 but covers host-side writes (xe::store_and_swap<T>,
// Memory::Zero/Fill/Copy). Empty default = zero cost.
DEFINE_string(audit_68_host_mem_watch_values, "",
"AUDIT-068: CSV of u32 values (max 8) — log every host-side "
"guest-memory write whose value matches.",
"Audit");
DEFINE_string(audit_68_host_mem_watch_addrs, "",
"AUDIT-068: CSV of guest VAs or VA ranges 'START-END' (max 8) "
"— log every host-side guest-memory write whose guest VA falls "
"within the configured set.",
"Audit");
// AUDIT-068 Session 3: read-mode probe. See cpu_flags.h for format.
DEFINE_string(audit_68_host_mem_read_probe, "",
"AUDIT-068 Session 3: CSV of 'VA:SIZE:PERIOD_NS' tuples (max 8) "
"— a dedicated poll thread reads the value at each VA every "
"PERIOD_NS and emits AUDIT-068-READ-CHANGE on transition.",
"Audit");
// AUDIT-069: see cpu_flags.h header. Empty default = zero cost.
DEFINE_string(audit_69_event_signal_watch, "",
"AUDIT-069: CSV of guest event-handle IDs (max 4) — log each "
"XEvent::Set / Ke*Event / Nt*Event fire whose target matches.",
"Audit");
DEFINE_string(audit_69_event_signal_native_ptr, "",
"AUDIT-069: CSV of guest event native VAs (X_KEVENT*) (max 4) "
"— log each set fire whose native pointer matches.",
"Audit");
DEFINE_bool(audit_69_log_all_sets, false,
"AUDIT-069: when true, log EVERY XEvent::Set/Pulse fire (used "
"for one-run wait→signal correlation across handle drift). "
"Default false; use only with --mute=true.",
"Audit");
// AUDIT-070 (S5 of AUDIT-069 family): semaphore-release watch. See header.
DEFINE_string(audit_70_semaphore_release_watch, "",
"AUDIT-070: CSV of guest semaphore handle IDs (max 4) — log "
"each NtReleaseSemaphore / xeKeReleaseSemaphore fire whose "
"target matches.",
"Audit");
DEFINE_bool(audit_70_log_all_releases, false,
"AUDIT-070: when true, log EVERY NtReleaseSemaphore / "
"xeKeReleaseSemaphore fire (used to identify the work-semaphore "
"handle on first run). Default false; use only with --mute=true.",
"Audit");
// Phase A — see kernel/event_log.h.
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");
// Phase A — expansive extraction tracing (game-data RE). All default-off so the
// diff-oriented schema-v1 output stays byte-identical when unused.
DEFINE_bool(phase_a_trace_args, false,
"Phase A extraction: populate the kernel.call args (raw r3..r10) and "
"args_resolved (file I/O path/offset/length/buffer, alloc size, "
"handle names) fields, and emit file.read events. Default false.",
"Audit");
DEFINE_string(phase_a_hash_probe, "",
"Phase A extraction: CSV of guest PCs (max 32). At each, deref r3 "
"as a guest C-string and emit a guest.call event {pc,arg_str,"
"r3..r6,tid} — used to recover the IPFB/IDXD name-hash. Default "
"empty (off).",
"Audit");
// Phase D Stage 1 — see kernel/event_log.h `EmitContentionObserved`.
DEFINE_bool(kernel_emit_contention, false,
"Phase D Stage 1: emit `contention.observed` events when "
"RtlEnterCriticalSection's spin loop is exhausted and the call "
"falls through to xeKeWaitForSingleObject. Default false (zero "
"cost when disabled). Requires --phase_a_event_log_path to be "
"set as well.",
"Audit");
// Phase B — see kernel/phase_b_snapshot.h.
DEFINE_string(phase_b_snapshot_dir, "",
"Phase B: write 5-file structured state snapshot to "
"<dir>/canary/ at the moment immediately before the first "
"guest PPC instruction of entry_point. Empty (default) = "
"disabled, zero overhead.",
"Audit");
DEFINE_bool(phase_b_snapshot_and_exit, false,
"Phase B: after writing the snapshot, exit the process "
"immediately (std::_Exit(0)) so re-runs are byte-deterministic.",
"Audit");
DEFINE_bool(phase_b_dump_section_content, false,
"Phase B: in memory.json, populate section_contents[].content_b64 "
"with raw bytes of every committed XEX-image region. Default "
"false — per-region SHA-256 is enough for the routine diff; "
"this is the escape hatch for the STOP-and-report condition "
"(image_loaded_sha256 mismatch).",
"Audit");

View File

@@ -35,4 +35,78 @@ DECLARE_bool(break_condition_truncate);
DECLARE_bool(break_on_debugbreak);
// AUDIT-DEMO smoke marker.
DECLARE_bool(audit_demo_setup_trace);
// AUDIT-061: multi-PC branch probe — emits one log line per fire with
// (pc, lr, cr0 LGE, cr6 LGE, r3, r4, r5, r6, r31, tid). CSV of guest PCs.
DECLARE_string(audit_61_branch_probe_pcs);
// AUDIT-067: value-watch — emit a log line for each 32-bit guest store whose
// value-to-be-stored matches any configured value. CSV of u32 values
// ("0xDEADBEEF,..."), max 4 entries. Default empty (off); zero cost when empty.
DECLARE_string(audit_67_value_watch);
// AUDIT-068: host-side memory-write watch — emit a log line for each host-side
// write to guest memory whose VALUE matches any configured u32 value, or whose
// guest VA falls within any configured ADDR or ADDR-range. Mirrors AUDIT-067
// but covers the host-side write paths (xe::store_and_swap<T>, Memory::Zero/
// Fill/Copy) that AUDIT-067's JIT store-opcode hooks cannot see.
//
// VALUES: CSV of u32 values, max 8 entries; e.g. "0x8200A208,0x8200A928".
// ADDRS: CSV of guest VAs or VA ranges, max 8 entries; range form is
// "0xSTART-0xEND" (inclusive). e.g. "0x42500000-0x42600000,0xBCE25340".
// Default empty (off); zero cost on the hot path when both are empty.
DECLARE_string(audit_68_host_mem_watch_values);
DECLARE_string(audit_68_host_mem_watch_addrs);
// AUDIT-068 Session 3: read-mode probe. CSV of "VA:SIZE:PERIOD_NS" tuples
// (max 8). A dedicated low-priority thread polls each VA every PERIOD_NS and
// emits AUDIT-068-READ-CHANGE when the value transitions. SIZE in {1,2,4,8}.
// Example: "0xBCE25340:4:1000000" = poll u32 at 0xBCE25340 every 1 ms.
// Default empty (off); the poll thread is not spawned when empty.
DECLARE_string(audit_68_host_mem_read_probe);
// AUDIT-069: event-signal watch. CSV of guest handle IDs (e.g. "0xF8000098")
// to log on every XEvent::Set / KeSetEvent / NtSetEvent / KePulseEvent /
// NtPulseEvent fire whose target matches. Max 4 entries. Default empty (off);
// zero cost on the hot path when empty.
DECLARE_string(audit_69_event_signal_watch);
// AUDIT-069: event-signal watch by native guest VA (X_KEVENT*). CSV of guest
// VAs (max 4). Default empty (off). Use when the handle id varies across
// boots but the native dispatcher pointer is stable.
DECLARE_string(audit_69_event_signal_native_ptr);
// AUDIT-069: when true, log EVERY XEvent::Set / XEvent::Pulse fire (subject
// to the slowpath gate). Use only with --mute=true and short windows — high
// volume. Default false (off).
DECLARE_bool(audit_69_log_all_sets);
// AUDIT-070 (S5 of AUDIT-069 family): semaphore-release watch. CSV of guest
// handle IDs (e.g. "0xF8000098") to log on every NtReleaseSemaphore /
// xeKeReleaseSemaphore fire whose target matches. Max 4 entries. Default
// empty (off); zero cost on the hot path when empty.
DECLARE_string(audit_70_semaphore_release_watch);
// AUDIT-070: when true, log EVERY NtReleaseSemaphore / xeKeReleaseSemaphore
// fire. Use only with --mute=true and short windows — used to identify the
// canary work-semaphore handle on first run. Default false (off).
DECLARE_bool(audit_70_log_all_releases);
// Phase A: JSONL event-log emitter path. When non-empty, the engine writes
// schema-v1 JSONL events to this file. Empty (default) = no overhead, no
// behavior change. Schema: xenia-rs/audit-runs/phase-a-diff-harness/schema-v1.md
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);
// Phase B: initial-state snapshot. When the dir cvar is non-empty, the
// engine writes a five-file structured state snapshot (cpu_state.json,
// memory.json, kernel.json, vfs.json, config.json, plus manifest.json) to
// `<dir>/canary/` at the moment immediately before the first guest PPC
// instruction of the XEX entry_point executes. See
// `xenia-rs/audit-runs/phase-b-state-equivalence/`.
DECLARE_string(phase_b_snapshot_dir);
DECLARE_bool(phase_b_snapshot_and_exit);
DECLARE_bool(phase_b_dump_section_content);
#endif // XENIA_CPU_CPU_FLAGS_H_

View File

@@ -34,6 +34,141 @@ DEFINE_bool(
"unimplemented PowerPC instruction is encountered.",
"CPU");
// AUDIT-061 — multi-PC branch probe. Parses cvars::audit_61_branch_probe_pcs
// once and exposes a (pc -> trap_id) lookup table. trap_id range [200, 65535].
// PCs outside the table are not probed. Native side reads g_audit61_pcs[idx].
#include <vector>
#include <string>
namespace xe {
namespace cpu {
namespace audit61 {
constexpr uint16_t kTrapBase = 200;
constexpr size_t kMaxPcs = 32;
static std::vector<uint32_t> g_pcs;
static bool g_parsed = false;
const std::vector<uint32_t>& pcs() {
if (!g_parsed) {
g_parsed = true;
const std::string& csv = cvars::audit_61_branch_probe_pcs;
size_t pos = 0;
while (pos < csv.size() && g_pcs.size() < kMaxPcs) {
size_t end = csv.find(',', pos);
std::string tok = csv.substr(pos, end - pos);
// strip whitespace
while (!tok.empty() && (tok.front() == ' ' || tok.front() == '\t'))
tok.erase(tok.begin());
while (!tok.empty() && (tok.back() == ' ' || tok.back() == '\t'))
tok.pop_back();
if (!tok.empty()) {
try {
uint32_t v = static_cast<uint32_t>(std::stoul(tok, nullptr, 0));
g_pcs.push_back(v);
} catch (...) {
}
}
if (end == std::string::npos) break;
pos = end + 1;
}
}
return g_pcs;
}
// Returns trap id for pc, or 0 if pc not in probe set.
uint16_t trap_id_for(uint32_t pc) {
const auto& v = pcs();
for (size_t i = 0; i < v.size(); ++i) {
if (v[i] == pc) return static_cast<uint16_t>(kTrapBase + i);
}
return 0;
}
} // namespace audit61
// AUDIT-067 — value-watch. Parses cvars::audit_67_value_watch once, exposes
// values via vals(). Trap codes for matches start at kTrapBase = 250.
namespace audit67 {
constexpr uint16_t kTrapBase = 250;
constexpr size_t kMaxVals = 4;
static std::vector<uint32_t> g_vals;
static bool g_parsed = false;
const std::vector<uint32_t>& vals() {
if (!g_parsed) {
g_parsed = true;
const std::string& csv = cvars::audit_67_value_watch;
size_t pos = 0;
while (pos < csv.size() && g_vals.size() < kMaxVals) {
size_t end = csv.find(',', pos);
std::string tok = csv.substr(pos, end - pos);
while (!tok.empty() && (tok.front() == ' ' || tok.front() == '\t'))
tok.erase(tok.begin());
while (!tok.empty() && (tok.back() == ' ' || tok.back() == '\t'))
tok.pop_back();
if (!tok.empty()) {
try {
uint32_t v = static_cast<uint32_t>(std::stoul(tok, nullptr, 0));
g_vals.push_back(v);
} catch (...) {
}
}
if (end == std::string::npos) break;
pos = end + 1;
}
XELOGI("AUDIT-067-INIT csv=\"{}\" parsed_count={}", csv, g_vals.size());
for (size_t i = 0; i < g_vals.size(); ++i) {
XELOGI("AUDIT-067-INIT vals[{}] = 0x{:08X}", i, g_vals[i]);
}
}
return g_vals;
}
} // namespace audit67
// PHASE-A hash probe — multi-PC guest probe for recovering the IPFB/IDXD
// name-hash. Parses cvars::phase_a_hash_probe once; trap ids start at 300.
// At each fire the native handler derefs r3 as a guest C-string (the archive
// path being hashed) and logs it alongside r3..r6. Mirrors audit61.
namespace hashprobe {
constexpr uint16_t kTrapBase = 300;
constexpr size_t kMaxPcs = 32;
static std::vector<uint32_t> g_pcs;
static bool g_parsed = false;
const std::vector<uint32_t>& pcs() {
if (!g_parsed) {
g_parsed = true;
const std::string& csv = cvars::phase_a_hash_probe;
size_t pos = 0;
while (pos < csv.size() && g_pcs.size() < kMaxPcs) {
size_t end = csv.find(',', pos);
std::string tok = csv.substr(pos, end - pos);
while (!tok.empty() && (tok.front() == ' ' || tok.front() == '\t'))
tok.erase(tok.begin());
while (!tok.empty() && (tok.back() == ' ' || tok.back() == '\t'))
tok.pop_back();
if (!tok.empty()) {
try {
g_pcs.push_back(static_cast<uint32_t>(std::stoul(tok, nullptr, 0)));
} catch (...) {
}
}
if (end == std::string::npos) break;
pos = end + 1;
}
}
return g_pcs;
}
uint16_t trap_id_for(uint32_t pc) {
const auto& v = pcs();
for (size_t i = 0; i < v.size(); ++i) {
if (v[i] == pc) return static_cast<uint16_t>(kTrapBase + i);
}
return 0;
}
} // namespace hashprobe
} // namespace cpu
} // namespace xe
namespace xe {
namespace cpu {
namespace ppc {
@@ -174,6 +309,32 @@ bool PPCHIRBuilder::Emit(GuestFunction* function, uint32_t flags) {
MaybeBreakOnInstruction(address);
// AUDIT-061: emit a trap before this instruction if it's on the probe
// list. The trap fires BEFORE the cmp/branch HIR emit so the native
// handler observes cr0/cr6 set by the *previous* instruction (the cmp
// that controls this conditional branch). ContextBarrier flushes
// HIR temporaries to PPCContext so the handler reads consistent state.
if (!::xe::cpu::audit61::pcs().empty()) {
uint16_t tid = ::xe::cpu::audit61::trap_id_for(address);
if (tid != 0) {
Comment("--audit_61_branch_probe target");
ContextBarrier();
Trap(tid);
}
}
// PHASE-A hash probe: trap before this instruction so the native handler
// observes r3 (arg string ptr) as set by the caller. ContextBarrier
// flushes HIR temporaries so the handler reads consistent GPRs.
if (!::xe::cpu::hashprobe::pcs().empty()) {
uint16_t tid = ::xe::cpu::hashprobe::trap_id_for(address);
if (tid != 0) {
Comment("--phase_a_hash_probe target");
ContextBarrier();
Trap(tid);
}
}
InstrData i;
i.address = address;
i.code = code;

View File

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

View File

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