Stack overflow when provisioning mesh nodes

[susenka]

Good evening,

I have recently purchased an nRF52 development kit which I would like to use for my project. Currenty, I would like to provision external devices using this board, howerer, I cant seem to succeed in getting the provisioning process to work with the default unmodified example from nrf5 connect sdk. I am using the latest sdk and toolchain. I attach a copy of my log below. I have done some debugging using vscode and the program fails on this line:

/* Add Application Key */
err = bt_mesh_cfg_cli_app_key_add(net_idx, node->addr, net_idx, app_idx, app_key, &status);
if (err || status)
{
	printk("Failed to add app-key (err %d status %d)\n", err, status);
	return;
}

Log:

*** Booting nRF Connect SDK v2.9.0-7787b2649840 ***
*** Using Zephyr OS v3.7.99-1f8f3dc29142 ***
Initializing...
[00:00:00.007,324] <inf> fs_nvs: 2 Sectors of 4096 bytes
[00:00:00.007,324] <inf> fs_nvs: alloc wra: 0, ef0
[00:00:00.007,354] <inf> fs_nvs: data wra: 0, 1d0
[00:00:00.007,446] <inf> bt_sdc_hci_driver: SoftDevice Controller build revision: 
                                            2d 79 a1 c8 6a 40 b7 3c  f6 74 f9 0b 22 d3 c4 80 |-y..j@.< .t.."...
                                            74 72 82 ba                                      |tr..             
[00:00:00.009,948] <inf> bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)
[00:00:00.009,979] <inf> bt_hci_core: HW Variant: nRF52x (0x0002)
[00:00:00.010,009] <inf> bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 45.41337 Build 3074452168
[00:00:00.010,223] <inf> bt_hci_core: No ID address. App must call settings_load()
Bluetooth initialized
[00:00:00.010,284] <dbg> bt_mesh_health_cli: health_cli_init: primary 1
Mesh initialized
Loading stored settings
[00:00:00.423,156] <dbg> bt_mesh_access: mod_set: Decoded mod_key 0x0002 as elem_idx 0 mod_idx 2
[00:00:00.423,217] <dbg> bt_mesh_access: mod_set_bind: val
                                         00 00                                            |..               
[00:00:00.423,217] <dbg> bt_mesh_access: mod_set_bind: Decoded 1 bound keys for model
[00:00:00.423,400] <dbg> bt_mesh_settings: bt_mesh_settings_set: val
                                           06 00 00                                         |...              
[00:00:00.423,431] <dbg> bt_mesh_net: seq_set: Sequence Number 0x00007f
[00:00:00.423,645] <dbg> bt_mesh_settings: bt_mesh_settings_set: val
                                           00 00 00 00 00                                   |.....            
[00:00:00.423,675] <dbg> bt_mesh_net: iv_set: IV Index 0x0000 (IV Update Flag 0) duration 0 hours
[00:00:00.423,950] <dbg> bt_mesh_settings: bt_mesh_settings_set: val
                                           01 00 51 81 7e 78 0a 2c  c4 2c 78 95 70 d9 88 a7 |..Q.~x., .,x.p...
                                           eb b5                                            |..               
[00:00:00.423,950] <dbg> bt_mesh_access: bt_mesh_comp_provision: addr 0x0001 elem_count 1
[00:00:00.423,980] <dbg> bt_mesh_access: bt_mesh_comp_provision: addr 0x0001 mod_count 3 vnd_mod_count 0
[00:00:00.424,011] <dbg> bt_mesh_net: net_set: Provisioned with primary address 0x0001
[00:00:00.424,041] <dbg> bt_mesh_net: net_set: Recovered DevKey 51817e780a2cc42c789570d988a7ebb5
[00:00:00.424,377] <dbg> bt_mesh_settings: bt_mesh_settings_set: val
                                           00 00 00 ef 25 32 55 dc  cf 31 d5 d8 67 6f 26 66 |....%2U. .1..go&f
                                           a9 bb 3e 00 00 00 00 00  00 00 00 00 00 00 00 00 |..>..... ........
                                           00 00 00                                         |...              
[00:00:00.426,177] <dbg> bt_mesh_settings: bt_mesh_settings_set: val
                                           00 e7 2e 7c 63 70 11 c5  7e 4e 43 9f 88 56 d4 27 |...|cp.. ~NC..V.'
                                           c0 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00 |........ ........
                                           00                                               |.                
[00:00:00.434,356] <dbg> bt_mesh_settings: bt_mesh_settings_set: val
                                           00 e7 2e 7c 63 70 11 c5  7e 4e 43 9f 88 56 d4 27 |...|cp.. ~NC..V.'
                                           c0 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00 |........ ........
                                           00                                               |.                
[00:00:00.434,814] <dbg> bt_mesh_settings: bt_mesh_settings_set: val
                                           00 00 00 ef 25 32 55 dc  cf 31 d5 d8 67 6f 26 66 |....%2U. .1..go&f
                                           a9 bb 3e 00 00 00 00 00  00 00 00 00 00 00 00 00 |..>..... ........
                                           00 00 00                                         |...              
[00:00:00.435,058] <dbg> bt_mesh_settings: bt_mesh_settings_set: val
                                           00 00 01 01 dd dd 00 00  00 00 00 00 00 00 00 00 |........ ........
                                           00 00 00 00 51 81 7e 78  0a 2c c4 2c 78 95 70 d9 |....Q.~x .,.,x.p.
                                           88 a7 eb b5                                      |....             
[00:00:00.435,577] <dbg> bt_mesh_settings: bt_mesh_settings_set: val
                                           00 00 00 00 00 01 00                             |.......          
[00:00:00.436,157] <inf> bt_hci_core: Identity: C8:72:BA:38:85:E4 (random)
[00:00:00.436,187] <inf> bt_hci_core: HCI: version 6.0 (0x0e) revision 0x106b, manufacturer 0x0059
[00:00:00.436,218] <inf> bt_hci_core: LMP: version 6.0 (0x0e) subver 0x106b
Using stored CDB
[00:00:00.439,514] <inf> bt_mesh_main: Primary Element: 0x0001
[00:00:00.439,514] <dbg> bt_mesh_main: bt_mesh_provision: net_idx 0x0000 flags 0x00 iv_index 0x0000
Using stored settings
Waiting for unprovisioned beacon...
Device dc234e37efea60006164657777393261 detected, press button 1 to provision.
Provisioning dc234e37efea60006164657777393261
Waiting for node to be added...
[00:00:10.173,248] <dbg> bt_mesh_settings: bt_mesh_settings_store_schedule: Waiting 0 ms vs rem 0 ms
[00:00:10.173,339] <dbg> bt_mesh_settings: store_pending: 
Added node 0x0002
Configuring node 0x0002...
[00:00:10.174,560] <dbg> bt_mesh_access: bt_mesh_access_send: net_idx 0x0000 app_idx 0xfffd dst 0x0002
[00:00:10.174,621] <dbg> bt_mesh_access: bt_mesh_access_send: len 20: 00000000ef253255dccf31d5d8676f2666a9bb3e
[00:00:10.174,652] <dbg> bt_mesh_transport: bt_mesh_trans_send: net_idx 0x0000 app_idx 0xfffd dst 0x0002
[00:00:10.174,743] <dbg> bt_mesh_transport: bt_mesh_trans_send: len 20: 00000000ef253255dccf31d5d8676f2666a9bb3e
[00:00:10.174,835] <dbg> bt_mesh_transport: send_seg: src 0x0001 dst 0x0002 app_idx 0xfffd aszmic 0 sdu_len 24
[00:00:10.174,865] <dbg> bt_mesh_transport: send_seg: SeqZero 0x007f (segs: 2)
[00:00:10.174,926] <dbg> bt_mesh_transport: send_seg: seg 0: e5b09f9d4bba08329d19181a
[00:00:10.174,987] <dbg> bt_mesh_transport: send_seg: seg 1: f7e359505f2e60485f8c3520
[00:00:10.174,987] <dbg> bt_mesh_transport: seg_tx_send_unacked: SeqZero: 0x007f Attempts: 3
[00:00:10.175,018] <dbg> bt_mesh_transport: seg_tx_send_unacked: Sending 0/1
[00:00:10.175,048] <dbg> bt_mesh_net: bt_mesh_net_send: src 0x0001 dst 0x0002 len 16 headroom 9 tailroom 4
[00:00:10.175,079] <dbg> bt_mesh_net: bt_mesh_net_send: Payload len 16: 8001fc01e5b09f9d4bba08329d19181a
[00:00:10.175,109] <dbg> bt_mesh_net: bt_mesh_net_send: Seq 0x00007f
[00:00:10.175,140] <dbg> bt_mesh_net: net_header_encode: src 0x0001 dst 0x0002 ctl 0 seq 0x00007f
[00:00:10.175,140] <dbg> bt_mesh_settings: bt_mesh_settings_store_schedule: Waiting 0 ms vs rem 0 ms
[00:00:10.180,328] <err> os: ***** MPU FAULT *****
[00:00:10.180,328] <err> os:   Stacking error (context area might be not valid)
[00:00:10.180,328] <err> os:   Data Access Violation
[00:00:10.180,328] <err> os:   MMFAR Address: 0x20006578
[00:00:10.180,358] <err> os: r0/a1:  0x6181c202  r1/a2:  0x783a4e46  r2/a3:  0x0c8b61c2
[00:00:10.180,389] <err> os: r3/a4:  0x00000007 r12/ip:  0x0000000e r14/lr:  0x20006728
[00:00:10.180,389] <err> os:  xpsr:  0x21000000
[00:00:10.180,389] <err> os: Faulting instruction address (r15/pc): 0x00038688
[00:00:10.180,450] <err> os: >>> ZEPHYR FATAL ERROR 2: Stack overflow on CPU 0
[00:00:10.180,480] <err> os: Current thread: 0x20003280 (BT MESH WQ)
[00:00:10.412,597] <err> os: Halting system

Thanks for any help.

Kind regards,

Viktor

[Elfving]

Hi Viktor,

I have recently purchased an nRF52 development kit which I would like to use for my project. Currenty, I would like to provision external devices using this board, howerer, I cant seem to succeed in getting the provisioning process to work with the default unmodified example from nrf5 connect sdk.

I assume you are then doing something on the cli that makes this happen. Could you show me what?

What sample is this?

Does increasing the stack size help? Eg.

CONFIG_MAIN_STACK_SIZE

CONFIG_SYSTEM_WORKQUEUE_STACK_SIZE

Regards,

Elfving

[susenka]

Hello Elfving,

I am flashing the application using vscode and nrf connect toolchain as explained in the official video series.

https://github.com/zephyrproject-rtos/zephyr/tree/main/samples/bluetooth/mesh_provisioner - this is the sample i am using.

I tried setting the options as such, but the program is ending in same kernel panic error.

CONFIG_MAIN_STACK_SIZE=4096
CONFIG_SYSTEM_WORKQUEUE_STACK_SIZE=4096

Regards,

Viktor

[Elfving]

And could you show me what you are writing to provision it?

[susenka]

I think there is some miscommunication, I am having problem with the provisioner while provisioning other devices. The sample I am flashing should serve as a provisoner for other devices or?

[Elfving]

Ah you are right, sorry about that. I am not familiar with all the samples that comes directly from zephyr, like this one. I assumed it worked a bit like the mesh shell.

When you say you are using the latest SDK and toolchain, you mean 2.9? Just want to make sure you're not using the main branch.

What are you provisioning? Do you see the same thing when trying to provision a default sample?

Regards,

Elfving