wip: BT firmware debugging

kernel/src/Api/BuildNo.hpp

@@ -12,4 +12,4 @@
 
 #pragma once
 
-#define MONTAUK_BUILD_NUMBER 22
+#define MONTAUK_BUILD_NUMBER 23

kernel/src/Drivers/USB/Bluetooth/Bluetooth.cpp

@@ -395,6 +395,7 @@ namespace Drivers::USB::Bluetooth {
         if (cpu) cpu->reservedForKernelWork = true;
         Hci::SetFwTrace(true);    // bounded per-completion event-pipe trace
         CompleteInit();
+        Hci::DumpFwTrace();       // flush remaining records (process context)
         Hci::SetFwTrace(false);
         if (cpu) cpu->reservedForKernelWork = false;
     }

kernel/src/Drivers/USB/Bluetooth/Hci.cpp

@@ -38,13 +38,50 @@ namespace Drivers::USB::Bluetooth::Hci {
     // trace of the interrupt IN pipe (SetFwTrace, driven by the bring-up);
     // g_intInCompletions counts interrupt-IN completions since power-up so
     // wait-loop timeouts can report whether the pipe was delivering at all.
+    //
+    // The trace is recorded into a lock-free ring and printed LATER by
+    // DumpFwTrace() from process context.  It must NEVER KernelLogStream from
+    // TransferCallback: that runs nested under PollEvents in xHCI MSI (IRQ)
+    // context, and the terminal lock is a non-IRQ-disabling Mutex -- an IRQ
+    // logger interrupting a same-core holder spins forever (observed: hard
+    // boot freeze right after "Intel version raw", 2026-07-06).
     static std::atomic<bool> g_fwTrace{false};
     static std::atomic<uint32_t> g_fwTraceCount{0};
     static std::atomic<uint32_t> g_intInCompletions{0};
 
+    struct FwTraceRec {
+        uint8_t  cc;        // xHCI completion code
+        uint8_t  len;       // bytes delivered (0 = error/ZLP completion)
+        uint8_t  b0;        // first event byte (0xEE = no data)
+        uint8_t  ncmd;      // byte 2 (HCI flow-control window in a CC)
+        uint16_t b3b4;      // bytes 3..4 (opcode in a Command Complete)
+        uint8_t  overwrote; // mailbox still held an unconsumed event
+    };
+    static constexpr uint32_t FW_TRACE_CAP = 48;
+    static FwTraceRec g_fwTraceRing[FW_TRACE_CAP] = {};
+    static uint32_t g_fwTraceDumped = 0;   // process-context cursor
+
     void SetFwTrace(bool on) {
         g_fwTrace.store(on, std::memory_order_relaxed);
-        if (on) g_fwTraceCount.store(0, std::memory_order_relaxed);
+        if (on) {
+            g_fwTraceCount.store(0, std::memory_order_relaxed);
+            g_fwTraceDumped = 0;
+        }
+    }
+
+    // Print any not-yet-printed trace records.  Process context ONLY.
+    void DumpFwTrace() {
+        uint32_t n = g_fwTraceCount.load(std::memory_order_acquire);
+        if (n > FW_TRACE_CAP) n = FW_TRACE_CAP;
+        for (; g_fwTraceDumped < n; g_fwTraceDumped++) {
+            const FwTraceRec& r = g_fwTraceRing[g_fwTraceDumped];
+            KernelLogStream(INFO, "BT-TRACE") << "int-in cc=" << (uint64_t)r.cc
+                << " len=" << (uint64_t)r.len
+                << " b0=" << base::hex << (uint64_t)r.b0
+                << " b3b4=" << (uint64_t)r.b3b4
+                << " ncmd=" << (uint64_t)r.ncmd << base::dec
+                << (r.overwrote ? " [mailbox-full]" : "");
+        }
     }
 
     // ACL receive ring buffer.  The bulk-IN callback (nested under PollEvents)
@@ -292,22 +329,21 @@ namespace Drivers::USB::Bluetooth::Hci {
         if (epDci == intDci) {
             g_intInCompletions.fetch_add(1, std::memory_order_relaxed);
 
-            // Bounded bring-up trace: one line per interrupt-IN completion
+            // Bounded bring-up trace: one RING RECORD per interrupt-IN
-            // while the firmware phase runs, so a hardware boot log shows
+            // completion while the firmware phase runs; DumpFwTrace() prints
-            // exactly what the event pipe delivered (or didn't).
+            // them later from process context.  No logging here -- this runs
+            // in xHCI MSI (IRQ) context (see the deadlock note at the ring).
             if (g_fwTrace.load(std::memory_order_relaxed)) {
                 uint32_t n = g_fwTraceCount.fetch_add(1, std::memory_order_relaxed);
-                if (n < 48) {
+                if (n < FW_TRACE_CAP) {
-                    KernelLogStream(INFO, "BT-TRACE") << "int-in cc=" << (uint64_t)completionCode
+                    FwTraceRec& r = g_fwTraceRing[n];
-                        << " len=" << length
+                    r.cc   = (uint8_t)completionCode;
-                        << " b0=" << base::hex << (uint64_t)(data && length ? data[0] : 0xEE)
+                    r.len  = (uint8_t)(length > 255 ? 255 : length);
-                        << " b3b4=" << (uint64_t)(data && length >= 5
+                    r.b0   = (data && length >= 1) ? data[0] : 0xEE;
-                            ? ((uint32_t)data[3] | ((uint32_t)data[4] << 8)) : 0xEEEE)
+                    r.ncmd = (data && length >= 3) ? data[2] : 0xEE;
-                        // ncmd = HCI command-flow-control window in a Command
+                    r.b3b4 = (data && length >= 5)
-                        // Complete; 0 here would explain a controller ignoring
+                        ? (uint16_t)((uint16_t)data[3] | ((uint16_t)data[4] << 8)) : 0xEEEE;
-                        // all subsequent commands.
+                    r.overwrote = g_eventReady ? 1 : 0;
-                        << " ncmd=" << (uint64_t)(data && length >= 3 ? data[2] : 0xEE)
-                        << base::dec << (g_eventReady ? " [mailbox-full]" : "");
                 }
             }
 
@@ -1120,6 +1156,7 @@ namespace Drivers::USB::Bluetooth::Hci {
         KernelLogStream(WARNING, "BT-HCI") << "ReadIntelVersionTlv timeout ("
             << (uint64_t)(g_intInCompletions.load(std::memory_order_relaxed) - completionsBefore)
             << " int-in completions during wait)";
+        DumpFwTrace();
       }
         return -1;
     }

kernel/src/Drivers/USB/Bluetooth/Hci.hpp

@@ -265,11 +265,12 @@ namespace Drivers::USB::Bluetooth::Hci {
     // Returns true if a matching bond was found and forgotten.
     bool ForgetBond(const uint8_t* addr);
 
-    // Toggle the bounded firmware-phase interrupt-IN trace (one log line per
+    // Toggle the bounded firmware-phase interrupt-IN trace (one ring record
-    // completion, capped) plus mailbox-overwrite flags.  Enabled by the
+    // per completion, capped).  Recording is IRQ-safe (lock-free ring, no
-    // deferred bring-up so a failing hardware boot log shows exactly what the
+    // logging); DumpFwTrace() prints pending records and MUST only be called
-    // event pipe delivered.
+    // from process context (terminal lock is a non-IRQ-safe Mutex).
     void SetFwTrace(bool on);
+    void DumpFwTrace();
 
     // Non-blocking peek at the most recent 0xFF/0x06 secure-send result without
     // consuming it.  Returns true if one has arrived since the last