Hello,
We're building zigbee devices around the nRF5340 with the nRF SDK/zboss/zephyr. I'm working on custom boards and have based my 802154 code around the samples in nrf/samples/zigbee.
Though running atop those custom boards, I kept the light_switch and network_coordinator pretty much as-is and was running each on a distinct PCB. Things weren't working out, so I started looking at each component in turn, to finally find this:
In this example, I'm monitoring the network coordinator with a debugger and sniffing zigbee packets over the air. I let it run for a minute and all is well. As soon as I turn on the light_switch, a beacon request is made and crash! A sample of the logs is attached below for reference.
In attempting to trace where the problem lies, I've peppered the nrf/zephyr code with extra bread crumbs. The "zboss_osif: zbooslooop" (typos make it easy to grep ;-) ) before every call to zboss_main_loop_iteration() in the zboss_thread. The "zignetco: DEFHNDL" is from every time the network controller's zboss_signal_handler callback is triggered but just passes the signal along to zigbee_default_signal_handler().
Crashes always seem to happen in the same sequence: a beacon request or whatever commissioning stuff arrives through the aether, zboss main loop triggers my signal handler, which passes it back to zigbee_default_signal_handler() which wants to get the goods from the spinel IPC thing and... death.
I have played with
- CONFIG_HEAP_MEM_POOL_SIZE
- CONFIG_MAIN_STACK_SIZE
- CONFIG_SYSTEM_WORKQUEUE_STACK_SIZE
to no avail. I eventually thought it was my own system stuff, tried to simplify and just use standard vanilla network_controller code on standard vanilla nRF5340DK... that just led me to posting this:
https://devzone.nordicsemi.com/f/nordic-q-a/82962/frozen-zigbee-network-coordinator-sample-on-nrf5340
so no love there, but oddly in that case I can't get anything working at all.
Of course, to not be completely blind in trying to debug all this, I had to disable the default LOG_MINIMAL stuff (not sure what the idea is there, hard to dev without some sort of feedback), and all the interaction between mcuboot and the network processor and I dunno what makes using the serial logging harder to deal with than I care, but I did manage to get the segger RTT debug stuff working--don't know if that has an impact on anything.
For reference, I'm using a relatively fresh codebase, zephyr-sdk-0.13.2 and nrf/VERSION says 1.8.0-rc1 (last commit 053f939f0478b68ba6da4d01f3ebd463c111ee00, Pavel Vasilyev, Dec 2 16:49:27 2021).
Neither my straight port of the network coordinator nor the default code on the default platform are behaving well: people must be using this stuff, I feel like I'm missing something obvious... Any clues as to what's going on, where to look, what to tweak would be appreciated.
# SEGGER J-Link RTT Viewer V7.58d Terminal Log File # Compiled: 15:28:47 on Dec 2 2021 # Logging started @ 20 Dec 2021 14:01:53 00> [00:00:00.843,688] <dbg> nrf5340_outoflow.remoteproc_mgr_boot: Network MCU released. 00> [00:00:00.850,463] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:00.850,921] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 4 bytes directly 00> [00:00:00.851,440] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 8 bytes. 00> [00:00:00.851,837] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier 00> [00:00:00.852,294] <inf> ieee802154_nrf5: nRF5 802154 radio initialized 00> [00:00:00.852,600] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:00.853,057] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 5 bytes directly 00> [00:00:00.853,576] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 4 bytes. 00> outoflow init done. 00> 00> OUTOFLOW Driver startupSetting pin 30 to 0 00> 00> Setting pin 11 to 0 00> 00> Adding basic curve to sched... ANIM set black 00> 00> done 00> 00> Adding basic curve to sched... ANIM set black 00> 00> done 00> 00> Adding basic curve to sched... ANIM set black 00> 00> done 00> 00> Setting pin 6 to 0 00> 00> Setting pin 7 to 0 00> 00> Setting pin 4 to 0 00> 00> Setting pin 5 to 0 00> 00> Prepping IOSpecs for ext switches... 00> 00> adding pin 9 to spec list 00> 00> adding pin 10 to spec list 00> 00> adding pin 8 to spec list 00> 00> adding pin 25 to spec list 00> 00> DIG input ctor w pin 9 00> 00> DIG input ctor w pin 10 00> 00> DIG input ctor w pin 8 00> 00> DIG input ctor w pin 25 00> 00> EXT inputs ctrl begin 00> 00> DIG input ctor w pin 5 00> 00> Setting pin 26 to 0 00> 00> ext input 0 00> 00> ext input 1 00> 00> ext input 2 00> 00> ext input 3 00> 00> ANIM set heartbeat 00> 00> ANIM set heartbeat 00> 00> ANIM set heartbeat 00> 00> Acting as COORDINATOR---startup. 00> 00> [00:00:04.505,218] <inf> zignetco: COORD STARTUP 00> hohoho indicate coord led cb 1 00> 00> [00:00:04.505,676] <inf> zboss_osif: zigbee_enable created zboss thread 00> [00:00:04.510,406] <inf> zboss_osif: zbooslooop 00> [00:00:04.510,864] <inf> zignetco: DEFHNDL 00> [00:00:04.511,108] <inf> zigbee_app_utils: Production configuration is not present or invalid (status: -1) 00> [00:00:04.511,932] <inf> zignetco: DEFHNDL 00> [00:00:04.512,176] <inf> zigbee_app_utils: Zigbee stack initialized 00> [00:00:04.514,526] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:04.514,984] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 6 bytes directly 00> [00:00:04.515,502] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 4 bytes. 00> [00:00:04.515,899] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier 00> [00:00:04.516,937] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:04.517,395] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 6 bytes directly 00> [00:00:04.517,913] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 4 bytes. 00> [00:00:04.518,280] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier 00> [00:00:04.518,920] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:04.519,378] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 6 bytes directly 00> [00:00:04.519,897] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 4 bytes. 00> [00:00:04.520,294] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier 00> [00:00:04.520,904] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:04.526,336] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 12 bytes directly 00> [00:00:04.526,855] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 4 bytes. 00> [00:00:04.527,252] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier 00> [00:00:04.529,022] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:04.529,479] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 6 bytes directly 00> [00:00:04.529,998] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 4 bytes. 00> [00:00:04.530,395] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier 00> [00:00:04.530,944] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:04.531,402] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 5 bytes directly 00> [00:00:04.531,921] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 4 bytes. 00> [00:00:04.532,287] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier 00> [00:00:04.532,806] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:04.538,238] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 5 bytes directly 00> [00:00:04.538,757] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 4 bytes. 00> [00:00:04.539,154] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier 00> [00:00:04.539,581] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:04.540,039] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 5 bytes directly 00> [00:00:04.540,557] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 4 bytes. 00> [00:00:04.540,954] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier 00> [00:00:04.541,412] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:04.541,870] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 4 bytes directly 00> [00:00:04.542,449] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 5 bytes. 00> [00:00:04.547,821] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier 00> [00:00:04.548,278] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:04.548,706] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 12 bytes directly 00> [00:00:04.549,285] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 4 bytes. 00> [00:00:04.549,682] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier 00> [00:00:04.550,109] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:04.550,567] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 6 bytes directly 00> [00:00:04.551,086] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 4 bytes. 00> [00:00:04.556,427] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier 00> [00:00:04.556,884] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:04.557,342] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 6 bytes directly 00> [00:00:04.557,861] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 4 bytes. 00> [00:00:04.558,258] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier 00> [00:00:04.559,112] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:04.559,570] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 4 bytes directly 00> [00:00:04.565,093] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 5 bytes. 00> [00:00:04.565,490] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier 00> [00:00:04.566,650] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:04.567,108] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 4 bytes directly 00> [00:00:04.567,657] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 5 bytes. 00> [00:00:04.568,054] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier 00> [00:00:04.573,028] <inf> zignetco: REBOOT 00> [00:00:04.573,272] <inf> zignetco: Start network steering 00> [00:00:04.585,174] <inf> zboss_osif: zbooslooop 00> [00:00:04.585,449] <inf> zignetco: DEFHNDL 00> [00:00:04.595,886] <inf> zboss_osif: zbooslooop 00> [00:00:04.596,191] <inf> zignetco: DEFHNDL 00> [00:00:04.606,567] <inf> zboss_osif: zbooslooop 00> Outoflow startup OK 00> 00> [00:00:04.616,943] <inf> zboss_osif: zbooslooop 00> [00:00:04.618,957] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:04.619,445] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 72 bytes directly 00> [00:00:04.620,025] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 5 bytes. 00> [00:00:04.620,422] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier 00> [00:00:04.624,328] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 27 bytes. 00> [00:00:04.634,887] <inf> zboss_osif: zbooslooop 00> [00:00:04.645,294] <inf> zboss_osif: zbooslooop 00> [00:00:04.655,670] <inf> zboss_osif: zbooslooop 00> [00:00:04.666,137] <inf> zboss_osif: zbooslooop 00> [00:00:04.666,442] <inf> zignetco: DEFHNDL 00> [00:00:04.676,879] <inf> zboss_osif: zbooslooop 00> [00:00:04.677,185] <inf> zignetco: DEFHNDL 00> [00:00:04.687,561] <inf> zboss_osif: zbooslooop 00> [00:00:04.697,937] <inf> zboss_osif: zbooslooop 00> [00:00:04.708,404] <inf> zboss_osif: zbooslooop 00> [00:00:04.708,709] <inf> zignetco: DEFHNDL 00> Running main loop. 00> 00> Hohoho sensor triggered for 512 00> 00> Hohoho value is 0 00> 00> Hohoho sensor triggered for 1024 00> 00> Hohoho value is 0 00> 00> Hohoho sensor triggered for 256 00> 00> Hohoho value is 0 00> 00> Hohoho sensor triggered for 33554432 00> 00> Hohoho value is 0 00> 00> ANIM set net coordinator 00> 00> LED EN: Activity trig 00> 00> [00:00:04.746,795] <inf> adi_adp8866: Re-trig low level setup... 00> [00:00:04.747,314] <inf> adi_adp8866: backlight set 00> [00:00:04.747,680] <inf> adi_adp8866: ICS fade rate set 00> [00:00:04.748,046] <inf> adi_adp8866: backlight fade rate set 00> [00:00:04.748,443] <inf> adi_adp8866: ISCC1 set 00> [00:00:04.748,779] <inf> adi_adp8866: ISCC2 set 00> [00:00:04.749,206] <inf> zboss_osif: zbooslooop 00> [00:00:04.749,908] <inf> adi_adp8866: GOT stat 32 00> [00:00:04.750,183] <inf> adi_adp8866: SETUP DONE 00> [00:00:04.759,674] <inf> zboss_osif: zbooslooop 00> [00:00:04.759,948] <inf> zignetco: DEFHNDL 00> [00:00:04.800,476] <inf> zboss_osif: zbooslooop 00> [00:00:04.800,781] <inf> zignetco: DEFHNDL 00> [00:00:04.811,157] <inf> zboss_osif: zbooslooop 00> [00:00:04.821,533] <inf> zboss_osif: zbooslooop 00> [00:00:04.832,000] <inf> zboss_osif: zbooslooop 00> [00:00:04.832,305] <inf> zignetco: DEFHNDL 00> [00:00:04.872,833] <inf> zboss_osif: zbooslooop 00> [00:00:04.873,138] <inf> zignetco: DEFHNDL 00> [00:00:04.883,514] <inf> zboss_osif: zbooslooop 00> [00:00:04.893,890] <inf> zboss_osif: zbooslooop 00> [00:00:04.904,357] <inf> zboss_osif: zbooslooop 00> [00:00:04.904,663] <inf> zignetco: DEFHNDL 00> [00:00:04.945,190] <inf> zboss_osif: zbooslooop 00> [00:00:04.945,495] <inf> zignetco: DEFHNDL 00> [00:00:04.955,871] <inf> zboss_osif: zbooslooop 00> [00:00:04.966,247] <inf> zboss_osif: zbooslooop 00> [00:00:04.976,715] <inf> zboss_osif: zbooslooop 00> [00:00:04.977,020] <inf> zignetco: DEFHNDL 00> [00:00:05.017,547] <inf> zboss_osif: zbooslooop 00> [00:00:05.017,852] <inf> zignetco: DEFHNDL 00> [00:00:05.028,228] <inf> zboss_osif: zbooslooop 00> [00:00:05.038,604] <inf> zboss_osif: zbooslooop 00> [00:00:05.049,072] <inf> zboss_osif: zbooslooop 00> [00:00:05.049,377] <inf> zignetco: DEFHNDL 00> [00:00:05.089,904] <inf> zboss_osif: zbooslooop 00> [00:00:05.090,209] <inf> zignetco: DEFHNDL 00> [00:00:05.100,585] <inf> zboss_osif: zbooslooop 00> [00:00:05.110,961] <inf> zboss_osif: zbooslooop 00> [00:00:05.121,429] <inf> zboss_osif: zbooslooop 00> [00:00:05.121,734] <inf> zignetco: DEFHNDL 00> [00:00:05.153,442] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:05.153,900] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 72 bytes directly 00> [00:00:05.154,510] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 5 bytes. 00> [00:00:05.154,907] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier 00> [00:00:05.158,508] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 27 bytes. 00> [00:00:05.161,468] <inf> zignetco: STEERING 00> [00:00:05.161,712] <inf> zignetco: Network steering started 00> [00:00:05.172,271] <inf> zboss_osif: zbooslooop 00> [00:00:05.172,576] <inf> zignetco: DEFHNDL 00> ANIM set net join 00> 00> [00:00:05.183,044] <inf> zboss_osif: zbooslooop 00> [00:00:05.183,319] <inf> zignetco: DEFHNDL 00> [00:00:05.699,798] <inf> zboss_osif: zbooslooop 00> [00:00:05.710,174] <inf> zboss_osif: zbooslooop 00> [00:00:05.720,672] <inf> zboss_osif: zbooslooop 00> [00:00:05.720,947] <inf> zignetco: DEFHNDL 00> [00:00:06.729,431] <inf> zboss_osif: zbooslooop 00> [00:00:06.739,929] <inf> zboss_osif: zbooslooop 00> [00:00:06.740,203] <inf> zignetco: DEFHNDL 00> ColCB for sched 1 complete... for led 1... 00> 00> [00:00:07.748,687] <inf> zboss_osif: zbooslooop 00> [00:00:07.759,155] <inf> zboss_osif: zbooslooop 00> [00:00:07.759,460] <inf> zignetco: DEFHNDL 00> [00:00:08.767,944] <inf> zboss_osif: zbooslooop 00> [00:00:08.778,442] <inf> zboss_osif: zbooslooop 00> [00:00:08.778,717] <inf> zignetco: DEFHNDL 00> [00:00:09.787,292] <inf> zboss_osif: zbooslooop 00> [00:00:09.797,760] <inf> zboss_osif: zbooslooop 00> [00:00:09.798,065] <inf> zignetco: DEFHNDL 00> ColCB for sched 1 complete... for led 1... 00> 00> Anim complete! 00> 00> ANIM set black 00> 00> ColCB for sched 2 complete... for led 2... 00> 00> [00:00:10.806,549] <inf> zboss_osif: zbooslooop 00> [00:00:10.817,047] <inf> zboss_osif: zbooslooop 00> [00:00:10.817,321] <inf> zignetco: DEFHNDL 00> [00:00:11.825,805] <inf> zboss_osif: zbooslooop 00> [00:00:11.836,273] <inf> zboss_osif: zbooslooop 00> [00:00:11.836,578] <inf> zignetco: DEFHNDL 00> [00:00:12.845,062] <inf> zboss_osif: zbooslooop 00> [00:00:12.855,529] <inf> zboss_osif: zbooslooop 00> [00:00:12.855,834] <inf> zignetco: DEFHNDL 00> [00:00:13.634,307] <inf> zboss_osif: zbooslooop 00> [00:00:13.634,613] <inf> zignetco: DEFHNDL 00> [00:00:13.844,085] <inf> zboss_osif: zbooslooop 00> [00:00:13.854,461] <inf> zboss_osif: zbooslooop 00> [00:00:13.864,929] <inf> zboss_osif: zbooslooop 00> [00:00:13.865,234] <inf> zignetco: DEFHNDL 00> [00:00:14.873,748] <inf> zboss_osif: zbooslooop 00> [00:00:14.884,216] <inf> zboss_osif: zbooslooop 00> [00:00:14.884,521] <inf> zignetco: DEFHNDL 00> ColCB for sched 2 complete... for led 2... 00> 00> [00:00:15.893,005] <inf> zboss_osif: zbooslooop 00> [00:00:15.903,442] <inf> zboss_osif: zbooslooop 00> [00:00:15.903,747] <inf> zignetco: DEFHNDL 00> [00:00:16.912,231] <inf> zboss_osif: zbooslooop 00> [00:00:16.912,536] <inf> zignetco: DEFHNDL 00> [00:00:17.921,020] <inf> zboss_osif: zbooslooop 00> [00:00:17.921,325] <inf> zignetco: DEFHNDL 00> [00:00:18.944,824] <inf> zboss_osif: zbooslooop 00> [00:00:18.945,129] <inf> zignetco: DEFHNDL 00> [00:00:19.785,034] <inf> zboss_osif: zbooslooop 00> [00:00:19.785,339] <inf> zignetco: DEFHNDL 00> [00:00:19.817,047] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:19.817,504] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 63 bytes directly 00> [00:00:19.818,237] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 5 bytes. 00> [00:00:19.818,603] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier 00> [00:00:19.820,251] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 27 bytes. 00> [00:00:19.830,932] <inf> zboss_osif: zbooslooop 00> [00:00:19.831,268] <inf> zignetco: DEFHNDL 00> [00:00:19.841,674] <inf> zboss_osif: zbooslooop 00> [00:00:19.841,979] <inf> zignetco: DEFHNDL 00> ColCB for sched 2 complete... for led 2... 00> 00> [00:00:19.944,519] <inf> zboss_osif: zbooslooop 00> [00:00:19.944,824] <inf> zignetco: DEFHNDL 00> [00:00:20.799,346] <inf> zboss_osif: zbooslooop 00> [00:00:20.799,652] <inf> zignetco: DEFHNDL 00> [00:00:20.963,165] <inf> zboss_osif: zbooslooop 00> [00:00:20.963,470] <inf> zignetco: DEFHNDL 00> [00:00:21.818,023] <inf> zboss_osif: zbooslooop 00> [00:00:21.818,359] <inf> zignetco: DEFHNDL 00> [00:00:21.981,842] <inf> zboss_osif: zbooslooop 00> [00:00:21.982,147] <inf> zignetco: DEFHNDL 00> [00:00:22.836,669] <inf> zboss_osif: zbooslooop 00> [00:00:22.837,005] <inf> zignetco: DEFHNDL 00> [00:00:23.000,518] <inf> zboss_osif: zbooslooop 00> [00:00:23.000,823] <inf> zignetco: DEFHNDL 00> [00:00:23.855,346] <inf> zboss_osif: zbooslooop 00> [00:00:23.855,651] <inf> zignetco: DEFHNDL 00> [00:00:24.019,165] <inf> zboss_osif: zbooslooop 00> [00:00:24.019,470] <inf> zignetco: DEFHNDL 00> ColCB for sched 2 complete... for led 2... 00> 00> [00:00:24.873,992] <inf> zboss_osif: zbooslooop 00> [00:00:24.874,298] <inf> zignetco: DEFHNDL 00> [00:00:25.037,841] <inf> zboss_osif: zbooslooop 00> [00:00:25.038,146] <inf> zignetco: DEFHNDL 00> [00:00:25.892,669] <inf> zboss_osif: zbooslooop 00> [00:00:25.892,974] <inf> zignetco: DEFHNDL 00> [00:00:26.056,488] <inf> zboss_osif: zbooslooop 00> [00:00:26.056,793] <inf> zignetco: DEFHNDL 00> [00:00:26.911,315] <inf> zboss_osif: zbooslooop 00> [00:00:26.911,621] <inf> zignetco: DEFHNDL 00> [00:00:27.075,103] <inf> zboss_osif: zbooslooop 00> [00:00:27.075,408] <inf> zignetco: DEFHNDL 00> ColCB for sched 0 complete... for led 0... 00> 00> [00:00:27.929,931] <inf> zboss_osif: zbooslooop 00> [00:00:27.930,236] <inf> zignetco: DEFHNDL 00> [00:00:28.093,750] <inf> zboss_osif: zbooslooop 00> [00:00:28.094,055] <inf> zignetco: DEFHNDL 00> [00:00:28.948,577] <inf> zboss_osif: zbooslooop 00> [00:00:28.948,883] <inf> zignetco: DEFHNDL 00> [00:00:29.112,396] <inf> zboss_osif: zbooslooop 00> [00:00:29.112,701] <inf> zignetco: DEFHNDL 00> ColCB for sched 2 complete... for led 2... 00> 00> [00:00:29.967,254] <inf> zboss_osif: zbooslooop 00> [00:00:29.967,559] <inf> zignetco: DEFHNDL 00> [00:00:30.131,103] <inf> zboss_osif: zbooslooop 00> [00:00:30.131,408] <inf> zignetco: DEFHNDL 00> ColCB for sched 1 complete... for led 1... 00> 00> [00:00:30.985,900] <inf> zboss_osif: zbooslooop 00> [00:00:30.986,206] <inf> zignetco: DEFHNDL 00> [00:00:31.149,688] <inf> zboss_osif: zbooslooop 00> [00:00:31.149,993] <inf> zignetco: DEFHNDL 00> [00:00:32.173,461] <inf> zboss_osif: zbooslooop 00> [00:00:32.173,767] <inf> zignetco: DEFHNDL 00> [00:00:33.182,250] <inf> zboss_osif: zbooslooop 00> [00:00:33.182,556] <inf> zignetco: DEFHNDL 00> [00:00:34.206,054] <inf> zboss_osif: zbooslooop 00> [00:00:34.206,359] <inf> zignetco: DEFHNDL 00> ColCB for sched 2 complete... for led 2... 00> 00> [00:00:34.877,258] <inf> zboss_osif: zbooslooop 00> [00:00:34.877,563] <inf> zignetco: DEFHNDL 00> [00:00:34.909,271] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:34.909,729] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 63 bytes directly 00> [00:00:34.910,339] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 5 bytes. 00> [00:00:34.910,736] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier 00> [00:00:34.914,703] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 27 bytes. 00> [00:00:34.925,384] <inf> zboss_osif: zbooslooop 00> [00:00:34.925,689] <inf> zignetco: DEFHNDL 00> [00:00:34.936,126] <inf> zboss_osif: zbooslooop 00> [00:00:34.936,431] <inf> zignetco: DEFHNDL 00> [00:00:35.222,961] <inf> zboss_osif: zbooslooop 00> [00:00:35.223,266] <inf> zignetco: DEFHNDL 00> [00:00:35.908,782] <inf> zboss_osif: zbooslooop 00> [00:00:35.909,088] <inf> zignetco: DEFHNDL 00> [00:00:36.241,607] <inf> zboss_osif: zbooslooop 00> [00:00:36.241,912] <inf> zignetco: DEFHNDL 00> [00:00:36.927,429] <inf> zboss_osif: zbooslooop 00> [00:00:36.927,734] <inf> zignetco: DEFHNDL 00> [00:00:37.260,253] <inf> zboss_osif: zbooslooop 00> [00:00:37.260,559] <inf> zignetco: DEFHNDL 00> [00:00:37.946,075] <inf> zboss_osif: zbooslooop 00> [00:00:37.946,380] <inf> zignetco: DEFHNDL 00> [00:00:38.278,900] <inf> zboss_osif: zbooslooop 00> [00:00:38.279,205] <inf> zignetco: DEFHNDL 00> [00:00:38.964,721] <inf> zboss_osif: zbooslooop 00> [00:00:38.965,026] <inf> zignetco: DEFHNDL 00> ColCB for sched 2 complete... for led 2... 00> 00> [00:00:39.297,546] <inf> zboss_osif: zbooslooop 00> [00:00:39.297,851] <inf> zignetco: DEFHNDL 00> [00:00:39.983,367] <inf> zboss_osif: zbooslooop 00> [00:00:39.983,673] <inf> zignetco: DEFHNDL 00> [00:00:40.316,223] <inf> zboss_osif: zbooslooop 00> [00:00:40.316,528] <inf> zignetco: DEFHNDL 00> [00:00:41.002,044] <inf> zboss_osif: zbooslooop 00> [00:00:41.002,380] <inf> zignetco: DEFHNDL 00> [00:00:41.334,869] <inf> zboss_osif: zbooslooop 00> [00:00:41.335,205] <inf> zignetco: DEFHNDL 00> [00:00:42.020,721] <inf> zboss_osif: zbooslooop 00> [00:00:42.021,057] <inf> zignetco: DEFHNDL 00> [00:00:42.353,576] <inf> zboss_osif: zbooslooop 00> [00:00:42.353,881] <inf> zignetco: DEFHNDL 00> [00:00:43.039,398] <inf> zboss_osif: zbooslooop 00> [00:00:43.039,703] <inf> zignetco: DEFHNDL 00> [00:00:43.372,222] <inf> zboss_osif: zbooslooop 00> [00:00:43.372,558] <inf> zignetco: DEFHNDL 00> ColCB for sched 2 complete... for led 2... 00> 00> [00:00:44.058,074] <inf> zboss_osif: zbooslooop 00> [00:00:44.058,380] <inf> zignetco: DEFHNDL 00> [00:00:44.390,899] <inf> zboss_osif: zbooslooop 00> [00:00:44.391,204] <inf> zignetco: DEFHNDL 00> [00:00:45.076,721] <inf> zboss_osif: zbooslooop 00> [00:00:45.077,026] <inf> zignetco: DEFHNDL 00> [00:00:45.409,606] <inf> zboss_osif: zbooslooop 00> [00:00:45.409,912] <inf> zignetco: DEFHNDL 00> [00:00:46.095,428] <inf> zboss_osif: zbooslooop 00> [00:00:46.095,733] <inf> zignetco: DEFHNDL 00> [00:00:46.428,222] <inf> zboss_osif: zbooslooop 00> [00:00:46.428,527] <inf> zignetco: DEFHNDL 00> [00:00:47.451,995] <inf> zboss_osif: zbooslooop 00> [00:00:47.452,301] <inf> zignetco: DEFHNDL 00> [00:00:48.460,784] <inf> zboss_osif: zbooslooop 00> [00:00:48.461,090] <inf> zignetco: DEFHNDL 00> ColCB for sched 2 complete... for led 2... 00> 00> [00:00:49.484,588] <inf> zboss_osif: zbooslooop 00> [00:00:49.484,893] <inf> zignetco: DEFHNDL 00> ColCB for sched 0 complete... for led 0... 00> 00> [00:00:49.955,810] <inf> zboss_osif: zbooslooop 00> [00:00:49.956,115] <inf> zignetco: DEFHNDL 00> [00:00:49.987,823] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:49.988,311] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 63 bytes directly 00> [00:00:49.988,922] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 5 bytes. 00> [00:00:49.989,318] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier 00> [00:00:49.991,668] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 27 bytes. 00> [00:00:50.002,349] <inf> zboss_osif: zbooslooop 00> [00:00:50.002,655] <inf> zignetco: DEFHNDL 00> [00:00:50.013,092] <inf> zboss_osif: zbooslooop 00> [00:00:50.013,397] <inf> zignetco: DEFHNDL 00> [00:00:50.499,938] <inf> zboss_osif: zbooslooop 00> [00:00:50.500,244] <inf> zignetco: DEFHNDL 00> ColCB for sched 1 complete... for led 1... 00> 00> [00:00:50.986,755] <inf> zboss_osif: zbooslooop 00> [00:00:50.987,060] <inf> zignetco: DEFHNDL 00> [00:00:51.519,531] <inf> zboss_osif: zbooslooop 00> [00:00:51.519,836] <inf> zignetco: DEFHNDL 00> [00:00:52.006,347] <inf> zboss_osif: zbooslooop 00> [00:00:52.006,652] <inf> zignetco: DEFHNDL 00> [00:00:52.539,154] <inf> zboss_osif: zbooslooop 00> [00:00:52.539,459] <inf> zignetco: DEFHNDL 00> [00:00:53.025,970] <inf> zboss_osif: zbooslooop 00> [00:00:53.026,275] <inf> zignetco: DEFHNDL 00> [00:00:53.558,776] <inf> zboss_osif: zbooslooop 00> [00:00:53.559,082] <inf> zignetco: DEFHNDL 00> ColCB for sched 2 complete... for led 2... 00> 00> [00:00:54.045,593] <inf> zboss_osif: zbooslooop 00> [00:00:54.045,898] <inf> zignetco: DEFHNDL 00> [00:00:54.578,399] <inf> zboss_osif: zbooslooop 00> [00:00:54.578,704] <inf> zignetco: DEFHNDL 00> [00:00:55.065,216] <inf> zboss_osif: zbooslooop 00> [00:00:55.065,521] <inf> zignetco: DEFHNDL 00> [00:00:55.598,052] <inf> zboss_osif: zbooslooop 00> [00:00:55.598,358] <inf> zignetco: DEFHNDL 00> [00:00:56.084,869] <inf> zboss_osif: zbooslooop 00> [00:00:56.085,174] <inf> zignetco: DEFHNDL 00> [00:00:56.617,675] <inf> zboss_osif: zbooslooop 00> [00:00:56.617,980] <inf> zignetco: DEFHNDL 00> [00:00:57.104,492] <inf> zboss_osif: zbooslooop 00> [00:00:57.104,797] <inf> zignetco: DEFHNDL 00> [00:00:57.637,298] <inf> zboss_osif: zbooslooop 00> [00:00:57.637,603] <inf> zignetco: DEFHNDL 00> [00:00:58.124,114] <inf> zboss_osif: zbooslooop 00> [00:00:58.124,420] <inf> zignetco: DEFHNDL 00> ColCB for sched 2 complete... for led 2... 00> 00> [00:00:58.656,921] <inf> zboss_osif: zbooslooop 00> [00:00:58.657,226] <inf> zignetco: DEFHNDL 00> [00:00:59.143,737] <inf> zboss_osif: zbooslooop 00> [00:00:59.144,042] <inf> zignetco: DEFHNDL 00> [00:00:59.676,544] <inf> zboss_osif: zbooslooop 00> [00:00:59.676,879] <inf> zignetco: DEFHNDL 00> [00:01:00.163,391] <inf> zboss_osif: zbooslooop 00> [00:01:00.163,696] <inf> zignetco: DEFHNDL 00> [00:01:00.696,228] <inf> zboss_osif: zbooslooop 00> [00:01:00.696,533] <inf> zignetco: DEFHNDL 00> [00:01:01.183,013] <inf> zboss_osif: zbooslooop 00> [00:01:01.183,319] <inf> zignetco: DEFHNDL 00> [00:01:01.715,789] <inf> zboss_osif: zbooslooop 00> [00:01:01.716,094] <inf> zignetco: DEFHNDL 00> [00:01:02.739,562] <inf> zboss_osif: zbooslooop 00> [00:01:02.739,868] <inf> zignetco: DEFHNDL 00> ColCB for sched 2 complete... for led 2... 00> 00> [00:01:03.748,352] <inf> zboss_osif: zbooslooop 00> [00:01:03.748,657] <inf> zignetco: DEFHNDL 00> [00:01:04.772,155] <inf> zboss_osif: zbooslooop 00> [00:01:04.772,460] <inf> zignetco: DEFHNDL 00> [00:01:05.044,372] <inf> zboss_osif: zbooslooop 00> [00:01:05.044,677] <inf> zignetco: DEFHNDL 00> [00:01:05.076,385] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:01:05.076,843] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 63 bytes directly 00> [00:01:05.077,453] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 5 bytes. 00> [00:01:05.077,850] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier 00> [00:01:05.079,864] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 27 bytes. 00> [00:01:05.090,545] <inf> zboss_osif: zbooslooop 00> [00:01:05.090,850] <inf> zignetco: DEFHNDL 00> [00:01:05.101,287] <inf> zboss_osif: zbooslooop 00> [00:01:05.101,593] <inf> zignetco: DEFHNDL 00> [00:01:05.787,139] <inf> zboss_osif: zbooslooop 00> [00:01:05.787,445] <inf> zignetco: DEFHNDL 00> [00:01:06.073,944] <inf> zboss_osif: zbooslooop 00> [00:01:06.074,249] <inf> zignetco: DEFHNDL 00> [00:01:06.805,755] <inf> zboss_osif: zbooslooop 00> [00:01:06.806,060] <inf> zignetco: DEFHNDL 00> [00:01:07.092,559] <inf> zboss_osif: zbooslooop 00> [00:01:07.092,864] <inf> zignetco: DEFHNDL 00> [00:01:07.644,195] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 30 bytes. 00> [00:01:07.644,653] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:01:07.645,111] <err> os: ***** USAGE FAULT ***** 00> [00:01:07.645,385] <err> os: Stack overflow (context area not valid) 00> [00:01:07.645,690] <err> os: r0/a1: 0x00000000 r1/a2: 0x00000000 r2/a3: 0x00000000 00> [00:01:07.646,057] <err> os: r3/a4: 0x00000000 r12/ip: 0x0000005b r14/lr: 0x0000005b 00> [00:01:07.646,423] <err> os: xpsr: 0x00000400 00> [00:01:07.646,667] <err> os: s[ 0]: 0x00000000 s[ 1]: 0x00000000 s[ 2]: 0x00000000 s[ 3]: 0x00000000 00> [00:01:07.647,125] <err> os: s[ 4]: 0x00000000 s[ 5]: 0x00000000 s[ 6]: 0x00000000 s[ 7]: 0x00000000 00> [00:01:07.647,583] <err> os: s[ 8]: 0x00000000 s[ 9]: 0x00000000 s[10]: 0x00000000 s[11]: 0x00000000 00> [00:01:07.648,040] <err> os: s[12]: 0x00000000 s[13]: 0x00000000 s[14]: 0x00000000 s[15]: 0x00000000 00> [00:01:07.648,529] <err> os: fpscr: 0x00000000 00> [00:01:07.648,773] <err> os: Faulting instruction address (r15/pc): 0x0004a021 00> [00:01:07.649,078] <err> os: >>> ZEPHYR FATAL ERROR 2: Stack overflow on CPU 0 00> [00:01:07.649,414] <err> os: Current thread: 0x20000d80 (unknown) 00> [00:01:07.659,698] [1;31m<err> fatal_error: Resetting system 00> [00:00:00.253,845] <dbg> nrf5340_outoflow.remoteproc_mgr_boot: Network MCU released. 00> [00:00:00.260,467] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:00.260,925] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 4 bytes directly 00> [00:00:00.261,444] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 8 bytes. 00> [00:00:00.261,840] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier 00> [00:00:00.262,298] <inf> ieee802154_nrf5: nRF5 802154 radio initialized 00> [00:00:00.262,603] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:00.263,061] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 5 bytes directly 00> [00:00:00.263,549] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 4 bytes. 00> [00:00:00.263,946] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier 00> [00:00:00.264,404] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:00.264,831] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 5 bytes directly 00> [00:00:00.270,324] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 4 bytes. 00> [00:00:00.270,721] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier 00> [00:00:00.301,849] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_lock_before_request: Locking response notifier 00> [00:00:00.302,307] <dbg> spinel_ipc_backend.nrf_802154_spinel_encoded_packet_send: Sending 4 bytes directly 00> [00:00:00.302,856] <dbg> spinel_ipc_backend.endpoint_cb: PSYHo message of 5 bytes. 00> [00:00:00.303,222] <dbg> spinel_ipc_backend_rsp_ntf.nrf_802154_spinel_response_notifier_property_await: Unlockling response notifier
