Mesh provisioner stuck, compair fail?

[Wols]

Hi Nordic team,

I am tring to make a BLE mesh net, I use two promicro(nrf52840), one for mesh_provisioner_example, one for mesh_on_off_app_example.

But mesh_provisioner_example will stuck, how can I fix this?

Due to easy debug, I add some log in code, also I remove OOB in mesh_on_off_app_example

static const struct bt_mesh_prov prov = {
	.uuid = dev_uuid,
	// .output_size = 6,
	// .output_actions = (BT_MESH_DISPLAY_NUMBER | BT_MESH_DISPLAY_STRING),
	// .output_number = output_number,
	// .output_string = output_string,
	.complete = prov_complete,
	.reset = prov_reset,
};

Here is node log(mesh_on_off_app_example)，machine still alive.

*** Booting nRF Connect SDK v3.1.0-6c6e5b32496e ***
*** Using Zephyr OS v4.1.99-1612683d4010 ***                                                                                                            
Initializing...                                                                                                                                         
[00:00:00.012,573] <inf> fs_nvs: 3 Sectors of 4096 bytes                                                                                                
[00:00:00.012,573] <inf> fs_nvs: alloc wra: 0, e88                                                                                                      
[00:00:00.012,603] <inf> fs_nvs: data wra: 0, 20c                                                                                                       
[00:00:00.013,427] <inf> bt_sdc_hci_driver: SoftDevice Controller build revision:                                                                       
                                            fc de 41 eb a2 d1 42 24  00 b5 f8 57 9f ac 9d 9e |..A...B$ ...W....                                         
                                            aa c9 b4 34                                      |...4                                                      
[00:00:00.017,456] <inf> bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)                                                                        
[00:00:00.017,486] <inf> bt_hci_core: HW Variant: nRF52x (0x0002)                                                                                       
[00:00:00.017,517] <inf> bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 252.16862 Build 1121034987                                 
[00:00:00.017,883] <inf> bt_hci_core: No ID address. App must call settings_load()                                                                      
Bluetooth initialized                                                                                                                                   
[00:00:00.154,296] <inf> bt_hci_core: HCI transport: SDC                                                                                                
[00:00:00.154,388] <inf> bt_hci_core: Identity: C7:D6:01:06:B1:FA (random)                                                                              
[00:00:00.154,418] <inf> bt_hci_core: HCI: version 6.1 (0x0f) revision 0x1069, manufacturer 0x0059                                                      
[00:00:00.154,479] <inf> bt_hci_core: LMP: version 6.1 (0x0f) subver 0x1069                                                                             
[00:00:00.162,078] <inf> bt_mesh_provisionee: Device UUID: fab10601-d6c7-0000-0000-000000000000                                                         
Mesh initialized                                                                                                                                        
[00:00:10.777,191] <dbg> bt_mesh_provisionee: prov_invite: Attention Duration: 0 seconds                                                                
[00:00:12.181,152] <dbg> bt_mesh_provisionee: prov_start: Algorithm:   0x01                                                                             
[00:00:12.181,182] <dbg> bt_mesh_provisionee: prov_start: Public Key:  0x00                                                                             
[00:00:12.181,213] <dbg> bt_mesh_provisionee: prov_start: Auth Method: 0x00                                                                             
[00:00:12.181,213] <dbg> bt_mesh_provisionee: prov_start: Auth Action: 0x00                                                                             
[00:00:12.181,243] <dbg> bt_mesh_provisionee: prov_start: Auth Size:   0x00                                                                             
[00:00:12.358,337] <dbg> bt_mesh_provisionee: prov_pub_key: Remote Public Key: cefe4522223ebb1a9c1b110ae021a5d94d06cfa327b88094e22757b59b07c5198d8d7d4bb
[00:00:12.386,901] <dbg> bt_mesh_provisionee: prov_dh_key_gen: DHkey: 0bc7864542365a5cfb003e6cf616b895cae3616f3fbcf9b64a4a0bc0bde17b0c                  
[00:00:12.387,023] <dbg> bt_mesh_provisionee: send_pub_key: Local Public Key: 27dcacf75cd701006dcabe49b24f7bfe6f10b6cb8d352713d84ea9201514541f2dfc92f9bd
[00:00:13.345,062] <dbg> bt_mesh_provisionee: prov_confirm: Remote Confirm: 6cfeb7113e6ac6b732d2f3636a722847c817e7aaa12c231944b0bf06ed382ccb            
[00:00:13.345,153] <dbg> bt_mesh_provisionee: send_confirm: ConfInputs[0]   0004000300000000000000000100000000cefe4522223ebb1a9c1b110ae021a5            
[00:00:13.345,245] <dbg> bt_mesh_provisionee: send_confirm: ConfInputs[32]  d94d06cfa327b88094e22757b59b07c5198d8d7d4bad5cf1c2138afceb1e8a91            
[00:00:13.345,306] <dbg> bt_mesh_provisionee: send_confirm: ConfInputs[64]  20938fac91c768ac7b22b54e95b0aa62fb27dcacf75cd701006dcabe49b24f7b            
[00:00:13.345,367] <dbg> bt_mesh_provisionee: send_confirm: ConfInputs[96]  fe6f10b6cb8d352713d84ea9201514541f2dfc92f9b6d49f21ce543eeec763ff            
[00:00:13.345,428] <dbg> bt_mesh_provisionee: send_confirm: ConfInputs[128] b9a30ae5846f702c5f8ea2345d3246ad0d                                          
[00:00:13.346,099] <dbg> bt_mesh_provisionee: send_confirm: ConfirmationSalt: fdf1c74eacb17beb325dbbf9b7dbf24d97386d569c241043d0afc54a1ca8020d          
[00:00:13.346,160] <dbg> bt_mesh_provisionee: send_confirm: AuthValue  0000000000000000000000000000000000000000000000000000000000000000                 
[00:00:13.347,351] <dbg> bt_mesh_provisionee: send_confirm: ConfirmationKey: f1bace7116e868b7a32f31a94c21aed2d24c51b8ee22fb9ccbdba76e116e7e9f           
[00:00:13.347,595] <dbg> bt_mesh_provisionee: send_confirm: LocalRandom: 1030ac8f4ea74114b1b80aa0a3a320e2a1c98fc9dc7a7ec4e14bbda3d444a308               
[00:00:14.299,468] <dbg> bt_mesh_provisionee: prov_random: Remote Random: b7e2d87da92fc4bb7a7a3b42f6004ec40af45e06f09b5377333e4c923ec2927f              
[00:00:14.300,659] <dbg> bt_mesh_provisionee: prov_random: ProvisioningSalt: 93e0b98aa3946283ddffc7b4a552aa58                                           
[00:00:15.207,916] <dbg> bt_mesh_provisionee: prov_data:                                                                                                
[00:00:15.209,716] <dbg> bt_mesh_provisionee: prov_data: Nonce: 74a69a9b5c0a1d7e1888deb1f3                                                              
[00:00:15.210,876] <dbg> bt_mesh_provisionee: prov_data: net_idx 0 iv_index 0x00000000, addr 0x0002                                                     
[00:00:15.211,090] <inf> bt_mesh_main: Primary Element: 0x0002                                                                                          
[00:00:15.211,120] <dbg> bt_mesh_main: bt_mesh_provision: net_idx 0x0000 flags 0x00 iv_index 0x0000                                                     
provisioning complete for net_idx 0x0000 addr 0x0002                                                                                                    
button_press_cnt 0x01 onoff_state 0x01                                                                                                                  
Button press worker triggered.       

Here is provisioner log, this machine is stuck here.

*** Booting nRF Connect SDK v3.1.0-6c6e5b32496e ***
*** Using Zephyr OS v4.1.99-1612683d4010 ***
Initializing...
[00:00:00.008,666] <inf> fs_nvs: 8 Sectors of 4096 bytes
[00:00:00.008,666] <inf> fs_nvs: alloc wra: 0, 9e8
[00:00:00.008,666] <inf> fs_nvs: data wra: 0, 950
[00:00:00.009,277] <inf> bt_sdc_hci_driver: SoftDevice Controller build revision: 
                                            fc de 41 eb a2 d1 42 24  00 b5 f8 57 9f ac 9d 9e |..A...B$ ...W....
                                            aa c9 b4 34                                      |...4             
[00:00:00.014,617] <inf> bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)
[00:00:00.014,648] <inf> bt_hci_core: HW Variant: nRF52x (0x0002)             
[00:00:00.014,678] <inf> bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 252.16862 Build 1121034987
[00:00:00.015,167] <inf> bt_hci_core: No ID address. App must call settings_load()
Bluetooth initialized
Mesh initialized
Loading stored settings
[00:00:00.159,667] <inf> bt_hci_core: HCI transport: SDC
[00:00:00.159,759] <inf> bt_hci_core: Identity: E9:B3:8F:AE:D4:94 (random)
[00:00:00.159,790] <inf> bt_hci_core: HCI: version 6.1 (0x0f) revision 0x1069, manufacturer 0x0059
[00:00:00.159,820] <inf> bt_hci_core: LMP: version 6.1 (0x0f) subver 0x1069
✅ prov_complete callback! net_idx=0x0000, addr=0x0001
   Setting node_addr from prov_complete
Using stored CDB
[00:00:00.175,170] <inf> bt_mesh_main: Primary Element: 0x0001                                                               
[00:00:00.175,201] <dbg> bt_mesh_main: bt_mesh_provision: net_idx 0x0000 flags 0x00 iv_index 0x0000                          
Using stored settings                                                                                                        
📡 Unprovisioned beacon: fab10601d6c700000000000000000000                                                                    
📡 Unprovisioned beacon: fab10601d6c700000000000000000000                                                                    
📡 Unprovisioned beacon: fab10601d6c700000000000000000000                                                                    
📍 Button IRQ: pin_logic = 1                                                                                                 
⬇️  BUTTON PRESSED - Starting 5-second timer                                                                                  
📍 Button IRQ: pin_logic = 0                                                                                                 
BTN release                                                                                                                  
BTN pair logic start                                                                                                         
Waiting for unprovisioned beacon...                                                                                          
📡 Unprovisioned beacon: fab10601d6c700000000000000000000                                                                    
Device fab10601d6c700000000000000000000 detected, starting provisioning...                                                   
[00:00:06.312,469] <dbg> bt_mesh_provisioner: link_open: Provisioning 00000000-0000-0000-0000-c7d60106b1fa                   
Provisioning in progress... waiting for completion signal.                                                                   
[00:00:06.382,080] <dbg> bt_mesh_provisioner: send_invite:                                                                   
[00:00:07.114,624] <dbg> bt_mesh_provisioner: prov_capabilities: Elements:          4                                        
[00:00:07.114,654] <dbg> bt_mesh_provisioner: prov_capabilities: Algorithms:        0x03                                     
[00:00:07.114,654] <dbg> bt_mesh_provisioner: prov_capabilities: Public Key Type:   0x00                                     
[00:00:07.114,685] <dbg> bt_mesh_provisioner: prov_capabilities: Static OOB Type:   0x00                                     
[00:00:07.114,685] <dbg> bt_mesh_provisioner: prov_capabilities: Output OOB Size:   0                                        
[00:00:07.114,715] <dbg> bt_mesh_provisioner: prov_capabilities: Output OOB Action: 0x0000                                   
[00:00:07.114,746] <dbg> bt_mesh_provisioner: prov_capabilities: Input OOB Size:    0                                        
[00:00:07.114,746] <dbg> bt_mesh_provisioner: prov_capabilities: Input OOB Action:  0x0000                                   
[00:00:07.114,776] <dbg> bt_mesh_provisioner: send_start:                                                                    
[00:00:07.828,338] <dbg> bt_mesh_provisioner: send_pub_key: Local Public Key: cefe4522223ebb1a9c1b110ae021a5d94d06cfa327b880b
[00:00:08.205,261] <dbg> bt_mesh_provisioner: prov_pub_key: Remote Public Key: 27dcacf75cd701006dcabe49b24f7bfe6f10b6cb8d352d
[00:00:08.233,459] <dbg> bt_mesh_provisioner: prov_dh_key_gen: DHkey: 0bc7864542365a5cfb003e6cf616b895cae3616f3fbcf9b64a4a0bc
[00:00:08.233,520] <dbg> bt_mesh_provisioner: send_confirm: ConfInputs[0]   0004000300000000000000000100000000cefe4522223ebb5
[00:00:08.233,581] <dbg> bt_mesh_provisioner: send_confirm: ConfInputs[32]  d94d06cfa327b88094e22757b59b07c5198d8d7d4bad5cf11
[00:00:08.233,642] <dbg> bt_mesh_provisioner: send_confirm: ConfInputs[64]  20938fac91c768ac7b22b54e95b0aa62fb27dcacf75cd701b
[00:00:08.233,734] <dbg> bt_mesh_provisioner: send_confirm: ConfInputs[96]  fe6f10b6cb8d352713d84ea9201514541f2dfc92f9b6d49ff
[00:00:08.233,795] <dbg> bt_mesh_provisioner: send_confirm: ConfInputs[128] b9a30ae5846f702c5f8ea2345d3246ad0d               
[00:00:08.234,405] <dbg> bt_mesh_provisioner: send_confirm: ConfirmationSalt: fdf1c74eacb17beb325dbbf9b7dbf24d97386d569c2410d
[00:00:08.234,497] <dbg> bt_mesh_provisioner: send_confirm: AuthValue  000000000000000000000000000000000000000000000000000000
[00:00:08.235,626] <dbg> bt_mesh_provisioner: send_confirm: ConfirmationKey: f1bace7116e868b7a32f31a94c21aed2d24c51b8ee22fb9f
[00:00:08.235,900] <dbg> bt_mesh_provisioner: send_confirm: LocalRandom: b7e2d87da92fc4bb7a7a3b42f6004ec40af45e06f09b5377333f
[00:00:09.148,010] <dbg> bt_mesh_provisioner: prov_confirm: Remote Confirm: 8c966f4c2baeffcbf46dc9a097bc5546ebedcb9b937719f8a
[00:00:10.101,715] <dbg> bt_mesh_provisioner: prov_random: Remote Random: 1030ac8f4ea74114b1b80aa0a3a320e2a1c98fc9dc7a7ec4e18
[00:00:10.102,844] <dbg> bt_mesh_provisioner: prov_random: ProvisioningSalt: 93e0b98aa3946283ddffc7b4a552aa58                
[00:00:10.104,644] <dbg> bt_mesh_provisioner: send_prov_data: Nonce: 74a69a9b5c0a1d7e1888deb1f3                              
[00:00:10.117,645] <dbg> bt_mesh_provisioner: send_prov_data: net_idx 0, iv_index 0x00000000, addr 0x0002     

[Amanda Hsieh]

Hi, 

Are you using https://github.com/nrfconnect/sdk-zephyr/tree/ncs-v3.1.0/samples/bluetooth/mesh_provisioner and https://github.com/nrfconnect/sdk-zephyr/tree/ncs-v3.1.0/samples/bluetooth/mesh? I cannot reproduce the issues with those two examples on nRF52840DK. Not sure what you mean by the mesh_provisioner_example and mesh_on_off_app_example, and where to access them. Please test and refer to those two unmodified samples.

Regards,
Amanda H.  

[Wols]

Hi Amanda,
https://github.com/zephyrproject-rtos/zephyr/tree/main/samples/boards/nordic/mesh/onoff-app and https://github.com/nrfconnect/sdk-zephyr/tree/ncs-v3.1.0/samples/bluetooth/mesh_provisioner

If you would't mind, here is my part of project copy.
You can change compile provisioner or provisionee by prj.conf->CONFIG_APP_IS_PROVISIONER=y
prj_copy.zip

[Wols]

Here is a video record, my provisioner is stuck.

[Amanda Hsieh]

Could you test with https://github.com/nrfconnect/sdk-zephyr/tree/ncs-v3.1.0/samples/boards/nordic/mesh/onoff-app?

I still cannot reproduce the issue with nRF52840DKs.  

[Wols]

This is my on off .c file.

Fullscreen 0602.main_on_off_app.c Download

/* main.c - Application main entry point */

/*
 * Copyright (c) 2017 Intel Corporation
 *
 * SPDX-License-Identifier: Apache-2.0
 */

/*
 * This application is specific to the Nordic nRF52840-PDK board.
 *
 * It supports the 4 buttons and 4 LEDs as mesh clients and servers.
 *
 * Prior to provisioning, a button inverts the state of the
 * corresponding LED.
 *
 * The unprovisioned beacon uses the device address set by Nordic
 * in the FICR as its UUID and is presumed unique.
 *
 * Button and LED 1 are in the root node.
 * The 3 remaining button/LED pairs are in element 1 through 3.
 * Assuming the provisioner assigns 0x100 to the root node,
 * the secondary elements will appear at 0x101, 0x102 and 0x103.
 *
 * It's anticipated that after provisioning, the button clients would
 * be configured to publish and the LED servers to subscribe.
 *
 * If a LED server is provided with a publish address, it will
 * also publish its status on a state change.
 *
 * Messages from a button to its corresponding LED are ignored as
 * the LED's state has already been changed locally by the button client.
 *
 * The buttons are debounced at a nominal 250ms. That value can be
 * changed as needed.
 *
 */

#include <zephyr/sys/printk.h>
#include <zephyr/settings/settings.h>
#include <zephyr/sys/byteorder.h>
#include <zephyr/device.h>
#include <zephyr/drivers/gpio.h>
#include <zephyr/bluetooth/bluetooth.h>
#include <zephyr/bluetooth/conn.h>
#include <zephyr/bluetooth/l2cap.h>
#include <zephyr/bluetooth/hci.h>
#include <zephyr/bluetooth/mesh.h>
#include <stdio.h>
#include <zephyr/usb/usb_device.h>

#define MY_APP_CONFIG_NODE DT_PATH(my_app_config)

/* Model Operation Codes */
#define BT_MESH_MODEL_OP_GEN_ONOFF_GET		BT_MESH_MODEL_OP_2(0x82, 0x01)
#define BT_MESH_MODEL_OP_GEN_ONOFF_SET		BT_MESH_MODEL_OP_2(0x82, 0x02)
#define BT_MESH_MODEL_OP_GEN_ONOFF_SET_UNACK	BT_MESH_MODEL_OP_2(0x82, 0x03)
#define BT_MESH_MODEL_OP_GEN_ONOFF_STATUS	BT_MESH_MODEL_OP_2(0x82, 0x04)

static int gen_onoff_set(const struct bt_mesh_model *model,
			 struct bt_mesh_msg_ctx *ctx,
			 struct net_buf_simple *buf);

static int gen_onoff_set_unack(const struct bt_mesh_model *model,
			       struct bt_mesh_msg_ctx *ctx,
			       struct net_buf_simple *buf);

static int gen_onoff_get(const struct bt_mesh_model *model,
			 struct bt_mesh_msg_ctx *ctx,
			 struct net_buf_simple *buf);

static int gen_onoff_status(const struct bt_mesh_model *model,
			    struct bt_mesh_msg_ctx *ctx,
			    struct net_buf_simple *buf);

/*
 * Client Configuration Declaration
 */

static struct bt_mesh_cfg_cli cfg_cli = {
};

/*
 * Health Server Declaration
 */

static struct bt_mesh_health_srv health_srv = {
};

/*
 * Publication Declarations
 *
 * The publication messages are initialized to
 * the size of the opcode + content
 *
 * For publication, the message must be in static or global as
 * it is re-transmitted several times. This occurs
 * after the function that called bt_mesh_model_publish() has
 * exited and the stack is no longer valid.
 *
 * Note that the additional 4 bytes for the AppMIC is not needed
 * because it is added to a stack variable at the time a
 * transmission occurs.
 *
 */

BT_MESH_HEALTH_PUB_DEFINE(health_pub, 0);

BT_MESH_MODEL_PUB_DEFINE(gen_onoff_pub_srv, NULL, 2 + 2);
BT_MESH_MODEL_PUB_DEFINE(gen_onoff_pub_cli, NULL, 2 + 2);
BT_MESH_MODEL_PUB_DEFINE(gen_onoff_pub_srv_s_0, NULL, 2 + 2);
BT_MESH_MODEL_PUB_DEFINE(gen_onoff_pub_cli_s_0, NULL, 2 + 2);
BT_MESH_MODEL_PUB_DEFINE(gen_onoff_pub_srv_s_1, NULL, 2 + 2);
BT_MESH_MODEL_PUB_DEFINE(gen_onoff_pub_cli_s_1, NULL, 2 + 2);
BT_MESH_MODEL_PUB_DEFINE(gen_onoff_pub_srv_s_2, NULL, 2 + 2);
BT_MESH_MODEL_PUB_DEFINE(gen_onoff_pub_cli_s_2, NULL, 2 + 2);

/*
 * Models in an element must have unique op codes.
 *
 * The mesh stack dispatches a message to the first model in an element
 * that is also bound to an app key and supports the op code in the
 * received message.
 *
 */

/*
 * OnOff Model Server Op Dispatch Table
 *
 */

static const struct bt_mesh_model_op gen_onoff_srv_op[] = {
	{ BT_MESH_MODEL_OP_GEN_ONOFF_GET,       BT_MESH_LEN_EXACT(0), gen_onoff_get },
	{ BT_MESH_MODEL_OP_GEN_ONOFF_SET,       BT_MESH_LEN_EXACT(2), gen_onoff_set },
	{ BT_MESH_MODEL_OP_GEN_ONOFF_SET_UNACK, BT_MESH_LEN_EXACT(2), gen_onoff_set_unack },
	BT_MESH_MODEL_OP_END,
};

/*
 * OnOff Model Client Op Dispatch Table
 */

static const struct bt_mesh_model_op gen_onoff_cli_op[] = {
	{ BT_MESH_MODEL_OP_GEN_ONOFF_STATUS, BT_MESH_LEN_EXACT(1), gen_onoff_status },
	BT_MESH_MODEL_OP_END,
};

struct led_onoff_state {
	const struct gpio_dt_spec led_device;
	uint8_t current;
	uint8_t previous;
};

/*
 * Declare and Initialize Element Contexts
 * Change to select different GPIO output pins
 */

struct led_onoff_state led_onoff_states[] = {
	{ .led_device = GPIO_DT_SPEC_GET_BY_IDX(MY_APP_CONFIG_NODE, led_gpios, 0), },
	{ .led_device = GPIO_DT_SPEC_GET_BY_IDX(MY_APP_CONFIG_NODE, led_gpios, 1), },
	{ .led_device = GPIO_DT_SPEC_GET_BY_IDX(MY_APP_CONFIG_NODE, led_gpios, 2), },
	{ .led_device = GPIO_DT_SPEC_GET_BY_IDX(MY_APP_CONFIG_NODE, led_gpios, 3), },
};

/*
 *
 * Element Model Declarations
 *
 * Element 0 Root Models
 */

static const struct bt_mesh_model root_models[] = {
	BT_MESH_MODEL_CFG_SRV,
	BT_MESH_MODEL_CFG_CLI(&cfg_cli),
	BT_MESH_MODEL_HEALTH_SRV(&health_srv, &health_pub),
	BT_MESH_MODEL(BT_MESH_MODEL_ID_GEN_ONOFF_SRV, gen_onoff_srv_op,
		      &gen_onoff_pub_srv, &led_onoff_states[0]),
	BT_MESH_MODEL(BT_MESH_MODEL_ID_GEN_ONOFF_CLI, gen_onoff_cli_op,
		      &gen_onoff_pub_cli, &led_onoff_states[0]),
};

/*
 * Element 1 Models
 */

static const struct bt_mesh_model secondary_0_models[] = {
	BT_MESH_MODEL(BT_MESH_MODEL_ID_GEN_ONOFF_SRV, gen_onoff_srv_op,
		      &gen_onoff_pub_srv_s_0, &led_onoff_states[1]),
	BT_MESH_MODEL(BT_MESH_MODEL_ID_GEN_ONOFF_CLI, gen_onoff_cli_op,
		      &gen_onoff_pub_cli_s_0, &led_onoff_states[1]),
};

/*
 * Element 2 Models
 */

static const struct bt_mesh_model secondary_1_models[] = {
	BT_MESH_MODEL(BT_MESH_MODEL_ID_GEN_ONOFF_SRV, gen_onoff_srv_op,
		      &gen_onoff_pub_srv_s_1, &led_onoff_states[2]),
	BT_MESH_MODEL(BT_MESH_MODEL_ID_GEN_ONOFF_CLI, gen_onoff_cli_op,
		      &gen_onoff_pub_cli_s_1, &led_onoff_states[2]),
};

/*
 * Element 3 Models
 */

static const struct bt_mesh_model secondary_2_models[] = {
	BT_MESH_MODEL(BT_MESH_MODEL_ID_GEN_ONOFF_SRV, gen_onoff_srv_op,
		      &gen_onoff_pub_srv_s_2, &led_onoff_states[3]),
	BT_MESH_MODEL(BT_MESH_MODEL_ID_GEN_ONOFF_CLI, gen_onoff_cli_op,
		      &gen_onoff_pub_cli_s_2, &led_onoff_states[3]),
};

/*
 * Button to Client Model Assignments
 */

const struct bt_mesh_model *mod_cli_sw[] = {
		&root_models[4],
		&secondary_0_models[1],
		&secondary_1_models[1],
		&secondary_2_models[1],
};

/*
 * LED to Server Model Assignments
 */

const struct bt_mesh_model *mod_srv_sw[] = {
		&root_models[3],
		&secondary_0_models[0],
		&secondary_1_models[0],
		&secondary_2_models[0],
};

/*
 * Root and Secondary Element Declarations
 */

static const struct bt_mesh_elem elements[] = {
	BT_MESH_ELEM(0, root_models, BT_MESH_MODEL_NONE),
	BT_MESH_ELEM(0, secondary_0_models, BT_MESH_MODEL_NONE),
	BT_MESH_ELEM(0, secondary_1_models, BT_MESH_MODEL_NONE),
	BT_MESH_ELEM(0, secondary_2_models, BT_MESH_MODEL_NONE),
};

static const struct bt_mesh_comp comp = {
	.cid = BT_COMP_ID_LF,
	.elem = elements,
	.elem_count = ARRAY_SIZE(elements),
};

static const struct gpio_dt_spec sw_device[] = {
	GPIO_DT_SPEC_GET_BY_IDX(MY_APP_CONFIG_NODE, btn_gpios, 0),
	GPIO_DT_SPEC_GET_BY_IDX(MY_APP_CONFIG_NODE, btn_gpios, 1),
	GPIO_DT_SPEC_GET_BY_IDX(MY_APP_CONFIG_NODE, btn_gpios, 2),
	GPIO_DT_SPEC_GET_BY_IDX(MY_APP_CONFIG_NODE, btn_gpios, 3),
};

struct switch_data {
	uint8_t sw_num;
	uint8_t onoff_state;
	struct k_work button_work;
	struct k_timer button_timer;
};


static uint8_t button_press_cnt;
static struct switch_data sw;

static struct gpio_callback button_cb;

static uint8_t trans_id;
static uint32_t time, last_time;
static uint16_t primary_addr;
static uint16_t primary_net_idx;

/*
 * Generic OnOff Model Server Message Handlers
 *
 * Mesh Model Specification 3.1.1
 *
 */

static int gen_onoff_get(const struct bt_mesh_model *model,
			 struct bt_mesh_msg_ctx *ctx,
			 struct net_buf_simple *buf)
{
	NET_BUF_SIMPLE_DEFINE(msg, 2 + 1 + 4);
	struct led_onoff_state *onoff_state = model->rt->user_data;

	printk("addr 0x%04x onoff 0x%02x\n",
	       bt_mesh_model_elem(model)->rt->addr, onoff_state->current);
	bt_mesh_model_msg_init(&msg, BT_MESH_MODEL_OP_GEN_ONOFF_STATUS);
	net_buf_simple_add_u8(&msg, onoff_state->current);

	if (bt_mesh_model_send(model, ctx, &msg, NULL, NULL)) {
		printk("Unable to send On Off Status response\n");
	}

	return 0;
}

static int gen_onoff_set_unack(const struct bt_mesh_model *model,
			       struct bt_mesh_msg_ctx *ctx,
			       struct net_buf_simple *buf)
{
	struct net_buf_simple *msg = model->pub->msg;
	struct led_onoff_state *onoff_state = model->rt->user_data;
	int err;

	onoff_state->current = net_buf_simple_pull_u8(buf);
	printk("addr 0x%02x state 0x%02x\n",
	       bt_mesh_model_elem(model)->rt->addr, onoff_state->current);

	gpio_pin_set_dt(&onoff_state->led_device, onoff_state->current);

	/*
	 * If a server has a publish address, it is required to
	 * publish status on a state change
	 *
	 * See Mesh Profile Specification 3.7.6.1.2
	 *
	 * Only publish if there is an assigned address
	 */

	if (onoff_state->previous != onoff_state->current &&
	    model->pub->addr != BT_MESH_ADDR_UNASSIGNED) {
		printk("publish last 0x%02x cur 0x%02x\n",
		       onoff_state->previous, onoff_state->current);
		onoff_state->previous = onoff_state->current;
		bt_mesh_model_msg_init(msg,
				       BT_MESH_MODEL_OP_GEN_ONOFF_STATUS);
		net_buf_simple_add_u8(msg, onoff_state->current);
		err = bt_mesh_model_publish(model);
		if (err) {
			printk("bt_mesh_model_publish err %d\n", err);
		}
	}

	return 0;
}

static int gen_onoff_set(const struct bt_mesh_model *model,
			 struct bt_mesh_msg_ctx *ctx,
			 struct net_buf_simple *buf)
{
	printk("gen_onoff_set\n");

	(void)gen_onoff_set_unack(model, ctx, buf);
	(void)gen_onoff_get(model, ctx, buf);

	return 0;
}

static int gen_onoff_status(const struct bt_mesh_model *model,
			    struct bt_mesh_msg_ctx *ctx,
			    struct net_buf_simple *buf)
{
	uint8_t	state;

	state = net_buf_simple_pull_u8(buf);

	printk("Node 0x%04x OnOff status from 0x%04x with state 0x%02x\n",
	       bt_mesh_model_elem(model)->rt->addr, ctx->addr, state);

	return 0;
}

static int output_number(bt_mesh_output_action_t action, uint32_t number)
{
	printk("OOB Number %06u\n", number);
	return 0;
}

static int output_string(const char *str)
{
	printk("OOB String %s\n", str);
	return 0;
}

static void prov_complete(uint16_t net_idx, uint16_t addr)
{
	printk("provisioning complete for net_idx 0x%04x addr 0x%04x\n",
	       net_idx, addr);
	primary_addr = addr;
	primary_net_idx = net_idx;
}

static void prov_reset(void)
{
	bt_mesh_prov_enable(BT_MESH_PROV_ADV | BT_MESH_PROV_GATT);
}

static uint8_t dev_uuid[16] = { 0xdd, 0xdd };

#define BUTTON_DEBOUNCE_DELAY_MS 250

/*
 * Map GPIO pins to button number
 * Change to select different GPIO input pins
 */

static uint8_t pin_to_sw(uint32_t pin_pos)
{
	switch (pin_pos) {
	case BIT(DT_GPIO_PIN_BY_IDX(MY_APP_CONFIG_NODE, btn_gpios, 0)): return 0;
	case BIT(DT_GPIO_PIN_BY_IDX(MY_APP_CONFIG_NODE, btn_gpios, 1)): return 1;
	case BIT(DT_GPIO_PIN_BY_IDX(MY_APP_CONFIG_NODE, btn_gpios, 2)): return 2;
	case BIT(DT_GPIO_PIN_BY_IDX(MY_APP_CONFIG_NODE, btn_gpios, 3)): return 3;
	}
	printk("No match for GPIO pin 0x%08x\n", pin_pos);
	return 0;
}

static void button_pressed(const struct device *dev, struct gpio_callback *cb,
			   uint32_t pin_pos)
{
	/*
	 * One button press within a 1 second interval sends an on message
	 * More than one button press sends an off message
	 */

	time = k_uptime_get_32();

	/* debounce the switch */
	if (time < last_time + BUTTON_DEBOUNCE_DELAY_MS) {
		last_time = time;
		return;
	}

	if (button_press_cnt == 0U) {
		k_timer_start(&sw.button_timer, K_SECONDS(1), K_NO_WAIT);
	}

	printk("button_press_cnt 0x%02x\n", button_press_cnt);
	button_press_cnt++;

	/* The variable pin_pos is the pin position in the GPIO register,
	 * not the pin number. It's assumed that only one bit is set.
	 */

	sw.sw_num = pin_to_sw(pin_pos);
	last_time = time;
}

/*
 * Button Count Timer Worker
 */

static void button_cnt_timer(struct k_timer *work)
{
	struct switch_data *button_sw = CONTAINER_OF(work, struct switch_data, button_timer);

	button_sw->onoff_state = button_press_cnt == 1U ? 1 : 0;
	printk("button_press_cnt 0x%02x onoff_state 0x%02x\n",
	       button_press_cnt, button_sw->onoff_state);
	button_press_cnt = 0U;
	k_work_submit(&sw.button_work);
}

/*
 * Button Pressed Worker Task
 */

static void button_pressed_worker(struct k_work *work)
{
	const struct bt_mesh_model *mod_cli, *mod_srv;
	struct bt_mesh_model_pub *pub_cli, *pub_srv;
	struct switch_data *button_sw = CONTAINER_OF(work, struct switch_data, button_work);
	int err;
	uint8_t sw_idx = button_sw->sw_num;

	mod_cli = mod_cli_sw[sw_idx];
	pub_cli = mod_cli->pub;

	mod_srv = mod_srv_sw[sw_idx];
	pub_srv = mod_srv->pub;

	/* If unprovisioned, just call the set function.
	 * The intent is to have switch-like behavior
	 * prior to provisioning. Once provisioned,
	 * the button and its corresponding led are no longer
	 * associated and act independently. So, if a button is to
	 * control its associated led after provisioning, the button
	 * must be configured to either publish to the led's unicast
	 * address or a group to which the led is subscribed.
	 */

	if (primary_addr == BT_MESH_ADDR_UNASSIGNED) {
		NET_BUF_SIMPLE_DEFINE(msg, 1);
		struct bt_mesh_msg_ctx ctx = {
			.addr = sw_idx + primary_addr,
		};

		/* This is a dummy message sufficient
		 * for the led server
		 */

		net_buf_simple_add_u8(&msg, button_sw->onoff_state);
		(void)gen_onoff_set_unack(mod_srv, &ctx, &msg);
		return;
	}

	if (pub_cli->addr == BT_MESH_ADDR_UNASSIGNED) {
		return;
	}

	printk("publish to 0x%04x onoff 0x%04x sw_idx 0x%04x\n",
	       pub_cli->addr, button_sw->onoff_state, sw_idx);
	bt_mesh_model_msg_init(pub_cli->msg,
			       BT_MESH_MODEL_OP_GEN_ONOFF_SET);
	net_buf_simple_add_u8(pub_cli->msg, button_sw->onoff_state);
	net_buf_simple_add_u8(pub_cli->msg, trans_id++);
	err = bt_mesh_model_publish(mod_cli);
	if (err) {
		printk("bt_mesh_model_publish err %d\n", err);
	}
}

/* Disable OOB security for SILabs Android app */

static const struct bt_mesh_prov prov = {
	.uuid = dev_uuid,
#if 1
	.output_size = 6,
	.output_actions = (BT_MESH_DISPLAY_NUMBER | BT_MESH_DISPLAY_STRING),
	.output_number = output_number,
	.output_string = output_string,
#else
	.output_size = 0,
	.output_actions = 0,
	.output_number = 0,
#endif
	.complete = prov_complete,
	.reset = prov_reset,
};

/*
 * Bluetooth Ready Callback
 */

static void bt_ready(int err)
{
	struct bt_le_oob oob;

	if (err) {
		printk("Bluetooth init failed (err %d)\n", err);
		return;
	}

	printk("Bluetooth initialized\n");

	err = bt_mesh_init(&prov, &comp);
	if (err) {
		printk("Initializing mesh failed (err %d)\n", err);
		return;
	}

	if (IS_ENABLED(CONFIG_SETTINGS)) {
		settings_load();
	}

	/* Use identity address as device UUID */
	if (bt_le_oob_get_local(BT_ID_DEFAULT, &oob)) {
		printk("Identity Address unavailable\n");
	} else {
		memcpy(dev_uuid, oob.addr.a.val, 6);
	}

	bt_mesh_prov_enable(BT_MESH_PROV_GATT | BT_MESH_PROV_ADV);

	printk("Mesh initialized\n");
}

int main(void)
{
	int err, i;
	err = usb_enable(NULL);
    if (err != 0) {
        printk("Failed to enable USB\n");
        return 0;
    }
	printk("Initializing...\n");

	/* Initialize the button debouncer */
	last_time = k_uptime_get_32();

	/* Initialize button worker task*/
	k_work_init(&sw.button_work, button_pressed_worker);

	/* Initialize button count timer */
	k_timer_init(&sw.button_timer, button_cnt_timer, NULL);

	gpio_init_callback(&button_cb, button_pressed,
			   BIT(sw_device[0].pin) | BIT(sw_device[1].pin) |
			   BIT(sw_device[2].pin) | BIT(sw_device[3].pin));

	for (i = 0; i < ARRAY_SIZE(sw_device); i++) {
		if (!gpio_is_ready_dt(&sw_device[i])) {
			printk("SW%d GPIO controller device is not ready\n", i);
			return 0;
		}
		gpio_pin_configure_dt(&sw_device[i], GPIO_INPUT);
		gpio_pin_interrupt_configure_dt(&sw_device[i], GPIO_INT_EDGE_TO_ACTIVE);
		gpio_add_callback(sw_device[i].port, &button_cb);
	}


	/* Initialize LED's */
	for (i = 0; i < ARRAY_SIZE(led_onoff_states); i++) {
		if (!gpio_is_ready_dt(&led_onoff_states[i].led_device)) {
			printk("LED%d GPIO controller device is not ready\n", i);
			return 0;
		}
		gpio_pin_configure_dt(&led_onoff_states[i].led_device, GPIO_OUTPUT_INACTIVE);
	}

	/* Initialize the Bluetooth Subsystem */
	err = bt_enable(bt_ready);
	if (err) {
		printk("Bluetooth init failed (err %d)\n", err);
	}
	return 0;
}

And provisioner also stuck

[Wols]

[00:00:17.878,021] <inf> app_main: Waiting for node to be added...                                                                                      
[00:00:17.927,062] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:17.927,612] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:17.928,161] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:17.928,680] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:17.929,199] <dbg> bt_mesh_pb_adv: tx_work_handler: 7                                                                                             
[00:00:17.929,779] <dbg> bt_mesh_pb_adv: tx_work_handler: 8                                                                                             
[00:00:17.930,297] <dbg> bt_mesh_pb_adv: tx_work_handler: 9                                                                                             
[00:00:17.930,847] <dbg> bt_mesh_pb_adv: tx_work_handler: 10                                                                                            
[00:00:17.931,365] <dbg> bt_mesh_pb_adv: tx_work_handler: Starting retransmit timer                                                                     
[00:00:17.932,159] <dbg> bt_mesh_pb_adv: tx_work_handler: 11                                                                                            
[00:00:17.946,655] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 47ms                                                                          
[00:00:17.992,553] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x0                                                            
[00:00:17.993,347] <dbg> bt_mesh_pb_adv: gen_prov_ctl: op 0x01 len 0                                                                                    
[00:00:17.994,049] <dbg> bt_mesh_pb_adv: link_ack: len 0                                                                                                
[00:00:17.994,598] <dbg> bt_mesh_pb_adv: prov_clear_tx:                                                                                                 
[00:00:17.995,117] <dbg> bt_mesh_provisioner: send_invite:                                                                                              
[00:00:17.995,666] <dbg> bt_mesh_pb_adv: prov_clear_tx:                                                                                                 
[00:00:17.996,185] <dbg> bt_mesh_pb_adv: prov_send_adv: xact_id: 0x0 len: 2                                                                             
[00:00:17.996,887] <dbg> bt_mesh_pb_adv: prov_send_adv: seg 0 len 2: 0000                                                                               
[00:00:17.997,619] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 42ms                                                                          
[00:00:17.998,352] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:17.998,992] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:17.999,603] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:18.000,152] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:18.000,671] <dbg> bt_mesh_pb_adv: tx_work_handler: 7                                                                                             
[00:00:18.001,190] <dbg> bt_mesh_pb_adv: tx_work_handler: 8                                                                                             
[00:00:18.001,800] <dbg> bt_mesh_pb_adv: tx_work_handler: 9                                                                                             
[00:00:18.002,349] <dbg> bt_mesh_pb_adv: tx_work_handler: 10                                                                                            
[00:00:18.002,868] <dbg> bt_mesh_pb_adv: tx_work_handler: Starting retransmit timer                                                                     
[00:00:18.003,570] <dbg> bt_mesh_pb_adv: tx_work_handler: 11                                                                                            
[00:00:18.017,639] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 45ms                                                                          
[00:00:18.019,409] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x0                                                            
[00:00:18.020,172] <dbg> bt_mesh_pb_adv: gen_prov_ctl: op 0x01 len 0                                                                                    
[00:00:18.020,782] <dbg> bt_mesh_pb_adv: link_ack: len 0                                                                                                
[00:00:18.047,821] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x0                                                            
[00:00:18.048,583] <dbg> bt_mesh_pb_adv: gen_prov_ctl: op 0x01 len 0                                                                                    
[00:00:18.049,224] <dbg> bt_mesh_pb_adv: link_ack: len 0                                                                                                
[00:00:18.063,415] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:18.063,964] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:18.064,605] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:18.065,124] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:18.065,643] <dbg> bt_mesh_pb_adv: tx_work_handler: All PDUs were sent                                                                            
[00:00:18.074,951] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x0                                                            
[00:00:18.075,714] <dbg> bt_mesh_pb_adv: gen_prov_ack: len 0                                                                                            
[00:00:18.076,324] <dbg> bt_mesh_pb_adv: prov_clear_tx:                                                                                                 
[00:00:18.102,294] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x0                                                            
[00:00:18.103,057] <dbg> bt_mesh_pb_adv: gen_prov_ack: len 0                                                                                            
[00:00:18.128,387] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x0                                                            
[00:00:18.129,150] <dbg> bt_mesh_pb_adv: gen_prov_ack: len 0                                                                                            
[00:00:18.180,938] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x80                                                           
[00:00:18.181,732] <dbg> bt_mesh_pb_adv: gen_prov_start: len 12 last_seg 0 total_len 12 fcs 0xac                                                        
[00:00:18.182,556] <dbg> bt_mesh_pb_adv: prov_clear_tx:                                                                                                 
[00:00:18.183,074] <dbg> bt_mesh_pb_adv: gen_prov_ack_send: xact_id 0x80                                                                                
[00:00:18.183,807] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 33ms                                                                          
[00:00:18.184,509] <dbg> bt_mesh_provisioner: prov_capabilities: Elements:          4                                                                   
[00:00:18.185,241] <dbg> bt_mesh_provisioner: prov_capabilities: Algorithms:        0x03                                                                
[00:00:18.186,035] <dbg> bt_mesh_provisioner: prov_capabilities: Public Key Type:   0x00                                                                
[00:00:18.186,737] <dbg> bt_mesh_provisioner: prov_capabilities: Static OOB Type:   0x00                                                                
[00:00:18.187,469] <dbg> bt_mesh_provisioner: prov_capabilities: Output OOB Size:   0                                                                   
[00:00:18.188,171] <dbg> bt_mesh_provisioner: prov_capabilities: Output OOB Action: 0x0000                                                              
[00:00:18.188,903] <dbg> bt_mesh_provisioner: prov_capabilities: Input OOB Size:    0                                                                   
[00:00:18.189,666] <dbg> bt_mesh_provisioner: prov_capabilities: Input OOB Action:  0x0000                                                              
[00:00:18.190,399] <dbg> bt_mesh_provisioner: send_start:                                                                                               
[00:00:18.190,917] <dbg> bt_mesh_pb_adv: prov_clear_tx:                                                                                                 
[00:00:18.191,467] <dbg> bt_mesh_pb_adv: prov_send_adv: xact_id: 0x1 len: 6                                                                             
[00:00:18.192,108] <dbg> bt_mesh_pb_adv: prov_send_adv: seg 0 len 6: 020100000000                                                                       
[00:00:18.192,932] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 49ms                                                                          
[00:00:18.217,559] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:18.218,109] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:18.218,658] <dbg> bt_mesh_pb_adv: tx_work_handler: 2                                                                                             
[00:00:18.219,177] <dbg> bt_mesh_pb_adv: tx_work_handler: 3                                                                                             
[00:00:18.219,757] <dbg> bt_mesh_pb_adv: tx_work_handler: 4                                                                                             
[00:00:18.220,275] <dbg> bt_mesh_pb_adv: tx_work_handler: 5                                                                                             
[00:00:18.280,151] <dbg> bt_mesh_pb_adv: ack_complete: xact 0x80 complete                                                                               
[00:00:18.280,944] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 31ms                                                                          
[00:00:18.312,683] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:18.313,293] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:18.313,842] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:18.314,392] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:18.314,971] <dbg> bt_mesh_pb_adv: tx_work_handler: 7                                                                                             
[00:00:18.315,490] <dbg> bt_mesh_pb_adv: tx_work_handler: 8                                                                                             
[00:00:18.316,192] <dbg> bt_mesh_pb_adv: tx_work_handler: 9                                                                                             
[00:00:18.316,741] <dbg> bt_mesh_pb_adv: tx_work_handler: 10                                                                                            
[00:00:18.317,291] <dbg> bt_mesh_pb_adv: tx_work_handler: Starting retransmit timer                                                                     
[00:00:18.317,993] <dbg> bt_mesh_pb_adv: tx_work_handler: 11                                                                                            
[00:00:18.328,521] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 21ms                                                                          
[00:00:18.350,341] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:18.350,891] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:18.351,440] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:18.352,020] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:18.352,569] <dbg> bt_mesh_pb_adv: tx_work_handler: All PDUs were sent                                                                            
[00:00:18.367,767] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x1                                                            
[00:00:18.368,530] <dbg> bt_mesh_pb_adv: gen_prov_ack: len 0                                                                                            
[00:00:18.369,110] <dbg> bt_mesh_pb_adv: prov_clear_tx:                                                                                                 
[00:00:18.369,750] <dbg> bt_mesh_provisioner: send_pub_key: Local Public Key: 1cfa3ef905f39b91232b5c3b9361eb8f742ccd04eddbd694c9e8f8145a022eeb5b67574eab
[00:00:18.371,368] <dbg> bt_mesh_pb_adv: prov_clear_tx:                                                                                                 
[00:00:18.371,948] <dbg> bt_mesh_pb_adv: prov_send_adv: xact_id: 0x2 len: 65                                                                            
[00:00:18.372,680] <dbg> bt_mesh_pb_adv: prov_send_adv: seg 0 len 20: 031cfa3ef905f39b91232b5c3b9361eb8f742ccd                                          
[00:00:18.373,626] <dbg> bt_mesh_pb_adv: prov_send_adv: seg 1 len 23: 04eddbd694c9e8f8145a022eeb5b67574ea00d697701cf                                    
[00:00:18.374,694] <dbg> bt_mesh_pb_adv: prov_send_adv: seg 2 len 22: 2106fdee1188d0ff337448435b98962f93598a00dbdb                                      
[00:00:18.375,762] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 30ms                                                                          
[00:00:18.393,035] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x1                                                            
[00:00:18.393,798] <dbg> bt_mesh_pb_adv: gen_prov_ack: len 0                                                                                            
[00:00:18.406,555] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:18.407,104] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:18.407,653] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:18.408,172] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:18.408,691] <dbg> bt_mesh_pb_adv: tx_work_handler: 7                                                                                             
[00:00:18.409,301] <dbg> bt_mesh_pb_adv: tx_work_handler: 8                                                                                             
[00:00:18.409,881] <dbg> bt_mesh_pb_adv: tx_work_handler: 9                                                                                             
[00:00:18.410,400] <dbg> bt_mesh_pb_adv: tx_work_handler: 10                                                                                            
[00:00:18.410,949] <dbg> bt_mesh_pb_adv: tx_work_handler: 11                                                                                            
[00:00:18.421,722] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x1                                                            
[00:00:18.422,485] <dbg> bt_mesh_pb_adv: gen_prov_ack: len 0                                                                                            
[00:00:18.425,354] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 25ms                                                                          
[00:00:18.451,263] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:18.451,873] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:18.452,423] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:18.453,002] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:18.453,582] <dbg> bt_mesh_pb_adv: tx_work_handler: 7                                                                                             
[00:00:18.454,101] <dbg> bt_mesh_pb_adv: tx_work_handler: 8                                                                                             
[00:00:18.454,650] <dbg> bt_mesh_pb_adv: tx_work_handler: 9                                                                                             
[00:00:18.455,322] <dbg> bt_mesh_pb_adv: tx_work_handler: 10                                                                                            
[00:00:18.455,902] <dbg> bt_mesh_pb_adv: tx_work_handler: 11                                                                                            
[00:00:18.462,677] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 29ms                                                                          
[00:00:18.492,492] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:18.493,072] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:18.493,621] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:18.494,140] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:18.494,659] <dbg> bt_mesh_pb_adv: tx_work_handler: 7                                                                                             
[00:00:18.495,239] <dbg> bt_mesh_pb_adv: tx_work_handler: 8                                                                                             
[00:00:18.495,788] <dbg> bt_mesh_pb_adv: tx_work_handler: 9                                                                                             
[00:00:18.496,307] <dbg> bt_mesh_pb_adv: tx_work_handler: 10                                                                                            
[00:00:18.496,856] <dbg> bt_mesh_pb_adv: tx_work_handler: Starting retransmit timer                                                                     
[00:00:18.497,558] <dbg> bt_mesh_pb_adv: tx_work_handler: 11                                                                                            
[00:00:18.505,645] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 45ms                                                                          
[00:00:18.551,422] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:18.551,971] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:18.552,581] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:18.553,100] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:18.553,649] <dbg> bt_mesh_pb_adv: tx_work_handler: All PDUs were sent                                                                            
[00:00:18.997,589] <dbg> bt_mesh_pb_adv: prov_retransmit:                                                                                               
[00:00:18.998,260] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 45ms                                                                          
[00:00:19.044,006] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:19.044,555] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:19.045,135] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:19.045,654] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:19.046,173] <dbg> bt_mesh_pb_adv: tx_work_handler: 7                                                                                             
[00:00:19.046,722] <dbg> bt_mesh_pb_adv: tx_work_handler: 8                                                                                             
[00:00:19.047,332] <dbg> bt_mesh_pb_adv: tx_work_handler: 9                                                                                             
[00:00:19.047,851] <dbg> bt_mesh_pb_adv: tx_work_handler: 10                                                                                            
[00:00:19.048,370] <dbg> bt_mesh_pb_adv: tx_work_handler: 11                                                                                            
[00:00:19.058,532] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 22ms                                                                          
[00:00:19.081,298] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:19.081,848] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:19.082,397] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:19.082,916] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:19.083,435] <dbg> bt_mesh_pb_adv: tx_work_handler: 7                                                                                             
[00:00:19.084,014] <dbg> bt_mesh_pb_adv: tx_work_handler: 8                                                                                             
[00:00:19.084,625] <dbg> bt_mesh_pb_adv: tx_work_handler: 9                                                                                             
[00:00:19.085,144] <dbg> bt_mesh_pb_adv: tx_work_handler: 10                                                                                            
[00:00:19.085,662] <dbg> bt_mesh_pb_adv: tx_work_handler: 11                                                                                            
[00:00:19.095,642] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 34ms                                                                          
[00:00:19.130,432] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:19.131,011] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:19.131,561] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:19.132,110] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:19.132,629] <dbg> bt_mesh_pb_adv: tx_work_handler: 7                                                                                             
[00:00:19.133,148] <dbg> bt_mesh_pb_adv: tx_work_handler: 8                                                                                             
[00:00:19.133,697] <dbg> bt_mesh_pb_adv: tx_work_handler: 9                                                                                             
[00:00:19.134,216] <dbg> bt_mesh_pb_adv: tx_work_handler: 10                                                                                            
[00:00:19.134,765] <dbg> bt_mesh_pb_adv: tx_work_handler: Starting retransmit timer                                                                     
[00:00:19.135,498] <dbg> bt_mesh_pb_adv: tx_work_handler: 11                                                                                            
[00:00:19.144,348] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x2                                                            
[00:00:19.145,111] <dbg> bt_mesh_pb_adv: gen_prov_ack: len 0                                                                                            
[00:00:19.145,690] <dbg> bt_mesh_pb_adv: prov_clear_tx:                                                                                                 
[00:00:19.146,575] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 26ms                                                                          
[00:00:19.173,309] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:19.173,858] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:19.174,407] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:19.175,079] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:19.175,659] <dbg> bt_mesh_pb_adv: tx_work_handler: All PDUs were sent                                                                            
[00:00:19.223,724] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x81                                                           
[00:00:19.224,517] <dbg> bt_mesh_pb_adv: gen_prov_start: len 20 last_seg 2 total_len 65 fcs 0xa2                                                        
[00:00:19.225,433] <dbg> bt_mesh_pb_adv: prov_clear_tx:                                                                                                 
[00:00:19.267,517] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x81                                                           
[00:00:19.268,310] <dbg> bt_mesh_pb_adv: gen_prov_cont: len 23, seg_index 1                                                                             
0033e50cdaa60e10fe2da7c69334250083376df1208d74                                                                                                          
[00:00:19.372,985] <dbg> bt_mesh_pb_adv: prov_clear_tx:                                                                                                 
[00:00:19.373,535] <dbg> bt_mesh_pb_adv: prov_send_adv: xact_id: 0x3 len: 33                                                                            
[00:00:19.374,206] <dbg> bt_mesh_pb_adv: prov_send_adv: seg 0 len 20: 0558377dbe06ec76e0f7f04ec5ae6daf47518661                                          
[00:00:19.375,122] <dbg> bt_mesh_pb_adv: prov_send_adv: seg 1 len 13: 04b6ae04d9e7f90a8c9c1fb9ba                                                        
[00:00:19.376,037] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 25ms                                                                          
[00:00:19.376,953] <dbg> bt_mesh_pb_adv: tx_work_handler: 0331,329] <dbg> bt_mesh_pb_adv: prov_clear_tx:                                                
[00:00:19.360,076] <dbg> bt_mesh_provisioner: prov_dh_key_gen: DHkey: 03bb2af85cb815d9ecd8e745fbc146743fc49806bab95ad40a50808ae5c3cb8c                  
[00:00:19.361,206] <dbg> bt_mesh_provisioner: send_confirm: ConfInputs[0]   00040003000000000000000001000000001cfa3ef905f39b91232b5c3b9361eb            
[00:00:19.362,274] <dbg> bt_mesh_provisioner: send_confirm: ConfInputs[32]  8f742ccd04eddbd694c9e8f8145a022eeb5b67574ea00d697701cf2106fdee11            
[00:00:19.363,372] <dbg> bt_mesh_provisioner: send_confirm: ConfInputs[64]  88d0ff337448435b98962f93598a00dbdb6d2977c97b212408bfb646a50c7774            
[00:00:19.364,440] <dbg> bt_mesh_provisioner: send_confirm: ConfInputs[96]  ca511087a5ae9e52a443b5b6f03f050d0a7b1449f3d2bb72065450f305afb5e5            
[00:00:19.365,539] <dbg> bt_mesh_provisioner: send_confirm: ConfInputs[128] 2708938a8ffab7ff397bfd4f7f6c33cb59                                          
[00:00:19.366,973] <dbg> bt_mesh_provisioner: send_confirm: ConfirmationSalt: 9dfd41eeff074e4362ac0d418cebb284a89f7ed0b2f90483fbf9c256f1ffbf48          
[00:00:19.368,041] <dbg> bt_mesh_provisioner: send_confirm: AuthValue  0000000000000000000000000000000000000000000000000000000000000000                 
[00:00:19.370,239] <dbg> bt_mesh_provisioner: send_confirm: ConfirmationKey: d8a9c2a9a5aa9473ccb44a901a70d52ce7d7693b67e8425e50abc321e2d9856f           
[00:00:19.371,459] <dbg> bt_mesh_provisioner: send_confirm: LocalRandom: ae204f3277ed3a07640033e50cdaa60e10fe2da7c69334250083376df1208d74               
[00:00:19.372,985] <dbg> bt_mesh_pb_adv: prov_clear_tx:                                                                                                 
[00:00:19.373,535] <dbg> bt_mesh_pb_adv: prov_send_adv: xact_id: 0x3 len: 33                                                                            
[00:00:19.374,206] <dbg> bt_mesh_pb_adv: prov_send_adv: seg 0 len 20: 0558377dbe06ec76e0f7f04ec5ae6daf47518661                                          
[00:00:19.375,122] <dbg> bt_mesh_pb_adv: prov_send_adv: seg 1 len 13: 04b6ae04d9e7f90a8c9c1fb9ba                                                        
[00:00:19.376,037] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 25ms                                                                          
[00:00:19.376,953] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:19.377,655] <dbg> bt_mesh_pb_adv: tx_work_h[00:00:19.447,113] <dbg> bt_mesh_pb_adv: ack_complete: xact 0x81 complete                             
[00:00:19.447,906] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 47ms                                                                          
[00:00:19.495,697] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:19.496,246] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:19.496,795] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:19.497,406] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:19.497,955] <dbg> bt_mesh_pb_adv: tx_work_handler: 7                                                                                             
[00:00:19.498,474] <dbg> bt_mesh_pb_adv: tx_work_handler: 8                                                                                             
[00:00:19.499,084] <dbg> bt_mesh_pb_adv: tx_work_handler: 9                                                                                             
[00:00:19.499,725] <dbg> bt_mesh_pb_adv: tx_work_handler: 10                                                                                            
[00:00:19.500,244] <dbg> bt_mesh_pb_adv: tx_work_handler: 11                                                                                            
[00:00:19.509,277] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 37ms                                                                          
[00:00:19.547,058] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:19.547,607] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:19.548,156] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:19.548,675] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:19.549,194] <dbg> bt_mesh_pb_adv: tx_work_handler: 7                                                                                             
[00:00:19.549,835] <dbg> bt_mesh_pb_adv: tx_work_handler: 8                                                                                             
[00:00:19.550,445] <dbg> bt_mesh_pb_adv: tx_work_handler: 9                                                                                             
[00:00:19.550,964] <dbg> bt_mesh_pb_adv: tx_work_handler: 10                                                                                            
[00:00:19.551,513] <dbg> bt_mesh_pb_adv: tx_work_handler: Starting retransmit timer                                                                     
[00:00:19.552,215] <dbg> bt_mesh_pb_adv: tx_work_handler: 11                                                                                            
[00:00:19.563,720] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 32ms                                                                          
[00:00:19.596,496] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:19.597,106] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:19.597,656] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:19.598,205] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:19.598,815] <dbg> bt_mesh_pb_adv: tx_work_handler: All PDUs were sent                                                                            
[00:00:19.606,048] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x3                                                            
[00:00:19.606,811] <dbg> bt_mesh_pb_adv: gen_prov_ack: len 0                                                                                            
[00:00:19.607,391] <dbg> bt_mesh_pb_adv: prov_clear_tx:                                                                                                 
[00:00:19.626,892] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x3                                                            
[00:00:19.627,655] <dbg> bt_mesh_pb_adv: gen_prov_ack: len 0                                                                                            
[00:00:19.654,022] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x3                                                            
[00:00:19.654,907] <dbg> bt_mesh_pb_adv: gen_prov_ack: len 0                                                                                            
[00:00:19.731,811] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x82                                                           
[00:00:19.732,574] <dbg> bt_mesh_pb_adv: gen_prov_cont: len 13, seg_index 1                                                                             
[00:00:19.733,245] <dbg> bt_mesh_pb_adv: gen_prov_cont: Start segment lost                                                                              
[00:00:19.733,886] <dbg> bt_mesh_pb_adv: prov_clear_tx:                                                                                                 
[00:00:20.251,464] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x82                                                           
[00:00:20.252,258] <dbg> bt_mesh_pb_adv: gen_prov_start: len 20 last_seg 1 total_len 33 fcs 0x2a                                                        
[00:00:20.253,112] <dbg> bt_mesh_pb_adv: prov_clear_tx:                                                                                                 
[00:00:20.253,662] <dbg> bt_mesh_pb_adv: gen_prov_ack_send: xact_id 0x82                                                                                
[00:00:20.254,455] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 48ms                                                                          
[00:00:20.255,218] <dbg> bt_mesh_provisioner: prov_confirm: Remote Confirm: cebbc73ebc09f75136b7a99e95da97ce905c7d358385cee5ff060348088c6e4d            
[00:00:20.256,256] <dbg> bt_mesh_pb_adv: prov_clear_tx:                                                                                                 
[00:00:20.256,805] <dbg> bt_mesh_pb_adv: prov_send_adv: xact_id: 0x4 len: 33                                                                            
[00:00:20.257,507] <dbg> bt_mesh_pb_adv: prov_send_adv: seg 0 len 20: 06ae204f3277ed3a07640033e50cdaa60e10fe2d                                          
[00:00:20.258,392] <dbg> bt_mesh_pb_adv: prov_send_adv: seg 1 len 13: a7c69334250083376df1208d74                                                        
[00:00:20.259,338] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 46ms                                                                          
[00:00:20.292,755] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x82                                                           
[00:00:20.293,548] <dbg> bt_mesh_pb_adv: gen_prov_cont: len 13, seg_index 1                                                                             
[00:00:20.303,222] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:20.303,771] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:20.304,321] <dbg> bt_mesh_pb_adv: tx_work_handler: 2                                                                                             
[00:00:20.304,901] <dbg> bt_mesh_pb_adv: tx_work_handler: 3                                                                                             
[00:00:20.305,450] <dbg> bt_mesh_pb_adv: tx_work_handler: 4                                                                                             
[00:00:20.306,030] <dbg> bt_mesh_pb_adv: tx_work_handler: 5                                                                                             
[00:00:20.361,022] <dbg> bt_mesh_pb_adv: ack_complete: xact 0x82 complete                                                                               
[00:00:20.361,877] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 35ms                                                                          
[00:00:20.397,674] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:20.398,223] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:20.398,773] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:20.399,444] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:20.400,024] <dbg> bt_mesh_pb_adv: tx_work_handler: 7                                                                                             
[00:00:20.400,543] <dbg> bt_mesh_pb_adv: tx_work_handler: 8                                                                                             
[00:00:20.401,062] <dbg> bt_mesh_pb_adv: tx_work_handler: 9                                                                                             
[00:00:20.401,611] <dbg> bt_mesh_pb_adv: tx_work_handler: 10                                                                                            
[00:00:20.402,130] <dbg> bt_mesh_pb_adv: tx_work_handler: 11                                                                                            
[00:00:20.407,043] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 41ms                                                                          
[00:00:20.448,883] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:20.449,493] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:20.450,042] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:20.450,653] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:20.451,171] <dbg> bt_mesh_pb_adv: tx_work_handler: 7                                                                                             
[00:00:20.451,690] <dbg> bt_mesh_pb_adv: tx_work_handler: 8                                                                                             
[00:00:20.452,270] <dbg> bt_mesh_pb_adv: tx_work_handler: 9                                                                                             
[00:00:20.452,789] <dbg> bt_mesh_pb_adv: tx_work_handler: 10                                                                                            
[00:00:20.453,399] <dbg> bt_mesh_pb_adv: tx_work_handler: Starting retransmit timer                                                                     
[00:00:20.454,101] <dbg> bt_mesh_pb_adv: tx_work_handler: 11                                                                                            
[00:00:20.462,493] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 40ms                                                                          
[00:00:20.503,265] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:20.503,875] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:20.504,425] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:20.504,943] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:20.505,554] <dbg> bt_mesh_pb_adv: tx_work_handler: All PDUs were sent                                                                            
[00:00:20.506,591] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x4                                                            
[00:00:20.507,354] <dbg> bt_mesh_pb_adv: gen_prov_ack: len 0                                                                                            
[00:00:20.507,995] <dbg> bt_mesh_pb_adv: prov_clear_tx:                                                                                                 
[00:00:20.529,907] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x4                                                            
[00:00:20.530,670] <dbg> bt_mesh_pb_adv: gen_prov_ack: len 0                                                                                            
[00:00:20.611,206] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x83                                                           
[00:00:20.611,999] <dbg> bt_mesh_pb_adv: gen_prov_start: len 20 last_seg 1 total_len 33 fcs 0x5a                                                        
[00:00:20.612,854] <dbg> bt_mesh_pb_adv: prov_clear_tx:                                                                                                 
[00:00:20.659,332] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x83                                                           
[00:00:20.660,095] <dbg> bt_mesh_pb_adv: gen_prov_cont: len 13, seg_index 1                                                                             
[00:00:20.660,797] <dbg> bt_mesh_pb_adv: gen_prov_ack_send: xact_id 0x83                                                                                
[00:00:20.661,529] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 45ms                                                                          
[00:00:20.662,261] <dbg> bt_mesh_provisioner: prov_random: Remote Random: 79ceb0293cf349150d3a3bb18ee9a1322daea89031217a9978460cfa4d87439b              
[00:00:20.664,398] <dbg> bt_mesh_provisioner: prov_random: ProvisioningSalt: 27796b830a5f73f1cd52848708a9d8f8                                           
[00:00:20.666,931] <dbg> bt_mesh_provisioner: send_prov_data: Nonce: f916ec67f47ae56283d746762f                                                         
[00:00:20.683,227] <dbg> bt_mesh_provisioner: send_prov_data: net_idx 0, iv_index 0x00000000, addr 0x0002                                               
[00:00:20.684,295] <dbg> bt_mesh_pb_adv: prov_clear_tx:                                                                                                 
[00:00:20.684,875] <dbg> bt_mesh_pb_adv: prov_send_adv: xact_id: 0x5 len: 34                                                                            
[00:00:20.685,546] <dbg> bt_mesh_pb_adv: prov_send_adv: seg 0 len 20: 0715c73d624d04a563ab17b6a07fba4b8080c9a8                                          
[00:00:20.686,431] <dbg> bt_mesh_pb_adv: prov_send_adv: seg 1 len 14: c6aa7c7e179b577d8f1ece5d6b88                                                      
[00:00:20.687,347] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 49ms                                                                          
[00:00:20.707,275] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:20.707,824] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:20.708,374] <dbg> bt_mesh_pb_adv: tx_work_handler: 2                                                                                             
[00:00:20.708,892] <dbg> bt_mesh_pb_adv: tx_work_handler: 3                                                                                             
[00:00:20.709,442] <dbg> bt_mesh_pb_adv: tx_work_handler: 4                                                                                             
[00:00:20.709,991] <dbg> bt_mesh_pb_adv: tx_work_handler: 5                                                                                             
[00:00:20.773,620] <dbg> bt_mesh_pb_adv: ack_complete: xact 0x83 complete                                                                               
[00:00:20.774,414] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 36ms                                                                          
[00:00:20.811,248] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:20.811,798] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:20.812,347] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:20.812,866] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:20.813,385] <dbg> bt_mesh_pb_adv: tx_work_handler: 7                                                                                             
[00:00:20.813,964] <dbg> bt_mesh_pb_adv: tx_work_handler: 8                                                                                             
[00:00:20.814,483] <dbg> bt_mesh_pb_adv: tx_work_handler: 9                                                                                             
[00:00:20.815,032] <dbg> bt_mesh_pb_adv: tx_work_handler: 10                                                                                            
[00:00:20.815,551] <dbg> bt_mesh_pb_adv: tx_work_handler: 11                                                                                            
[00:00:20.821,075] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 43ms                                                                          
[00:00:20.864,868] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:20.865,417] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:20.865,966] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:20.866,516] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:20.867,065] <dbg> bt_mesh_pb_adv: tx_work_handler: 7                                                                                             
[00:00:20.867,645] <dbg> bt_mesh_pb_adv: tx_work_handler: 8                                                                                             
[00:00:20.868,194] <dbg> bt_mesh_pb_adv: tx_work_handler: 9                                                                                             
[00:00:20.868,713] <dbg> bt_mesh_pb_adv: tx_work_handler: 10                                                                                            
[00:00:20.869,262] <dbg> bt_mesh_pb_adv: tx_work_handler: Starting retransmit timer                                                                     
[00:00:20.869,964] <dbg> bt_mesh_pb_adv: tx_work_handler: 11                                                                                            
[00:00:20.878,173] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 22ms                                                                          
[00:00:20.900,970] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:20.901,519] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:20.902,069] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:20.902,587] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:20.903,137] <dbg> bt_mesh_pb_adv: tx_work_handler: All PDUs were sent                                                                            
[00:00:21.369,995] <dbg> bt_mesh_pb_adv: prov_retransmit:                                                                                               
[00:00:21.370,666] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 30ms                                                                          
[00:00:21.401,428] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:21.402,008] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:21.402,557] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:21.403,106] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:21.403,625] <dbg> bt_mesh_pb_adv: tx_work_handler: 7                                                                                             
[00:00:21.404,144] <dbg> bt_mesh_pb_adv: tx_work_handler: 8                                                                                             
[00:00:21.404,785] <dbg> bt_mesh_pb_adv: tx_work_handler: 9                                                                                             
[00:00:21.405,303] <dbg> bt_mesh_pb_adv: tx_work_handler: 10                                                                                            
[00:00:21.405,853] <dbg> bt_mesh_pb_adv: tx_work_handler: 11                                                                                            
[00:00:21.416,015] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 36ms                                                                          
[00:00:21.452,789] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:21.453,338] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:21.453,948] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:21.454,467] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:21.455,047] <dbg> bt_mesh_pb_adv: tx_work_handler: 7                                                                                             
[00:00:21.455,566] <dbg> bt_mesh_pb_adv: tx_work_handler: 8                                                                                             
[00:00:21.456,115] <dbg> bt_mesh_pb_adv: tx_work_handler: 9                                                                                             
[00:00:21.456,634] <dbg> bt_mesh_pb_adv: tx_work_handler: 10                                                                                            
[00:00:21.457,183] <dbg> bt_mesh_pb_adv: tx_work_handler: Starting retransmit timer                                                                     
[00:00:21.457,885] <dbg> bt_mesh_pb_adv: tx_work_handler: 11                                                                                            
[00:00:21.470,794] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 32ms                                                                          
[00:00:21.476,013] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x5                                                            
[00:00:21.476,806] <dbg> bt_mesh_pb_adv: gen_prov_ack: len 0                                                                                            
[00:00:21.477,355] <dbg> bt_mesh_pb_adv: prov_clear_tx:                                                                                                 
[00:00:21.503,540] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:21.504,089] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:21.504,638] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:21.505,218] <dbg> bt_mesh_pb_adv: tx_work_handler: 6                                                                                             
[00:00:21.505,767] <dbg> bt_mesh_pb_adv: tx_work_handler: All PDUs were sent                                                                            
[00:00:21.529,266] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x5                                                            
[00:00:21.530,120] <dbg> bt_mesh_pb_adv: gen_prov_ack: len 0                                                                                            
[00:00:21.645,812] <dbg> bt_mesh_pb_adv: bt_mesh_pb_adv_recv: link_id 0x6fdc659c xact_id 0x84                                                           
[00:00:21.646,606] <dbg> bt_mesh_pb_adv: gen_prov_start: len 1 last_seg 0 total_len 1 fcs 0x3e                                                          
[00:00:21.647,430] <dbg> bt_mesh_pb_adv: prov_clear_tx:                                                                                                 
[00:00:21.647,949] <dbg> bt_mesh_pb_adv: gen_prov_ack_send: xact_id 0x84                                                                                
[00:00:21.648,681] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 21ms                                                                          
[00:00:21.649,414] <dbg> bt_mesh_provisioner: prov_complete: key 9a78d11cf2c1fadba2c34b08295a4f3a, net_idx 0, num_elem 4, addr 0x0002                   
[00:00:21.650,451] <dbg> bt_mesh_provisioner: prov_complete: 0                                                                                          
[00:00:21.651,000] <dbg> bt_mesh_provisioner: prov_complete: 1                                                                                          
[00:00:21.651,550] <dbg> bt_mesh_pb_adv: prov_link_close: 0                                                                                             
[00:00:21.652,069] <dbg> bt_mesh_pb_adv: prov_link_close: 1                                                                                             
[00:00:21.652,587] <dbg> bt_mesh_pb_adv: prov_link_close: 2                                                                                             
[00:00:21.653,137] <dbg> bt_mesh_pb_adv: ctl_adv_create: op 0x02 data_len 1                                                                             
[00:00:21.653,778] <dbg> bt_mesh_pb_adv: prov_clear_tx:                                                                                                 
[00:00:21.654,418] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 27ms                                                                          
[00:00:21.655,120] <dbg> bt_mesh_pb_adv: prov_link_close: 3                                                                                             
[00:00:21.655,639] <dbg> bt_mesh_pb_adv: prov_link_close: 4                                                                                             
[00:00:21.656,158] <dbg> bt_mesh_provisioner: prov_complete: 2                                                                                          
[00:00:21.670,440] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:21.670,989] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:21.671,569] <dbg> bt_mesh_pb_adv: tx_work_handler: 2                                                                                             
[00:00:21.672,119] <dbg> bt_mesh_pb_adv: tx_work_handler: 3                                                                                             
[00:00:21.672,637] <dbg> bt_mesh_pb_adv: tx_work_handler: 4                                                                                             
[00:00:21.673,248] <dbg> bt_mesh_pb_adv: tx_work_handler: 5                                                                                             
[00:00:21.731,689] <dbg> bt_mesh_pb_adv: ack_complete: xact 0x84 complete                                                                               
[00:00:21.732,482] <dbg> bt_mesh_pb_adv: tx_schedule: Next PDU delayed by 47ms                                                                          
[00:00:21.780,395] <dbg> bt_mesh_pb_adv: tx_work_handler: 0                                                                                             
[00:00:21.781,036] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:21.781,585] <dbg> bt_mesh_pb_adv: tx_work_handler: 1                                                                                             
[00:00:21.782,104] <dbg> bt_mesh_pb_adv: tx_work_handler: 2                                                                                             
[00:00:21.782,714] <dbg> bt_mesh_pb_adv: tx_work_handler: 3                                                                                             
[00:00:21.783,264] <dbg> bt_mesh_pb_adv: tx_work_handler: 4                                                                                             
[00:00:21.783,782] <dbg> bt_mesh_pb_adv: tx_work_handler: 5  

Looks like stuck at here

static void tx_work_handler(struct k_work *work)
{
	int i;
	LOG_DBG("0");
	/* Send Link Ack, Link Close and Gen Trans Ack first. */
	for (i = 0; i < ARRAY_SIZE(link.tx.unacked); i++) {
		int idx = (i + link.tx.last_unacked) % ARRAY_SIZE(link.tx.unacked);
		struct unacked_adv_ctx *unacked = &link.tx.unacked[idx];
		LOG_DBG("1");
		if (!unacked->adv) {
			continue;
		}
		LOG_DBG("2");
		atomic_set_bit(link.flags, ADV_SENDING);
		LOG_DBG("3");
		bt_mesh_adv_send(unacked->adv, &delayed_adv_send_cb, (void *)true);
		LOG_DBG("4");
		link.tx.last_unacked = idx;
		LOG_DBG("5");
		return;
	}
	LOG_DBG("6");
	/* Send Trans Start, Trans Cont and Link Open */
	if (link.tx.next >= ARRAY_SIZE(link.tx.adv) || link.tx.adv[link.tx.next] == NULL) {
		LOG_DBG("All PDUs were sent");
		return;
	}
	LOG_DBG("7");
	atomic_set_bit(link.flags, ADV_SENDING);
	LOG_DBG("8");
	bt_mesh_adv_send(link.tx.adv[link.tx.next], &delayed_adv_send_cb, (void *)false);
	LOG_DBG("9");
	link.tx.next++;
	LOG_DBG("10");
	if (link.tx.next == ARRAY_SIZE(link.tx.adv) || link.tx.adv[link.tx.next] == NULL) {
		/* All ack-able PDUs are sent. Now we can run the retransmit timer. */
		LOG_DBG("Starting retransmit timer");
		k_work_reschedule(&link.tx.retransmit, RETRANSMIT_TIMEOUT);
	}
	LOG_DBG("11");
}

[Wols]

OK, so I borrow a nrf52833DK, and run my provisioner app on it.

Now we have more info now, but how this happened?

[00:00:59.436,401] <err> os: ***** MPU FAULT *****                                                                                              
[00:00:59.441,833] <err> os:   Stacking error (context area might be not valid)                                                                 
[00:00:59.449,798] <err> os:   Data Access Violation                                                                                            
[00:00:59.455,444] <err> os:   MMFAR Address: 0x2000a26c                                                                                        
[00:00:59.461,456] <err> os: r0/a1:  0x00000004  r1/a2:  0x00000001  r2/a3:  0x0007a394                                                         
[00:00:59.470,153] <err> os: r3/a4:  0x000384fd r12/ip:  0xaaaaaaaa r14/lr:  0xaaaaaaaa                                                         
[00:00:59.478,820] <err> os:  xpsr:  0x61000000                                                                                                 
[00:00:59.484,039] <err> os: Faulting instruction address (r15/pc): 0x000142a8                                                                  
[00:00:59.491,943] <err> os: >>> ZEPHYR FATAL ERROR 2: Stack overflow on CPU 0                                                                  
[00:00:59.499,847] <err> os: Current thread: 0x20002dd8 (BT MESH WQ)                                                                            
[00:00:59.506,866] <err> os: Halting system 

Event I use "CONFIG_BT_LONG_WQ_STACK_SIZE=4096"，I still get same fault

I never try j-link debug before, if need more messge or debug way, please let me know.