diff --git a/kernel/src/Api/BuildNo.hpp b/kernel/src/Api/BuildNo.hpp index 694c0f8..8b446bd 100644 --- a/kernel/src/Api/BuildNo.hpp +++ b/kernel/src/Api/BuildNo.hpp @@ -12,4 +12,4 @@ #pragma once -#define MONTAUK_BUILD_NUMBER 22 +#define MONTAUK_BUILD_NUMBER 23 diff --git a/kernel/src/Drivers/USB/Bluetooth/Bluetooth.cpp b/kernel/src/Drivers/USB/Bluetooth/Bluetooth.cpp index 7b40193..28c6e14 100644 --- a/kernel/src/Drivers/USB/Bluetooth/Bluetooth.cpp +++ b/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; } diff --git a/kernel/src/Drivers/USB/Bluetooth/Hci.cpp b/kernel/src/Drivers/USB/Bluetooth/Hci.cpp index bef4301..41f20ea 100644 --- a/kernel/src/Drivers/USB/Bluetooth/Hci.cpp +++ b/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 g_fwTrace{false}; static std::atomic g_fwTraceCount{0}; static std::atomic 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 - // while the firmware phase runs, so a hardware boot log shows - // exactly what the event pipe delivered (or didn't). + // Bounded bring-up trace: one RING RECORD per interrupt-IN + // completion while the firmware phase runs; DumpFwTrace() prints + // 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) { - KernelLogStream(INFO, "BT-TRACE") << "int-in cc=" << (uint64_t)completionCode - << " len=" << length - << " b0=" << base::hex << (uint64_t)(data && length ? data[0] : 0xEE) - << " b3b4=" << (uint64_t)(data && length >= 5 - ? ((uint32_t)data[3] | ((uint32_t)data[4] << 8)) : 0xEEEE) - // ncmd = HCI command-flow-control window in a Command - // Complete; 0 here would explain a controller ignoring - // all subsequent commands. - << " ncmd=" << (uint64_t)(data && length >= 3 ? data[2] : 0xEE) - << base::dec << (g_eventReady ? " [mailbox-full]" : ""); + if (n < FW_TRACE_CAP) { + FwTraceRec& r = g_fwTraceRing[n]; + r.cc = (uint8_t)completionCode; + r.len = (uint8_t)(length > 255 ? 255 : length); + r.b0 = (data && length >= 1) ? data[0] : 0xEE; + r.ncmd = (data && length >= 3) ? data[2] : 0xEE; + r.b3b4 = (data && length >= 5) + ? (uint16_t)((uint16_t)data[3] | ((uint16_t)data[4] << 8)) : 0xEEEE; + r.overwrote = g_eventReady ? 1 : 0; } } @@ -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; } diff --git a/kernel/src/Drivers/USB/Bluetooth/Hci.hpp b/kernel/src/Drivers/USB/Bluetooth/Hci.hpp index b1c1f9d..51452b2 100644 --- a/kernel/src/Drivers/USB/Bluetooth/Hci.hpp +++ b/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 - // completion, capped) plus mailbox-overwrite flags. Enabled by the - // deferred bring-up so a failing hardware boot log shows exactly what the - // event pipe delivered. + // Toggle the bounded firmware-phase interrupt-IN trace (one ring record + // per completion, capped). Recording is IRQ-safe (lock-free ring, no + // logging); DumpFwTrace() prints pending records and MUST only be called + // 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