feat(hook): add SBC request tracing instrumentation

- sbc_hook.rs: trace SBC submission/response flow with request IDs
- sbc_request_trace.rs: capture request/response bodies for analysis
- sbc_trace.rs: runtime trace buffer with structured logging

Work in progress - needs validation against live FIFA 17 client

openfut-hook/src/sbc_request_trace.rs

@@ -55,6 +55,12 @@ static CONSUMER_88: AtomicUsize = AtomicUsize::new(0);
 static RESPONSE_VTABLE_88: AtomicUsize = AtomicUsize::new(0);
 static OWNER_SLOT_BEFORE_88: AtomicUsize = AtomicUsize::new(0);
 static OWNER_SLOT_AFTER_88: AtomicUsize = AtomicUsize::new(0);
+static OWNER_INNER_88: AtomicUsize = AtomicUsize::new(0);
+static OWNER_STATE_BEFORE_88: AtomicUsize = AtomicUsize::new(usize::MAX);
+static OWNER_STATE_AFTER_88: AtomicUsize = AtomicUsize::new(usize::MAX);
+static OWNER_FLAGS_88: AtomicUsize = AtomicUsize::new(usize::MAX);
+static OWNER_MANAGER_88: AtomicUsize = AtomicUsize::new(0);
+static OWNER_MANAGER_STATE_88: AtomicUsize = AtomicUsize::new(usize::MAX);
 
 fn enabled(value: Option<&str>) -> bool {
     matches!(value, Some("1"))
@@ -130,6 +136,22 @@ unsafe fn guarded_ptr(address: usize) -> usize {
     }
 }
 
+unsafe fn guarded_u32(address: usize) -> Option<u32> {
+    if readable_range(address, 4) {
+        Some(core::ptr::read_volatile(address as *const u32))
+    } else {
+        None
+    }
+}
+
+unsafe fn guarded_u8(address: usize) -> Option<u8> {
+    if readable_range(address, 1) {
+        Some(core::ptr::read_volatile(address as *const u8))
+    } else {
+        None
+    }
+}
+
 unsafe fn field_ptr(object: usize, offset: usize) -> usize {
     object
         .checked_add(offset)
@@ -149,14 +171,44 @@ unsafe extern "system" fn wrapper_88(request: *mut c_void, argument: *mut c_void
     let consumer = field_ptr(owner_vtable, 0x18);
     let owner_slot_before = guarded_ptr(argument_address);
     let response_vtable = guarded_ptr(owner_slot_before);
+    let owner_inner = field_ptr(owner, 8);
+    let owner_state_before = owner_inner
+        .checked_add(8)
+        .and_then(|p| guarded_u32(p))
+        .map(|v| v as usize)
+        .unwrap_or(usize::MAX);
+    let owner_flags = owner_inner
+        .checked_add(0x0c)
+        .and_then(|p| guarded_u8(p))
+        .map(|v| v as usize)
+        .unwrap_or(usize::MAX);
+    let owner_manager = field_ptr(owner_inner, 0x14d0);
+    let owner_manager_state = owner_manager
+        .checked_add(0x1dc0)
+        .and_then(|p| guarded_u32(p))
+        .map(|v| v as usize)
+        .unwrap_or(usize::MAX);
     OWNER_88.store(owner, Ordering::Relaxed);
     OWNER_VTABLE_88.store(owner_vtable, Ordering::Relaxed);
     CONSUMER_88.store(consumer, Ordering::Relaxed);
     RESPONSE_VTABLE_88.store(response_vtable, Ordering::Relaxed);
     OWNER_SLOT_BEFORE_88.store(owner_slot_before, Ordering::Relaxed);
+    OWNER_INNER_88.store(owner_inner, Ordering::Relaxed);
+    OWNER_STATE_BEFORE_88.store(owner_state_before, Ordering::Relaxed);
+    OWNER_FLAGS_88.store(owner_flags, Ordering::Relaxed);
+    OWNER_MANAGER_88.store(owner_manager, Ordering::Relaxed);
+    OWNER_MANAGER_STATE_88.store(owner_manager_state, Ordering::Relaxed);
     let original: Callback88 = core::mem::transmute(ORIGINAL_88.load(Ordering::Acquire));
     original(request, argument);
     OWNER_SLOT_AFTER_88.store(guarded_ptr(argument_address), Ordering::Relaxed);
+    OWNER_STATE_AFTER_88.store(
+        owner_inner
+            .checked_add(8)
+            .and_then(|p| guarded_u32(p))
+            .map(|v| v as usize)
+            .unwrap_or(usize::MAX),
+        Ordering::Relaxed,
+    );
     EXIT_88.fetch_add(1, Ordering::Release);
 }
 
@@ -334,7 +386,7 @@ unsafe fn worker() {
                 let count_90 = ENTER_90.load(Ordering::Acquire);
                 if count_88 != seen_88 || count_90 != seen_90 {
                     crate::write_log(&format!(
-                        "SBC_REQUEST_TRACE: +88 entry={} exit={} req={:#x} arg={:#x} tid={} owner={:#x} ovt={:#x} consumer={:#x} rvt={:#x} slot={:#x}->{:#x}; +90 entry={} exit={} req={:#x} arg={:#x} tid={} cb90={:#x} cb98={:#x} cba0={:#x} cba8={:#x} selected={:#x}\n",
+                        "SBC_REQUEST_TRACE: +88 entry={} exit={} req={:#x} arg={:#x} tid={} owner={:#x} ovt={:#x} consumer={:#x} rvt={:#x} slot={:#x}->{:#x} inner={:#x} state={}->{} flags={:#x} manager={:#x} manager_state={}; +90 entry={} exit={} req={:#x} arg={:#x} tid={} cb90={:#x} cb98={:#x} cba0={:#x} cba8={:#x} selected={:#x}\n",
                         count_88,
                         EXIT_88.load(Ordering::Acquire),
                         LAST_REQUEST_88.load(Ordering::Relaxed),
@@ -346,6 +398,12 @@ unsafe fn worker() {
                         RESPONSE_VTABLE_88.load(Ordering::Relaxed),
                         OWNER_SLOT_BEFORE_88.load(Ordering::Relaxed),
                         OWNER_SLOT_AFTER_88.load(Ordering::Relaxed),
+                        OWNER_INNER_88.load(Ordering::Relaxed),
+                        OWNER_STATE_BEFORE_88.load(Ordering::Relaxed),
+                        OWNER_STATE_AFTER_88.load(Ordering::Relaxed),
+                        OWNER_FLAGS_88.load(Ordering::Relaxed),
+                        OWNER_MANAGER_88.load(Ordering::Relaxed),
+                        OWNER_MANAGER_STATE_88.load(Ordering::Relaxed),
                         count_90,
                         EXIT_90.load(Ordering::Acquire),
                         LAST_REQUEST_90.load(Ordering::Relaxed),