fault_diag.cpp 32 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757758759760761762763764765766767768769770771772773774775776777778779780781782783784785786787788789790791792793794795796797798799800801802803804805806807808809810811812813814815816817818819820821822823824825826827828829830831832833834835836837838839840
  1. #include "fault_diag.h"
  2. #include <Arduino.h> // readResetReason(), NRF_POWER, NVIC_SystemReset, POWER_RESETREAS_*_Msk
  3. #include <FreeRTOS.h>
  4. #include <task.h> // uxTaskGetSystemState -> per-task stack high-water (overflow hypothesis check)
  5. #include <string.h>
  6. #include "rf_link.h" // g_pollsps/g_relayps/g_crcps/g_norxps/g_rfStallRecover -- flight-recorder vitals
  7. #include "haptics.h" // g_ringFault, relayPending() -- relay-load vitals
  8. // GPREGRET2 markers. GPREGRET (id 0) is reserved by the Adafruit bootloader for the DFU magic; GPREGRET2 is
  9. // free for the application and is retained across soft/watchdog/pin reset, cleared only on power-on/brownout.
  10. // Arbitrary non-zero tags -- any value distinct from each other and from the power-on default (0) works.
  11. #define G2_INTENT 0xB1u
  12. #define G2_FAULT 0xFAu
  13. static uint8_t g_reason = RR_UNKNOWN;
  14. static uint32_t g_resetReas = 0;
  15. static uint8_t g_hangStage = 0xFF;
  16. // ---- watchdog pre-reset PC capture ("software SWD") --------------------------------------------------------
  17. // The nRF52 WDT raises a TIMEOUT interrupt ~2 LFCLK cycles BEFORE it resets the chip. We take that interrupt at
  18. // the highest NVIC priority (0) -- above FreeRTOS/TinyUSB BASEPRI critical sections -- read the stacked PC of
  19. // whatever code was wedged, and stash it in a .noinit RAM struct that survives the reset. Next boot reports it
  20. // on the panel; map it with addr2line to name the stuck function. Caveat: this fires only if interrupts aren't
  21. // hard-masked (PRIMASK/CPSID). If a watchdog reset reports NO pc, the hang was a PRIMASK-off / flash-stall type
  22. // (a different, narrower class) -- itself a useful signal. .noinit isn't zeroed by the C runtime, so it rides
  23. // through the watchdog reset (unlike GPREGRET2, which this board's bootloader wipes).
  24. struct HangFrame {
  25. uint32_t pc, lr, magic;
  26. };
  27. #define HANGPC_MAGIC 0x48414E47u // "HANG"
  28. __attribute__((section(".noinit"))) volatile struct HangFrame g_hangFrame;
  29. static uint32_t g_reportHangPC = 0, g_reportHangLR = 0;
  30. __attribute__((naked)) void WDT_IRQHandler(void)
  31. {
  32. __asm volatile(
  33. "tst lr, #4 \n" // EXC_RETURN bit2: 0=frame on MSP, 1=on PSP
  34. "ite eq \n"
  35. "mrseq r0, msp \n"
  36. "mrsne r0, psp \n"
  37. "ldr r1, [r0, #24] \n" // stacked PC (frame[6])
  38. "ldr r3, [r0, #20] \n" // stacked LR (frame[5])
  39. "ldr r2, =g_hangFrame \n"
  40. "str r1, [r2, #0] \n"
  41. "str r3, [r2, #4] \n"
  42. "ldr r1, =0x48414E47 \n"
  43. "str r1, [r2, #8] \n"
  44. "b . \n" // hold until the WDT reset lands (microseconds away)
  45. ".ltorg \n");
  46. }
  47. // Enable the WDT TIMEOUT interrupt at top priority. Call once, right after NRF_WDT->TASKS_START in setup().
  48. void faultDiagArmHangCapture()
  49. {
  50. NRF_WDT->INTENSET = WDT_INTENSET_TIMEOUT_Msk;
  51. NVIC_SetPriority(
  52. WDT_IRQn,
  53. 0); // above FreeRTOS configMAX_SYSCALL priority -> fires through BASEPRI guards
  54. NVIC_ClearPendingIRQ(WDT_IRQn);
  55. NVIC_EnableIRQ(WDT_IRQn);
  56. }
  57. uint32_t faultDiagHangPC()
  58. {
  59. return g_reportHangPC;
  60. }
  61. uint32_t faultDiagHangLR()
  62. {
  63. return g_reportHangLR;
  64. }
  65. // Hang breadcrumb: loop() stage written to GPREGRET2 as 0x80|stage. 0x80..0x9F can never collide with the
  66. // intentional-reboot (0xB1) / HardFault (0xFA) markers or the power-on default (0), so the same register
  67. // disambiguates all of them at boot.
  68. #define G2_STAGE_FLAG 0x80u
  69. static const char *const STAGE_STR[] = { "webusb", "ctrl.task", "serial",
  70. "rfdiag", "rflink", "haptic",
  71. "led", "usbmount", "usbtx" };
  72. #define STAGE_COUNT ((uint8_t)(sizeof STAGE_STR / sizeof STAGE_STR[0]))
  73. static const char *const REASON_STR[RR_COUNT] = {
  74. "unknown", "power-on", "pin/replug", "WATCHDOG (hang)", "CPU lockup",
  75. "HARDFAULT", "reboot", "soft reset", "wake-from-off",
  76. };
  77. // HardFault override. The Adafruit core's default handler (cores/.../debug.cpp) already does NVIC_SystemReset();
  78. // we replace it to first stamp the fault marker so the NEXT boot classifies this SREQ as RR_HARDFAULT rather
  79. // than an intentional reboot. The core's strong symbol is only linked to satisfy the vector table, so our own
  80. // strong definition takes its place. Keep this MINIMAL: we are in fault context on a possibly-corrupt stack --
  81. // no Serial, no allocations, just stamp and reset.
  82. extern "C" void HardFault_Handler(void)
  83. {
  84. NRF_POWER->GPREGRET2 = G2_FAULT;
  85. NVIC_SystemReset();
  86. while (1) {
  87. }
  88. }
  89. void faultDiagArmIntentionalReset()
  90. {
  91. NRF_POWER->GPREGRET2 = G2_INTENT;
  92. }
  93. // Live stage + loop heartbeat. The post-reset GPREGRET2 breadcrumb only works if the bootloader preserves
  94. // GPREGRET2 across a watchdog reset -- some clone boards clear it, so it reads blank. These LIVE values don't
  95. // depend on surviving a reset: the WebUSB blob send runs on the USB SOF interrupt (independent of loop()), so
  96. // when loop() wedges, the SOF drain can still report the current stage + how long loop() has been stuck,
  97. // straight to the panel during the ~8s before the watchdog fires.
  98. static volatile uint8_t g_curStage = 0xFF;
  99. static volatile uint32_t g_loopBeatMs = 0;
  100. void faultDiagSetStage(uint8_t stage)
  101. {
  102. g_curStage = stage;
  103. NRF_POWER->GPREGRET2 = (uint8_t)(G2_STAGE_FLAG | (stage & 0x1Fu));
  104. }
  105. void faultDiagBeat()
  106. {
  107. g_loopBeatMs = millis();
  108. }
  109. uint8_t faultDiagCurStage()
  110. {
  111. return g_curStage;
  112. }
  113. uint32_t faultDiagStallMs()
  114. {
  115. // ms since loop() last beat. ~0 when healthy (loop beats ~250x/s); grows while loop() is stuck.
  116. return (uint32_t)(millis() - g_loopBeatMs);
  117. }
  118. const char *faultDiagStageStr(uint8_t s)
  119. {
  120. return s < STAGE_COUNT ? STAGE_STR[s] : "?";
  121. }
  122. uint8_t faultDiagHangStage()
  123. {
  124. return g_hangStage;
  125. }
  126. const char *faultDiagHangStageStr()
  127. {
  128. return g_hangStage < STAGE_COUNT ? STAGE_STR[g_hangStage] : "n/a";
  129. }
  130. // ---- flight recorder (data) --------------------------------------------------------------------------------
  131. // The live ring lives in .noinit so it survives a watchdog reset (like g_hangFrame). At boot we copy the
  132. // pre-reset trail into g_flightSaved (ordinary RAM -- no need to survive twice) so the live session can start a
  133. // fresh ring while the console can still re-dump the old trail on demand. Declared here (above faultDiagBoot)
  134. // because the boot classifier snapshots + dumps it; the push/tick/dump functions are implemented further down.
  135. struct FRRec {
  136. uint32_t ms; // millis() at the push
  137. uint16_t arg; // event-specific
  138. uint8_t evt; // FR_*
  139. uint8_t stage; // loop stage current at the push (g_curStage)
  140. };
  141. #define FR_RING 96u
  142. #define FR_MAGIC 0x464C4954u // "FLIT"
  143. struct FlightRec {
  144. uint32_t magic;
  145. uint16_t head; // next write slot
  146. uint16_t count; // total pushed this session (saturating) -> "showing last N of M"
  147. FRRec ring[FR_RING];
  148. // live vitals, refreshed ~4x/s -- the last values captured before a wedge
  149. uint32_t vMs; // millis() at last refresh
  150. uint32_t loopPerSec; // loop() iterations in the last full second
  151. uint32_t heapUsed; // mallinfo().uordblks (bytes) -- trend up = leak/fragmentation
  152. uint16_t usbdStackFree, loopStackFree; // words (0 = overflowed)
  153. uint16_t pollsps, relayps, crcps, norxps;
  154. uint16_t rfHeal, ringFault;
  155. uint8_t curStage;
  156. uint8_t stallMs; // ms since last loop beat, capped 255
  157. };
  158. __attribute__((section(".noinit"))) static volatile struct FlightRec g_flight;
  159. static struct FlightRec
  160. g_flightSaved; // boot-time copy of the pre-reset trail (BSS)
  161. static bool g_haveSaved = false;
  162. bool g_vitals = true; // live per-second CDC vitals line (console "VIT" toggles)
  163. static const char *const FR_STR[] = { "none", "beat", "SET", "GET",
  164. "relay", "rf-up", "rf-DN", "HEAL!",
  165. "mount", "SUSPEND", "resume", "OFF",
  166. "RINGF", "save" };
  167. #define FR_STR_COUNT ((uint8_t)(sizeof FR_STR / sizeof FR_STR[0]))
  168. static const char *frEvtStr(uint8_t e)
  169. {
  170. return e < FR_STR_COUNT ? FR_STR[e] : "?";
  171. }
  172. // ---- flash black box (pre-watchdog dump) -------------------------------------------------------------------
  173. // On boards whose bootloader wipes .noinit + GPREGRET2 across a watchdog reset (Teyleten-class), EVERY
  174. // post-mortem channel above is destroyed -- hangs on those boards were unforensicable. Flash survives any
  175. // reset, so: a 4 Hz TIMER4 interrupt (priority 1, above FreeRTOS BASEPRI masking, below the WDT capture's 0)
  176. // watches the loop heartbeat; when loop() has been frozen ~6 s (the WDT resets at 8 s), it walks the loop and
  177. // usbd tasks' TCBs for their stacked PCs (both tasks BLOCKED = the suspected mutual-deadlock class) plus the
  178. // PC it interrupted (covers the one-task-spinning class), and writes one record to a reserved raw flash page.
  179. // Next boot reports it on CDC and feeds the existing hangPC/hangStage panel channels. Caveats: fires only if
  180. // priority-1 interrupts still run (PRIMASK-off hangs leave no record -- same caveat as the WDT capture, and
  181. // itself a signal); a task that is RUNNING (not blocked) has a stale TCB pxTopOfStack, so cross-check its PC
  182. // against irqPC.
  183. #define BB_ADDR \
  184. 0xE8000UL // raw page: app image (~170 KB, ends < 0x60000) < here < InternalFS (0xED000)
  185. #define BB_MAGIC 0x62627831u // "bbx1"
  186. #define BB_WORDS 12
  187. static TaskHandle_t g_hLoop,
  188. g_hUsbd; // captured by faultDiagStackTick's 1 Hz sweep
  189. // non-static (like g_hangFrame): the naked ISR's `ldr =symbol` needs external linkage to resolve
  190. extern "C" {
  191. volatile uint32_t g_bbIrqPC,
  192. g_bbIrqLR; // stacked frame of whatever TIMER4 preempted
  193. }
  194. static void bbBootReport(
  195. bool isHang); // defined below faultDiagBlackBoxArm; called from faultDiagBoot
  196. static void bbErase(void); // dump-time lazy erase (see bbTimerBody)
  197. static void bbFlashWord(uint32_t addr, uint32_t v)
  198. {
  199. NRF_NVMC->CONFIG = NVMC_CONFIG_WEN_Wen << NVMC_CONFIG_WEN_Pos;
  200. __DMB();
  201. *(volatile uint32_t *)addr = v;
  202. while (!NRF_NVMC->READY) {
  203. }
  204. NRF_NVMC->CONFIG = NVMC_CONFIG_WEN_Ren << NVMC_CONFIG_WEN_Pos;
  205. __DMB();
  206. }
  207. // Stacked PC/LR of a BLOCKED FreeRTOS task. pxTopOfStack is the first TCB member (portable-layer invariant);
  208. // the CM4F PendSV push order is [r4-r11, EXC_RETURN] then (s16-s31 iff the FPU frame was live) then the
  209. // hardware frame [r0-r3, r12, lr, pc, xpsr]. EXC_RETURN bit4 = 0 means the FPU frame is present.
  210. static void bbTaskPc(TaskHandle_t h, uint32_t *pc, uint32_t *lr)
  211. {
  212. *pc = *lr = 0;
  213. if (!h)
  214. return;
  215. uint32_t *tos = *(uint32_t **)h;
  216. uint32_t a = (uint32_t)tos;
  217. if (a < 0x20000000u || a >= 0x20040000u - (26 + 8) * 4)
  218. return; // corrupt TCB/stack -> don't fault inside the black box
  219. uint32_t excret = tos[8];
  220. uint32_t hw = 9 + ((excret & 0x10) ? 0 : 16);
  221. *pc = tos[hw + 6];
  222. *lr = tos[hw + 5];
  223. }
  224. extern "C" void bbTimerBody(void)
  225. {
  226. NRF_TIMER4->EVENTS_COMPARE[0] = 0;
  227. (void)NRF_TIMER4->EVENTS_COMPARE[0]; // readback: event write is posted
  228. static uint32_t lastBeat;
  229. static uint16_t stuck;
  230. static bool dumped;
  231. uint32_t b = g_loopBeatMs;
  232. if (b != lastBeat) {
  233. lastBeat = b;
  234. stuck = 0;
  235. return;
  236. }
  237. if (dumped)
  238. return;
  239. if (++stuck <
  240. 24) { // 24 ticks @ 4 Hz = 6 s frozen; WDT reset lands at 8 s
  241. // USBD self-heal kick before giving up. The black-boxed wedge (2026-07-03, loopPC=start_dma,
  242. // usbdPC=idle xQueueReceive) is a USB EasyDMA whose END event/interrupt got swallowed (clone
  243. // USBD silicon under concurrent RADIO EasyDMA): TinyUSB's dma_running never clears, every next
  244. // transfer re-defers on the TASK_PRIO_HIGH usbd task (livelock), and TASK_PRIO_LOW loop starves.
  245. // If the END EVENT is latched but its IRQ was lost, re-pending the USBD IRQ makes the ISR run
  246. // edpt_dma_end -> the defer chain unwinds -> FULL recovery, no reset (the panel trail shows a
  247. // recovered stall episode). Harmless when nothing is pending: a spurious USBD ISR just returns.
  248. // >=500ms of frozen loop heartbeat is never legitimate (bond flash saves are ms-class).
  249. if (stuck >= 2) {
  250. NVIC_SetPendingIRQ(USBD_IRQn);
  251. faultDiagTrace(
  252. FR_HEAL,
  253. 0x05Bu); // arg 0x5B = USBD kick (radio heal passes its own count)
  254. }
  255. return;
  256. }
  257. dumped = true;
  258. // Lazy erase: the page still holds the PREVIOUS hang's (already-reported) record -- boot no longer
  259. // erases it, so its CDC banner stays re-printable on any later debug boot. An in-ISR page erase is
  260. // ~85ms of CPU stall, irrelevant here: the system is already dead and the WDT reset is ~2s away.
  261. bbErase();
  262. // Record v2, written in TWO PHASES: phase 1 (PCs + vitals) commits BEFORE any USBD register is
  263. // touched -- if the USBD peripheral has wedged the AHB matrix, reading its registers could bus-stall
  264. // this ISR forever (the WDT still resets: its reset path is hardware, not CPU). A record with phase 1
  265. // present and phase 2 erased (0xFFFFFFFF) is therefore itself the proof of an AHB/USBD bus wedge.
  266. uint32_t lpc, llr, upc, ulr;
  267. bbTaskPc(g_hLoop, &lpc, &llr);
  268. bbTaskPc(g_hUsbd, &upc, &ulr);
  269. uint32_t w1[8] = {
  270. BB_MAGIC,
  271. (2u << 24) | ((uint32_t)g_curStage << 16), // ver 2
  272. lpc, // w2: loop task stacked PC (where it starved/blocked)
  273. g_bbIrqPC, // w3: what TIMER4 preempted = the code RUNNING at dump time
  274. upc, // w4: usbd task stacked PC
  275. ((uint32_t)g_flight.usbdStackFree << 16) |
  276. g_flight.loopStackFree, // w5
  277. ((uint32_t)g_flight.relayps << 16) | g_flight.pollsps, // w6
  278. g_flight.vMs, // w7: millis at last healthy vitals ~= wedge time
  279. };
  280. (void)llr;
  281. (void)ulr;
  282. for (int i = 0; i < 8; i++)
  283. bbFlashWord(BB_ADDR + 4u * i, w1[i]);
  284. // phase 2: USBD peripheral state -- did the DMA END event ever latch? are its interrupts enabled?
  285. uint32_t endmask = 0;
  286. for (int i = 0; i < 8; i++) {
  287. if (NRF_USBD->EVENTS_ENDEPIN[i])
  288. endmask |= (1u << i);
  289. if (NRF_USBD->EVENTS_ENDEPOUT[i])
  290. endmask |= (1u << (8 + i));
  291. }
  292. if (NRF_USBD->EVENTS_EPDATA)
  293. endmask |= (1u << 16);
  294. if (NRF_USBD->EVENTS_USBEVENT)
  295. endmask |= (1u << 17);
  296. if (NRF_USBD->EVENTS_EP0DATADONE)
  297. endmask |= (1u << 18);
  298. if (NRF_USBD->EVENTS_SOF)
  299. endmask |= (1u << 19);
  300. if (NVIC_GetPendingIRQ(USBD_IRQn))
  301. endmask |= (1u << 20); // IRQ pending but not being serviced
  302. if (NVIC_GetEnableIRQ(USBD_IRQn))
  303. endmask |= (1u << 21);
  304. uint32_t w2[4] = {
  305. endmask, // w8: latched-event bitmap (ENDEPIN 0-7, ENDEPOUT 8-15, EPDATA/USBEVENT/EP0DD/SOF, NVIC)
  306. NRF_USBD->INTEN, // w9: which USBD interrupts are enabled
  307. NRF_USBD->EPDATASTATUS, // w10: per-endpoint data-ready flags
  308. ((uint32_t)NRF_USBD->EPINEN << 16) |
  309. (NRF_USBD->EPOUTEN & 0xFFFF), // w11
  310. };
  311. for (int i = 0; i < 4; i++)
  312. bbFlashWord(BB_ADDR + 4u * (8 + i), w2[i]);
  313. }
  314. // Naked shim: grab the interrupted context's stacked PC/LR (like the WDT capture), then tail-branch to the C
  315. // body -- LR still holds EXC_RETURN, so the body's return IS the exception return.
  316. extern "C" __attribute__((naked)) void TIMER4_IRQHandler(void)
  317. {
  318. __asm volatile("tst lr, #4 \n"
  319. "ite eq \n"
  320. "mrseq r0, msp \n"
  321. "mrsne r0, psp \n"
  322. "ldr r1, [r0, #24] \n"
  323. "ldr r2, =g_bbIrqPC \n"
  324. "str r1, [r2] \n"
  325. "ldr r1, [r0, #20] \n"
  326. "ldr r2, =g_bbIrqLR \n"
  327. "str r1, [r2] \n"
  328. "b bbTimerBody \n"
  329. ".ltorg \n");
  330. }
  331. void faultDiagBlackBoxArm()
  332. {
  333. NRF_TIMER4->TASKS_STOP = 1;
  334. NRF_TIMER4->MODE = TIMER_MODE_MODE_Timer << TIMER_MODE_MODE_Pos;
  335. NRF_TIMER4->BITMODE = TIMER_BITMODE_BITMODE_32Bit
  336. << TIMER_BITMODE_BITMODE_Pos;
  337. NRF_TIMER4->PRESCALER = 9; // 16 MHz / 512 = 31250 Hz
  338. NRF_TIMER4->CC[0] = 31250u / 4u; // 4 Hz
  339. NRF_TIMER4->SHORTS = TIMER_SHORTS_COMPARE0_CLEAR_Msk;
  340. NRF_TIMER4->EVENTS_COMPARE[0] = 0;
  341. NRF_TIMER4->INTENSET = TIMER_INTENSET_COMPARE0_Msk;
  342. NVIC_SetPriority(TIMER4_IRQn,
  343. 1); // above BASEPRI masking, below the WDT capture
  344. NVIC_ClearPendingIRQ(TIMER4_IRQn);
  345. NVIC_EnableIRQ(TIMER4_IRQn);
  346. NRF_TIMER4->TASKS_START = 1;
  347. }
  348. static void bbErase()
  349. {
  350. NRF_NVMC->CONFIG = NVMC_CONFIG_WEN_Een << NVMC_CONFIG_WEN_Pos;
  351. __DMB();
  352. NRF_NVMC->ERASEPAGE = BB_ADDR;
  353. while (!NRF_NVMC->READY) {
  354. }
  355. NRF_NVMC->CONFIG = NVMC_CONFIG_WEN_Ren << NVMC_CONFIG_WEN_Pos;
  356. __DMB();
  357. }
  358. // Boot-side: report the record. Runs from faultDiagBoot AFTER the .noinit hangPC/hangStage recovery, so on
  359. // boards where those survive the black box only fills the gaps; on RAM-wiping boards it IS the evidence.
  360. // Lifecycle: the record is NOT erased here -- a normal boot often has no CDC attached, so erasing on first
  361. // boot would destroy the register words unread. Instead it persists (the banner re-prints on ANY later boot,
  362. // e.g. a debug-CDC reboot) and the NEXT dump erases the page itself. A "seen" marker at word 12 keeps the
  363. // panel adoption one-shot so a stale record can't masquerade as a later, unrelated hang's evidence.
  364. static void bbBootReport(bool isHang)
  365. {
  366. const volatile uint32_t *w = (const volatile uint32_t *)BB_ADDR;
  367. bool fresh = (w[12] == 0xFFFFFFFFu);
  368. if (w[0] != BB_MAGIC) {
  369. // garbage/partial page (interrupted dump or pre-feature content): clean it so the next dump
  370. // writes onto erased flash. All-blank needs no erase.
  371. bool blank = true;
  372. for (int i = 0; i < BB_WORDS; i++)
  373. if (w[i] != 0xFFFFFFFFu)
  374. blank = false;
  375. // keep a half-written phase-1 record (magic present handled below); anything else non-blank
  376. // without magic is garbage
  377. if (!blank)
  378. bbErase();
  379. return;
  380. }
  381. {
  382. uint8_t stage = (uint8_t)(w[1] >> 16);
  383. Serial.printf(
  384. "# BLACK BOX v%lu (flash dump written ~6s into the last hang):\n",
  385. (unsigned long)(w[1] >> 24));
  386. Serial.printf(
  387. "# stage=%s loopPC=%08lX irqPC=%08lX (running at dump) usbdPC=%08lX\n",
  388. faultDiagStageStr(stage), (unsigned long)w[2],
  389. (unsigned long)w[3], (unsigned long)w[4]);
  390. Serial.printf(
  391. "# stkFree usbd=%luw loop=%luw polls/s=%lu relay/s=%lu tWedge~%lums\n",
  392. (unsigned long)(w[5] >> 16),
  393. (unsigned long)(w[5] & 0xFFFF),
  394. (unsigned long)(w[6] & 0xFFFF),
  395. (unsigned long)(w[6] >> 16), (unsigned long)w[7]);
  396. // phase 2 = USBD peripheral state; all-FF here with phase 1 present = reading USBD registers
  397. // bus-stalled the dump ISR = the peripheral wedged the AHB matrix (decisive by itself).
  398. if (w[8] == 0xFFFFFFFFu && w[9] == 0xFFFFFFFFu)
  399. Serial.printf(
  400. "# USBD regs: UNREADABLE (dump died reading them -> AHB/USBD bus wedge)\n");
  401. else
  402. Serial.printf(
  403. "# USBD: events=%08lX (ENDEPIN0-7,ENDEPOUT8-15,EPDATA16,USBEVT17,EP0DD18,SOF19,NVICpend20,NVICen21)"
  404. " INTEN=%08lX EPDATASTATUS=%08lX EPINEN=%04lX EPOUTEN=%04lX\n",
  405. (unsigned long)w[8], (unsigned long)w[9],
  406. (unsigned long)w[10],
  407. (unsigned long)(w[11] >> 16),
  408. (unsigned long)(w[11] & 0xFFFF));
  409. // feed the existing panel channels (hangLog / Last-reset tile) when the .noinit path came back
  410. // blank -- i.e. exactly the RAM-wiping boards this exists for. loopPC is the primary suspect
  411. // location; irqPC (the code actually RUNNING while loop starved) rides the LR slot. One-shot:
  412. // only a FRESH record (seen-marker still erased) may claim this boot's hang.
  413. if (isHang && fresh) {
  414. if (!g_reportHangPC && w[2]) {
  415. g_reportHangPC = w[2];
  416. g_reportHangLR = w[3];
  417. }
  418. if (g_hangStage == 0xFF && stage < STAGE_COUNT)
  419. g_hangStage = stage;
  420. }
  421. if (fresh)
  422. bbFlashWord(BB_ADDR + 4u * 12, 1u); // stamp "seen"
  423. }
  424. }
  425. void faultDiagBoot()
  426. {
  427. uint32_t rr =
  428. readResetReason(); // latched + cleared by the core's init()
  429. uint8_t g2 = (uint8_t)NRF_POWER->GPREGRET2;
  430. NRF_POWER->GPREGRET2 = 0; // consume the marker for this boot cycle
  431. g_resetReas = rr;
  432. // If this boot follows a watchdog/lockup reset and GPREGRET2 holds a stage breadcrumb (0x80|stage), recover
  433. // which loop stage was stuck. Only meaningful for hangs -- an intentional reboot/HardFault stamps its own
  434. // marker over the breadcrumb, and a clean power-on zeroes it.
  435. bool isHang = (rr & POWER_RESETREAS_DOG_Msk) ||
  436. (rr & POWER_RESETREAS_LOCKUP_Msk);
  437. if (isHang && (g2 & G2_STAGE_FLAG) && g2 < G2_INTENT)
  438. g_hangStage = (uint8_t)(g2 & 0x1Fu);
  439. else
  440. g_hangStage = 0xFF;
  441. // Recover the PC the WDT pre-reset ISR captured (if it fired -- i.e. the hang wasn't PRIMASK-off). Consume
  442. // the magic so a later watchdog reset that DIDN'T capture (PRIMASK-off) can't report a stale address.
  443. if (isHang && g_hangFrame.magic == HANGPC_MAGIC) {
  444. g_reportHangPC = g_hangFrame.pc;
  445. g_reportHangLR = g_hangFrame.lr;
  446. } else {
  447. g_reportHangPC = 0;
  448. g_reportHangLR = 0;
  449. }
  450. g_hangFrame.magic = 0;
  451. uint8_t reason;
  452. // Precedence: a physical pin reset / watchdog / lockup is unambiguous from RESETREAS; only a SREQ needs the
  453. // GPREGRET2 marker to split intentional reboot vs HardFault.
  454. if (rr & POWER_RESETREAS_RESETPIN_Msk)
  455. reason = RR_PIN;
  456. else if (rr & POWER_RESETREAS_DOG_Msk)
  457. reason = RR_WATCHDOG;
  458. else if (rr & POWER_RESETREAS_LOCKUP_Msk)
  459. reason = RR_LOCKUP;
  460. else if (rr & POWER_RESETREAS_SREQ_Msk)
  461. reason = (g2 == G2_FAULT) ? RR_HARDFAULT :
  462. (g2 == G2_INTENT) ? RR_REBOOT :
  463. RR_SOFT;
  464. else if (rr & POWER_RESETREAS_OFF_Msk)
  465. reason = RR_WAKE;
  466. else if (rr == 0)
  467. reason = RR_POWERON; // all bits clear == power-on / brownout
  468. else
  469. reason = RR_UNKNOWN;
  470. g_reason = reason;
  471. Serial.printf(
  472. "# reset cause: %s (RESETREAS=0x%08lX gpregret2=0x%02X)\n",
  473. REASON_STR[reason], (unsigned long)rr, g2);
  474. if (g_hangStage != 0xFF)
  475. Serial.printf("# hang stage: %s (%u)\n",
  476. faultDiagHangStageStr(), g_hangStage);
  477. if (g_reportHangPC)
  478. Serial.printf("# hang PC=0x%08lX LR=0x%08lX\n",
  479. (unsigned long)g_reportHangPC,
  480. (unsigned long)g_reportHangLR);
  481. // Flash black box: report + consume last hang's pre-watchdog dump (fills hangPC/stage on boards whose
  482. // bootloader wiped the .noinit/GPREGRET2 evidence above).
  483. bbBootReport(isHang);
  484. // Flight recorder: if the pre-reset trail survived (.noinit), snapshot it into ordinary RAM so the live
  485. // session can start a fresh ring while the console can still re-dump the old trail ("FR"). On a hang, dump
  486. // it now -- this is the post-mortem of what the firmware was doing in the seconds before it wedged.
  487. if (g_flight.magic == FR_MAGIC) {
  488. memcpy(&g_flightSaved, (const void *)&g_flight,
  489. sizeof g_flightSaved);
  490. g_haveSaved = true;
  491. }
  492. g_flight.magic = FR_MAGIC; // start this session's trail fresh
  493. g_flight.head = 0;
  494. g_flight.count = 0;
  495. if (isHang)
  496. faultDiagDumpFlight();
  497. }
  498. // ---- flight recorder (implementation; data declared above faultDiagBoot) ----------------------------------
  499. void faultDiagTrace(uint8_t evt, uint16_t arg)
  500. {
  501. uint32_t pm = __get_PRIMASK();
  502. __disable_irq();
  503. if (g_flight.magic !=
  504. FR_MAGIC) { // lazy (re)init: power-on garbage or first push this session
  505. g_flight.magic = FR_MAGIC;
  506. g_flight.head = 0;
  507. g_flight.count = 0;
  508. }
  509. uint16_t h = g_flight.head;
  510. g_flight.ring[h].ms = millis();
  511. g_flight.ring[h].arg = arg;
  512. g_flight.ring[h].evt = evt;
  513. g_flight.ring[h].stage = g_curStage;
  514. g_flight.head = (uint16_t)((h + 1u) % FR_RING);
  515. if (g_flight.count < 0xFFFFu)
  516. g_flight.count++;
  517. if (!pm)
  518. __enable_irq();
  519. }
  520. void faultDiagFlightTick(void)
  521. {
  522. static unsigned long beatMs = 0, secMs = 0;
  523. static uint32_t loops = 0;
  524. loops++;
  525. unsigned long now = millis();
  526. // ~4x/s: refresh the persistent vitals snapshot + drop a heartbeat crumb (its cadence in the trail shows
  527. // exactly when loop() stopped advancing).
  528. if ((uint32_t)(now - beatMs) >= 250u) {
  529. beatMs = now;
  530. uint32_t stall = faultDiagStallMs();
  531. g_flight.vMs = now;
  532. g_flight.usbdStackFree = faultDiagUsbdStackFree();
  533. g_flight.loopStackFree = faultDiagLoopStackFree();
  534. // NOTE: mallinfo() removed here -- it suspended the FreeRTOS scheduler + walked the heap free list 4x/s,
  535. // which is new loop latency and a new wedge surface on a slow clone, for zero payoff (heap was flat). If
  536. // a heap-usage trend is ever needed, sample it lazily from loop, not on this hot path.
  537. g_flight.heapUsed = 0;
  538. g_flight.pollsps = g_pollsps;
  539. g_flight.relayps = g_relayps;
  540. g_flight.crcps = g_crcps;
  541. g_flight.norxps = g_norxps;
  542. g_flight.rfHeal = g_rfStallRecover;
  543. g_flight.ringFault = g_ringFault;
  544. g_flight.curStage = g_curStage;
  545. g_flight.stallMs = (uint8_t)(stall > 255 ? 255 : stall);
  546. faultDiagTrace(FR_BEAT, (uint16_t)g_flight.stallMs);
  547. }
  548. // once per second: latch loop rate + emit the live CDC vitals line (loop context -> Serial is safe here,
  549. // unlike the usbd task). Reads as a trend on a flaky board: usbd stack falling toward 0 = the overflow;
  550. // heapUsed climbing = a leak; poll==0 = the RF loop stalled; relay high = Steam flooding the link.
  551. if ((uint32_t)(now - secMs) >= 1000u) {
  552. g_flight.loopPerSec = loops;
  553. loops = 0;
  554. secMs = now;
  555. // Guard on FIFO space: a CDC write to a host that has the port open but isn't draining blocks the loop --
  556. // itself a watchdog-hang source (same failure the WebUSB blob send hit). If there's no room this second,
  557. // skip the line rather than stall; the persistent trail still captured the vitals via the beat above.
  558. if (g_vitals && Serial && Serial.availableForWrite() >= 200) {
  559. // Clock fingerprint on every line: the radio waits time out on micros() (HFCLK-derived). If a clone's
  560. // HFCLK drops to the internal RC (or micros() freezes), usPerMs drifts off 1000 and a "bounded" RX/
  561. // disable wait can spin forever -- the prime suspect for a healthy-then-sudden hard lock. lf/hf: R=RC,
  562. // X=xtal, S=synth, -=stopped.
  563. const char clkc[] = { '-', 'R', 'X', 'S' };
  564. uint8_t lf = clockLfSrc(), hf = clockHfSrc();
  565. Serial.printf(
  566. "# vit up=%lus loop=%lu/s stall=%ums stage=%s usbdStk=%u loopStk=%u heapUsed=%lu "
  567. "poll=%u relay=%u crc=%u norx=%u heal=%u ringF=%u clk=%c/%c usPerMs=%u\n",
  568. (unsigned long)(now / 1000),
  569. (unsigned long)g_flight.loopPerSec,
  570. (unsigned)g_flight.stallMs,
  571. faultDiagStageStr(g_flight.curStage),
  572. (unsigned)g_flight.usbdStackFree,
  573. (unsigned)g_flight.loopStackFree,
  574. (unsigned long)g_flight.heapUsed,
  575. (unsigned)g_flight.pollsps,
  576. (unsigned)g_flight.relayps,
  577. (unsigned)g_flight.crcps,
  578. (unsigned)g_flight.norxps,
  579. (unsigned)g_flight.rfHeal,
  580. (unsigned)g_flight.ringFault,
  581. lf < 4 ? clkc[lf] : '?',
  582. hf < 4 ? clkc[hf] : '?',
  583. (unsigned)clockUsPerMs());
  584. }
  585. }
  586. }
  587. // Wait (bounded) for room in the CDC TX FIFO so a multi-line dump to a slow host neither drops lines nor
  588. // blocks forever. Caps each line's wait at ~20ms -> the whole ~100-line dump can't approach the ~8s watchdog.
  589. static void frWaitTx(uint16_t need)
  590. {
  591. for (uint8_t w = 0;
  592. w < 20 && Serial && Serial.availableForWrite() < need; w++)
  593. delay(1);
  594. }
  595. void faultDiagDumpFlight(void)
  596. {
  597. if (!Serial) // no host attached (e.g. the automatic boot dump before the panel connects) -- use "FR" later
  598. return;
  599. if (!g_haveSaved || g_flightSaved.magic != FR_MAGIC) {
  600. Serial.println(
  601. "# flight: no pre-reset trail (recorder lost across this reset, or last boot wasn't a hang)");
  602. return;
  603. }
  604. const struct FlightRec *f = &g_flightSaved;
  605. Serial.printf(
  606. "# ---- FLIGHT RECORDER (trail up to the last hang) ----\n"
  607. "# vitals@wedge: loop=%lu/s stall=%ums stage=%s usbdStkFree=%u loopStkFree=%u heapUsed=%lu\n"
  608. "# poll=%u relay=%u crc=%u norx=%u heal=%u ringFault=%u (age %lums before reset)\n",
  609. (unsigned long)f->loopPerSec, (unsigned)f->stallMs,
  610. faultDiagStageStr(f->curStage), (unsigned)f->usbdStackFree,
  611. (unsigned)f->loopStackFree, (unsigned long)f->heapUsed,
  612. (unsigned)f->pollsps, (unsigned)f->relayps, (unsigned)f->crcps,
  613. (unsigned)f->norxps, (unsigned)f->rfHeal,
  614. (unsigned)f->ringFault, (unsigned long)0);
  615. uint16_t total = f->count;
  616. uint16_t cnt = total < FR_RING ? total : (uint16_t)FR_RING;
  617. if (!cnt) {
  618. Serial.println("# flight: trail empty");
  619. return;
  620. }
  621. uint16_t start = (uint16_t)((f->head + FR_RING - cnt) % FR_RING);
  622. uint16_t lastIdx = (uint16_t)((f->head + FR_RING - 1u) % FR_RING);
  623. uint32_t last = f->ring[lastIdx].ms;
  624. Serial.printf(
  625. "# %u events (of %u total); t = ms BEFORE the last recorded crumb:\n",
  626. cnt, total);
  627. for (uint16_t i = 0; i < cnt; i++) {
  628. uint16_t idx = (uint16_t)((start + i) % FR_RING);
  629. const FRRec *r = &f->ring[idx];
  630. frWaitTx(64);
  631. Serial.printf("# -%6lu %-8s stage=%-9s arg=0x%04X\n",
  632. (unsigned long)(last - r->ms), frEvtStr(r->evt),
  633. faultDiagStageStr(r->stage), r->arg);
  634. }
  635. Serial.println("# ---- end flight recorder ----");
  636. }
  637. // ---- WebUSB panel access to the saved trail ----------------------------------------------------------------
  638. static uint16_t g_frDrain =
  639. 0; // pull cursor into g_flightSaved, 0 = oldest saved event
  640. bool faultDiagHaveFlight(void)
  641. {
  642. return g_haveSaved && g_flightSaved.magic == FR_MAGIC;
  643. }
  644. uint16_t faultDiagFlightCount(void)
  645. {
  646. if (!faultDiagHaveFlight())
  647. return 0;
  648. uint16_t t = g_flightSaved.count;
  649. return t < FR_RING ? t : (uint16_t)FR_RING;
  650. }
  651. uint16_t faultDiagFlightTotal(void)
  652. {
  653. return faultDiagHaveFlight() ? g_flightSaved.count : 0;
  654. }
  655. void faultDiagFlightDrainReset(void)
  656. {
  657. g_frDrain = 0;
  658. }
  659. bool faultDiagFlightPull(uint32_t *dtMs, uint8_t *evt, uint8_t *stage,
  660. uint16_t *arg)
  661. {
  662. uint16_t cnt = faultDiagFlightCount();
  663. if (g_frDrain >= cnt)
  664. return false;
  665. const struct FlightRec *f = &g_flightSaved;
  666. uint16_t start = (uint16_t)((f->head + FR_RING - cnt) % FR_RING);
  667. uint16_t idx = (uint16_t)((start + g_frDrain) % FR_RING);
  668. uint16_t lastIdx = (uint16_t)((f->head + FR_RING - 1u) % FR_RING);
  669. *dtMs = (uint32_t)(f->ring[lastIdx].ms - f->ring[idx].ms);
  670. *evt = f->ring[idx].evt;
  671. *stage = f->ring[idx].stage;
  672. *arg = f->ring[idx].arg;
  673. g_frDrain++;
  674. return true;
  675. }
  676. bool faultDiagFlightVitals(struct FaultFlightVitals *out)
  677. {
  678. if (!faultDiagHaveFlight())
  679. return false;
  680. const struct FlightRec *f = &g_flightSaved;
  681. out->loopPerSec =
  682. (uint16_t)(f->loopPerSec > 0xFFFFu ? 0xFFFFu : f->loopPerSec);
  683. out->usbdStkFree = f->usbdStackFree;
  684. out->loopStkFree = f->loopStackFree;
  685. out->heapUsed = f->heapUsed;
  686. out->pollsps = f->pollsps;
  687. out->relayps = f->relayps;
  688. out->crcps = f->crcps;
  689. out->norxps = f->norxps;
  690. out->rfHeal = f->rfHeal;
  691. out->ringFault = f->ringFault;
  692. out->curStage = f->curStage;
  693. out->stallMs = f->stallMs;
  694. return true;
  695. }
  696. // ---- clock fingerprint -------------------------------------------------------------------------------------
  697. static uint8_t g_clkLf = 0, g_clkHf = 0;
  698. static uint16_t g_clkUsPerMs = 0;
  699. void clockDiagBoot()
  700. {
  701. // LFCLKSTAT: bit16 STATE(running), bits1:0 SRC (0=RC,1=Xtal,2=Synth). HFCLKSTAT: bit16 STATE, bit0 SRC
  702. // (0=RC,1=Xtal). The bare-metal radio needs HFXO; if HF shows RC here, RF runs on the 64 MHz internal RC.
  703. uint32_t lf = NRF_CLOCK->LFCLKSTAT;
  704. uint32_t hf = NRF_CLOCK->HFCLKSTAT;
  705. bool lfrun = lf & CLOCK_LFCLKSTAT_STATE_Msk;
  706. uint8_t lfsrc = (uint8_t)(lf & CLOCK_LFCLKSTAT_SRC_Msk);
  707. g_clkLf = lfrun ? (uint8_t)(lfsrc + 1) :
  708. 0; // 1=RC,2=Xtal,3=Synth, 0=stopped
  709. bool hfxtal = hf & CLOCK_HFCLKSTAT_SRC_Msk;
  710. g_clkHf = hfxtal ? 2 : 0; // 2=crystal, 0=RC
  711. Serial.printf("# clock: LFCLK=%s HFCLK=%s\n",
  712. g_clkLf == 2 ? "xtal" :
  713. g_clkLf == 1 ? "RC" :
  714. g_clkLf == 3 ? "synth" :
  715. "stopped",
  716. g_clkHf == 2 ? "xtal" : "RC");
  717. }
  718. void clockDiagTick()
  719. {
  720. // Cross-check the two time bases: count micros() (HFCLK-derived) elapsed over a ~1s millis() (LFCLK/RTC)
  721. // window. usPerMs = micros-delta / millis-delta; 1000 = the clocks agree. A clone whose HFCLK runs fast vs
  722. // its LFCLK reads >1000 here -- the exact signature behind "poll rate too high, delivered too low".
  723. static uint32_t u0 = 0;
  724. static unsigned long m0 = 0;
  725. static bool init = false;
  726. unsigned long m = millis();
  727. if (!init) {
  728. u0 = micros();
  729. m0 = m;
  730. init = true;
  731. return;
  732. }
  733. unsigned long dm = m - m0;
  734. if (dm >= 1000) {
  735. uint32_t du = (uint32_t)(micros() - u0);
  736. g_clkUsPerMs = (uint16_t)(du / dm);
  737. u0 = micros();
  738. m0 = m;
  739. }
  740. }
  741. uint8_t clockLfSrc()
  742. {
  743. return g_clkLf;
  744. }
  745. uint8_t clockHfSrc()
  746. {
  747. return g_clkHf;
  748. }
  749. uint16_t clockUsPerMs()
  750. {
  751. return g_clkUsPerMs;
  752. }
  753. // ---- per-task stack headroom (usbd-overflow hypothesis check) ---------------------------------------------
  754. // uxTaskGetSystemState (configUSE_TRACE_FACILITY=1) reports each task's stack high-water mark = the LEAST free
  755. // stack it ever had, in words. The "usbd" task (200 words / 800 B, core-fixed) runs handleSet->relayEnqueue;
  756. // if this trends toward 0 under haptic load, the stack overflow is confirmed. Repo-scoped, read-only, no core
  757. // changes -- just observing FreeRTOS.
  758. static uint16_t g_usbdStackMin = 0xFFFF;
  759. static uint16_t g_loopStackMin = 0xFFFF;
  760. void faultDiagStackTick()
  761. {
  762. static unsigned long ms = 0;
  763. if ((uint32_t)(millis() - ms) < 1000)
  764. return;
  765. ms = millis();
  766. static TaskStatus_t st[12];
  767. UBaseType_t n = uxTaskGetSystemState(st, 12, NULL);
  768. for (UBaseType_t i = 0; i < n; i++) {
  769. uint16_t hw = (uint16_t)st[i].usStackHighWaterMark;
  770. if (!strcmp(st[i].pcTaskName, "usbd")) {
  771. g_hUsbd =
  772. st[i].xHandle; // black box: TCB to walk at dump time
  773. if (hw < g_usbdStackMin)
  774. g_usbdStackMin = hw;
  775. } else if (!strcmp(st[i].pcTaskName, "loop")) {
  776. g_hLoop = st[i].xHandle;
  777. if (hw < g_loopStackMin)
  778. g_loopStackMin = hw;
  779. }
  780. }
  781. }
  782. uint16_t faultDiagUsbdStackFree()
  783. {
  784. return g_usbdStackMin == 0xFFFF ? 0 : g_usbdStackMin;
  785. }
  786. uint16_t faultDiagLoopStackFree()
  787. {
  788. return g_loopStackMin == 0xFFFF ? 0 : g_loopStackMin;
  789. }
  790. uint8_t faultDiagReason()
  791. {
  792. return g_reason;
  793. }
  794. uint32_t faultDiagResetReas()
  795. {
  796. return g_resetReas;
  797. }
  798. const char *faultDiagReasonStr()
  799. {
  800. return REASON_STR[g_reason < RR_COUNT ? g_reason : 0];
  801. }