[Audit] round 24: signal-path probes (XEvent::Set + IO + NtDuplicateObject)

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) <noreply@anthropic.com>

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");

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_

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<XEvent>(event_handle);
     assert_not_null(ev);
     if (ev) {
+      if (cvars::audit_handle_lifecycle) {
+        uint32_t lr =
+            static_cast<uint32_t>(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);
     }
   }

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<uint32_t>(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<uint32_t>(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<uint32_t>(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);
   }
 

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<uint32_t>(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;
   }

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<uint32_t>(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<uint32_t>* 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<uint32_t>(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<uint32_t>(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<uint32_t>(ctx->r[1]);
+    uint32_t back1 = xe::load_and_swap<uint32_t>(ctx->TranslateVirtual(sp));
+    if (back1) {
+      uint32_t back2 =
+          xe::load_and_swap<uint32_t>(ctx->TranslateVirtual(back1));
+      if (back2) {
+        guest_lr = xe::load_and_swap<uint32_t>(
+            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);
 }

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<uint32_t>(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;