Using ncs 2.1.2 on nrf52840. Softdevice controller, bluetooth mesh and bluetooth gatt coexisting application.
I have been having an issue attempting to perform DFU using the dfu_target interface on our nrf52840. For whatever reason, an MPSL assertion is being raised during this process. It is more consistently raised the larger I make the buffer passed through dfu_target_mcuboot_set_buf()
. I've enabled the maximum (debug) logging from all the MPSL sources in KConfig, but I have not seen any additional logs. CONFIG_SOC_FLASH_NRF_RADIO_SYNC_MPSL
is enabled, so my understanding is that should deal with any synchronization required. A log is shown below.
[00:01:26.549,102] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x0007e000 [00:01:27.718,017] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x0007f000 [00:01:28.861,694] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x00080000 [00:01:29.995,269] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x00081000 [00:01:31.164,489] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x00082000 [00:01:32.339,294] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x00083000 [00:01:33.468,994] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x00084000 [00:01:34.672,882] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x00085000 [00:01:35.801,696] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x00086000 [00:01:36.970,489] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x00087000 [00:01:38.137,115] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x00088000 [00:01:39.272,125] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x00089000 [00:01:40.406,616] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x0008a000 [00:01:41.575,500] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x0008b000 [00:01:42.738,739] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x0008c000 [00:01:43.869,415] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x0008d000 [00:01:45.040,130] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x0008e000 [00:01:46.189,117] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x0008f000 [00:01:47.317,932] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x00090000 [00:01:48.473,114] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x00091000 [00:01:49.641,021] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x00092000 [00:01:50.785,522] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x00093000 [00:01:51.945,953] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x00094000 [00:01:53.111,816] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x00095000 [00:01:54.249,938] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x00096000 [00:01:55.416,595] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x00097000 [00:01:56.581,695] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x00098000 [00:01:57.776,275] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x00099000 [00:01:58.952,484] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x0009a000 [00:02:00.088,195] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x0009b000 [00:02:01.219,482] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x0009c000 [00:02:02.381,866] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x0009d000 [00:02:03.550,964] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x0009e000 [00:02:04.718,780] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x0009f000 [00:02:05.891,052] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000a0000 [00:02:07.029,693] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000a1000 [00:02:08.200,744] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000a2000 [00:02:09.368,774] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000a3000 [00:02:10.502,593] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000a4000 [00:02:11.673,065] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000a5000 [00:02:12.861,755] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000a6000 [00:02:13.996,246] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000a7000 [00:02:15.163,269] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000a8000 [00:02:16.329,406] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000a9000 [00:02:17.466,461] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000aa000 [00:02:18.637,481] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000ab000 [00:02:19.793,518] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000ac000 [00:02:20.917,968] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000ad000 [00:02:22.090,728] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000ae000 [00:02:23.252,349] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000af000 [00:02:24.394,104] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000b0000 [00:02:25.563,507] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000b1000 [00:02:26.725,860] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000b2000 [00:02:27.947,998] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000b3000 [00:02:29.115,051] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000b4000 [00:02:30.250,396] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000b5000 [00:02:31.415,008] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000b6000 [00:02:32.586,853] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000b7000 [00:02:33.717,224] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000b8000 [00:02:34.886,779] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000b9000 [00:02:36.052,154] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000ba000 [00:02:37.188,446] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000bb000 [00:02:38.356,781] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000bc000 [00:02:39.524,169] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000bd000 [00:02:40.659,301] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000be000 [00:02:41.822,753] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000bf000 [00:02:43.003,967] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000c0000 [00:02:44.174,316] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000c1000 [00:02:45.343,017] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000c2000 [00:02:46.472,106] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000c3000 [00:02:47.609,558] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000c4000 [00:02:48.774,597] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000c5000 [00:02:49.943,969] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000c6000 [00:02:51.076,110] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000c7000 [00:02:52.244,079] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000c8000 [00:02:53.388,488] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000c9000 [00:02:54.521,545] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000ca000 [00:02:55.689,453] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000cb000 [00:02:56.856,262] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000cc000 [00:02:57.995,483] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000cd000 [00:02:59.164,947] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000ce000 [00:03:00.331,756] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000cf000 [00:03:01.470,123] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000d0000 [00:03:02.640,655] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000d1000 [00:03:03.795,196] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000d2000 [00:03:04.929,748] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000d3000 [00:03:06.175,964] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000d4000 [00:03:07.311,157] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000d5000 [00:03:08.481,323] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000d6000 [00:03:09.646,759] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000d7000 [00:03:10.788,269] <dbg> STREAM_FLASH: stream_flash_erase_page: Erasing page at offset 0x000d8000 [00:03:10.908,721] <err> mpsl_init: MPSL ASSERT: 112, 2142 ASSERTION FAIL [z_spin_lock_valid(l)] @ WEST_TOPDIR/zephyr/include/zephyr/spinlock.h:142 Recursive spinlock 0x2000a7f0 [00:03:10.908,813] <err> os: ***** HARD FAULT ***** [00:03:10.908,813] <err> os: Fault escalation (see below) [00:03:10.908,843] <err> os: ARCH_EXCEPT with reason 4 [00:03:10.908,843] <err> os: r0/a1: 0x00000004 r1/a2: 0x0000008e r2/a3: 0x00000003 [00:03:10.908,874] <err> os: r3/a4: 0x0000008e r12/ip: 0x00000000 r14/lr: 0x0005d773 [00:03:10.908,874] <err> os: xpsr: 0x61000018 [00:03:10.908,905] <err> os: Faulting instruction address (r15/pc): 0x000637dc [00:03:10.908,935] <err> os: >>> ZEPHYR FATAL ERROR 4: Kernel panic on CPU 0 [00:03:10.908,935] <err> os: Fault during interrupt handling [00:03:10.908,966] <err> os: Current thread: 0x20003c88 (MPSL Work) [00:03:11.283,386] <err> fatal_error: Resetting system
Since the MPSL is completely opaque, I really have no idea what's going on here. My best guess is that some time critical behavior is being violated, but I am not sure what. I'm also not sure what to do about it, since the flash erase and write times are essentially out of my control.