From 17f4612b79baa656b5e83eaba7b47f353e631637 Mon Sep 17 00:00:00 2001 From: MechaCat02 Date: Mon, 8 Jun 2026 21:09:40 +0200 Subject: [PATCH] [Audit] round 24: signal-path probes (XEvent::Set + IO + NtDuplicateObject) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Adds AUDIT-HLC probes for every path that signals an XEvent or duplicates its handle, so the round-23 puzzle (waits completing without visible NtSetEvent/KeSetEvent) can be cross-referenced by underlying X_KEVENT VA and by primary handle. * NtCreateEvent_inner: always log kevent_va for handle/VA cross-ref * XEvent::Set: universal hook prints primary handle + kevent_va + LR; catches all paths into the event regardless of shim used * NtSetEvent: extended with PPC back-chain walk for caller's guest_lr (same idiom as the wait probe), so the signaler function is immediately identifiable * NtReadFile / NtReadFileScatter / NtWriteFile: log when signal_event path fires ev->Set() inline at IO completion (bypasses both NtSetEvent and KeSetEvent shims) * CompleteOverlappedEx (kernel_state.cc): log when overlapped event is signaled at completion * NtDuplicateObject: log src/dst handle pair (round-24 confirmed silph event is dup'd before signaling, explaining the handle-mismatch puzzle between NtSetEvent's `handle=` argument and XEvent::Set's primary handle()) Result: silph wait at sub_821CB030+0x1B0 on handle F80000A0 is signaled via NtSetEvent on handle F80000A8 (the duplicate created by sub_8245D9D8 at lr=0x82450DF4 inside the worker chain sub_82450A28 ← 0xA68 ← 0xB68). Verdict A confirmed: signaler exists and is reachable, but round-17.β missed it because the search keyed on the wrong handle. No bypass path; the worker chain is identical between canary and ours-impl, but ours signals different handles (work-item queue divergence at sub_82452DC0). Audit-only diagnostic. No semantic changes. Net delta +86 LOC across 7 files. All probes gated on the existing audit_handle_lifecycle cvar (default off). Tested via Sylpheed boot (35 s, 4 MB log). Audit-handle- lifecycle-probes branch, local-only. Co-Authored-By: Claude Opus 4.7 (1M context) --- src/xenia/kernel/kernel_flags.cc | 5 +++ src/xenia/kernel/kernel_flags.h | 1 + src/xenia/kernel/kernel_state.cc | 8 ++++ src/xenia/kernel/xboxkrnl/xboxkrnl_io.cc | 23 +++++++++++ src/xenia/kernel/xboxkrnl/xboxkrnl_ob.cc | 10 +++++ .../kernel/xboxkrnl/xboxkrnl_threading.cc | 40 ++++++++++++++++--- src/xenia/kernel/xevent.cc | 9 +++++ 7 files changed, 91 insertions(+), 5 deletions(-) diff --git a/src/xenia/kernel/kernel_flags.cc b/src/xenia/kernel/kernel_flags.cc index 78bde94ea..93a931573 100644 --- a/src/xenia/kernel/kernel_flags.cc +++ b/src/xenia/kernel/kernel_flags.cc @@ -18,3 +18,8 @@ DEFINE_bool(audit_handle_lifecycle, false, "Emit XELOGKERNEL on Event/Semaphore/Wait lifecycle " "(create/set/wait/complete). Audit oracle probe — off by default.", "Auditing"); +DEFINE_uint32(audit_track_event_handle, 0, + "If non-zero and AUDIT-HLC enabled, log underlying X_KEVENT " + "guest VA whenever NtCreateEvent returns this handle. " + "Audit round-24 oracle probe.", + "Auditing"); diff --git a/src/xenia/kernel/kernel_flags.h b/src/xenia/kernel/kernel_flags.h index 8614e8946..96ace6470 100644 --- a/src/xenia/kernel/kernel_flags.h +++ b/src/xenia/kernel/kernel_flags.h @@ -14,5 +14,6 @@ DECLARE_bool(headless); DECLARE_bool(log_high_frequency_kernel_calls); DECLARE_bool(audit_handle_lifecycle); +DECLARE_uint32(audit_track_event_handle); #endif // XENIA_KERNEL_KERNEL_FLAGS_H_ diff --git a/src/xenia/kernel/kernel_state.cc b/src/xenia/kernel/kernel_state.cc index d37e52bb3..10037e285 100644 --- a/src/xenia/kernel/kernel_state.cc +++ b/src/xenia/kernel/kernel_state.cc @@ -1071,6 +1071,14 @@ void KernelState::CompleteOverlappedEx(uint32_t overlapped_ptr, X_RESULT result, auto ev = object_table()->LookupObject(event_handle); assert_not_null(ev); if (ev) { + if (cvars::audit_handle_lifecycle) { + uint32_t lr = + static_cast(cpu::ThreadState::Get()->context()->lr); + XELOGKERNEL( + "AUDIT-HLC CompleteOverlappedEx_signal_event handle={:08X} " + "kevent_va={:08X} lr={:08X}", + uint32_t(event_handle), ev->guest_object(), lr); + } ev->Set(0, false); } } diff --git a/src/xenia/kernel/xboxkrnl/xboxkrnl_io.cc b/src/xenia/kernel/xboxkrnl/xboxkrnl_io.cc index bed943647..5e6b354ea 100644 --- a/src/xenia/kernel/xboxkrnl/xboxkrnl_io.cc +++ b/src/xenia/kernel/xboxkrnl/xboxkrnl_io.cc @@ -8,7 +8,9 @@ */ #include "xenia/base/logging.h" +#include "xenia/cpu/thread_state.h" #include "xenia/kernel/info/file.h" +#include "xenia/kernel/kernel_flags.h" #include "xenia/kernel/kernel_state.h" #include "xenia/kernel/util/shim_utils.h" #include "xenia/kernel/xboxkrnl/xboxkrnl_private.h" @@ -208,6 +210,13 @@ dword_result_t NtReadFile_entry(dword_t file_handle, dword_t event_handle, } if (ev && signal_event) { + if (cvars::audit_handle_lifecycle) { + uint32_t lr = static_cast(cpu::ThreadState::Get()->context()->lr); + XELOGKERNEL( + "AUDIT-HLC NtReadFile_signal_event handle={:08X} kevent_va={:08X} " + "lr={:08X}", + uint32_t(event_handle), ev->guest_object(), lr); + } ev->Set(0, false); } @@ -294,6 +303,13 @@ dword_result_t NtReadFileScatter_entry( } if (ev && signal_event) { + if (cvars::audit_handle_lifecycle) { + uint32_t lr = static_cast(cpu::ThreadState::Get()->context()->lr); + XELOGKERNEL( + "AUDIT-HLC NtReadFileScatter_signal_event handle={:08X} " + "kevent_va={:08X} lr={:08X}", + uint32_t(event_handle), ev->guest_object(), lr); + } ev->Set(0, false); } @@ -381,6 +397,13 @@ dword_result_t NtWriteFile_entry(dword_t file_handle, dword_t event_handle, } if (ev && signal_event) { + if (cvars::audit_handle_lifecycle) { + uint32_t lr = static_cast(cpu::ThreadState::Get()->context()->lr); + XELOGKERNEL( + "AUDIT-HLC NtWriteFile_signal_event handle={:08X} kevent_va={:08X} " + "lr={:08X}", + uint32_t(event_handle), ev->guest_object(), lr); + } ev->Set(0, false); } diff --git a/src/xenia/kernel/xboxkrnl/xboxkrnl_ob.cc b/src/xenia/kernel/xboxkrnl/xboxkrnl_ob.cc index 02e77631b..1c9c7ad83 100644 --- a/src/xenia/kernel/xboxkrnl/xboxkrnl_ob.cc +++ b/src/xenia/kernel/xboxkrnl/xboxkrnl_ob.cc @@ -10,6 +10,8 @@ #include "xenia/kernel/xboxkrnl/xboxkrnl_ob.h" #include "xenia/base/logging.h" #include "xenia/cpu/processor.h" +#include "xenia/cpu/thread_state.h" +#include "xenia/kernel/kernel_flags.h" #include "xenia/kernel/kernel_state.h" #include "xenia/kernel/xboxkrnl/xboxkrnl_private.h" #include "xenia/kernel/xboxkrnl/xboxkrnl_threading.h" @@ -398,6 +400,14 @@ dword_result_t NtDuplicateObject_entry(dword_t handle, lpdword_t new_handle_ptr, X_STATUS result = kernel_state()->object_table()->DuplicateHandle(handle, &new_handle); + if (cvars::audit_handle_lifecycle) { + uint32_t lr = static_cast(cpu::ThreadState::Get()->context()->lr); + XELOGKERNEL( + "AUDIT-HLC NtDuplicateObject src={:08X} dst={:08X} options={:08X} " + "lr={:08X}", + uint32_t(handle), uint32_t(new_handle), uint32_t(options), lr); + } + if (new_handle_ptr) { *new_handle_ptr = new_handle; } diff --git a/src/xenia/kernel/xboxkrnl/xboxkrnl_threading.cc b/src/xenia/kernel/xboxkrnl/xboxkrnl_threading.cc index 7df32bfbe..9eadc2571 100644 --- a/src/xenia/kernel/xboxkrnl/xboxkrnl_threading.cc +++ b/src/xenia/kernel/xboxkrnl/xboxkrnl_threading.cc @@ -677,11 +677,26 @@ dword_result_t NtCreateEvent_entry( } if (cvars::audit_handle_lifecycle) { uint32_t lr = static_cast(cpu::ThreadState::Get()->context()->lr); + uint32_t out_handle = handle_ptr ? uint32_t(*handle_ptr) : 0u; XELOGKERNEL( "AUDIT-HLC NtCreateEvent handle={:08X} type={} initial_state={} " "lr={:08X}", - handle_ptr ? uint32_t(*handle_ptr) : 0u, uint32_t(event_type), - uint32_t(initial_state), lr); + out_handle, uint32_t(event_type), uint32_t(initial_state), lr); + // Round-24: also log the underlying X_KEVENT guest VA for every + // NtCreateEvent so KeSetEvent probes can be cross-referenced by ptr. + XELOGKERNEL( + "AUDIT-HLC NtCreateEvent_inner handle={:08X} kevent_va={:08X} " + "lr={:08X}", + out_handle, ev->guest_object(), lr); + // When caller pinned a target handle, additionally emit the legacy + // _target line so older round-24 grep recipes still match. + if (cvars::audit_track_event_handle != 0 && + out_handle == cvars::audit_track_event_handle) { + XELOGKERNEL( + "AUDIT-HLC NtCreateEvent_target handle={:08X} object_va={:08X} " + "lr={:08X}", + out_handle, ev->guest_object(), lr); + } } return X_STATUS_SUCCESS; } @@ -709,9 +724,24 @@ uint32_t xeNtSetEvent(uint32_t handle, xe::be* previous_state_ptr) { dword_result_t NtSetEvent_entry(dword_t handle, lpdword_t previous_state_ptr) { if (cvars::audit_handle_lifecycle) { - uint32_t lr = static_cast(cpu::ThreadState::Get()->context()->lr); - XELOGKERNEL("AUDIT-HLC NtSetEvent handle={:08X} lr={:08X}", - uint32_t(handle), lr); + auto* ctx = cpu::ThreadState::Get()->context(); + uint32_t lr = static_cast(ctx->lr); + // Round-24: walk PPC back-chain for caller's guest LR (same idiom as + // NtWaitForSingleObjectEx probe). + uint32_t guest_lr = 0; + uint32_t sp = static_cast(ctx->r[1]); + uint32_t back1 = xe::load_and_swap(ctx->TranslateVirtual(sp)); + if (back1) { + uint32_t back2 = + xe::load_and_swap(ctx->TranslateVirtual(back1)); + if (back2) { + guest_lr = xe::load_and_swap( + ctx->TranslateVirtual(back2 - 8)); + } + } + XELOGKERNEL( + "AUDIT-HLC NtSetEvent handle={:08X} lr={:08X} guest_lr={:08X}", + uint32_t(handle), lr, guest_lr); } return xeNtSetEvent(handle, previous_state_ptr); } diff --git a/src/xenia/kernel/xevent.cc b/src/xenia/kernel/xevent.cc index b583bf732..03b57bffd 100644 --- a/src/xenia/kernel/xevent.cc +++ b/src/xenia/kernel/xevent.cc @@ -11,6 +11,8 @@ #include "xenia/base/byte_stream.h" #include "xenia/base/logging.h" +#include "xenia/cpu/thread_state.h" +#include "xenia/kernel/kernel_flags.h" namespace xe { namespace kernel { @@ -58,6 +60,13 @@ void XEvent::InitializeNative(void* native_ptr, X_DISPATCH_HEADER* header) { } int32_t XEvent::Set(uint32_t priority_increment, bool wait) { + if (cvars::audit_handle_lifecycle) { + auto* ts = cpu::ThreadState::Get(); + uint32_t lr = ts ? static_cast(ts->context()->lr) : 0u; + XELOGKERNEL( + "AUDIT-HLC XEvent::Set handle={:08X} kevent_va={:08X} prio={} lr={:08X}", + handle(), guest_object(), priority_increment, lr); + } set_priority_increment(priority_increment); event_->Set(); return 1;