Acknowledged message status not received in light switch sample

[The Gribble]

Hi,

I'm just getting started with nRF mesh (sdk V3.00) and I've built the light switch sample successfully and deployed it on three nRF52832 development boards but provision keeps failing - if I provision from the mobile app it just stops at about 75%, if I try it from the dev board provisioner then I get an "Acknowledged message status not received" error, am I doing something stupid?

<t:          0>, main.c,  562, ----- BLE Mesh Light Switch Provisioner Demo -----
<t:      16489>, main.c,  499, Initializing and adding models
<t:      16521>, main.c,  552, Restored: Handles 
<t:      16523>, provisioner_helper.c,  307, m_netkey_handle:0 m_appkey_handle:0 m_self_devkey_handle:1
<t:      16528>, main.c,  591, <start> 
<t:      16530>, main.c,  579, Starting application ...
<t:      16532>, main.c,  581, Provisoned Nodes: 0, Configured Nodes: 0 Next Address: 0x0100
<t:      16537>, main.c,  582, Dev key : 00000000000000000000000000000000
<t:      16540>, main.c,  583, Net key : 00000000000000000000000000000000
<t:      16543>, main.c,  584, App key : 00000000000000000000000000000000
<t:      16546>, main.c,  585, Press Button 1 to start provisioning and configuration process. 
<t:      16632>, main.c,  405, Mesh evt: FLASH_STABLE 
<t:     161008>, main.c,  459, Button 1 pressed
<t:     161010>, main.c,  365, Waiting for Client node to be provisioned ...
<t:     165776>, provisioner_helper.c,  288, Scanning For Unprovisioned Devices
<t:     184795>, provisioner_helper.c,  143, UUID seen: 0059CCAA00000000F0496DC39DC89BD1
<t:     184798>, provisioner_helper.c,   95, UUID filter matched
<t:     186485>, provisioner_helper.c,  263, Provisioning link established
<t:     198406>, provisioner_helper.c,  258, Static authentication data provided
<t:     275986>, provisioner_helper.c,  196, Provisioning completed received
<t:     275989>, provisioner_helper.c,  201, Adding device address, and device keys
<t:     275995>, provisioner_helper.c,  218, Addr: 0x0100 addr_handle: 0 netkey_handle: 0 devkey_handle: 2
<t:     276209>, main.c,  405, Mesh evt: FLASH_STABLE 
<t:     276212>, main.c,  405, Mesh evt: FLASH_STABLE 
<t:     279566>, provisioner_helper.c,  159, Local provisioning link closed: prov_state: 2  remaining retries: 2
<t:     279570>, main.c,  286, Provisioning successful
<t:     279572>, provisioner_helper.c,  185, Provisioning complete. Node addr: 0x0100 elements: 3
<t:     279576>, provisioner_helper.c,   95, UUID filter matched
<t:     279579>, node_setup.c,  679, Configuring Node: 0x0100
<t:     279582>, node_setup.c,  569, Config client setup: devkey_handle:2 addr_handle:0
<t:     279585>, node_setup.c,  349, Getting composition data
<t:     279595>, access.c,  427, TX: [aop: 0x8008] 
<t:     279597>, access.c,  428, TX: Msg: 00
<t:     305820>, access.c,  427, TX: [aop: 0x8008] 
<t:     305822>, access.c,  428, TX: Msg: 00
<t:     332035>, access.c,  427, TX: [aop: 0x8008] 
<t:     332037>, access.c,  428, TX: Msg: 00
<t:     384464>, access.c,  427, TX: [aop: 0x8008] 
<t:     384466>, access.c,  428, TX: Msg: 00
<t:     489321>, access.c,  427, TX: [aop: 0x8008] 
<t:     489323>, access.c,  428, TX: Msg: 00
<t:     699036>, access.c,  427, TX: [aop: 0x8008] 
<t:     699038>, access.c,  428, TX: Msg: 00
<t:    1118467>, access.c,  427, TX: [aop: 0x8008] 
<t:    1118469>, access.c,  428, TX: Msg: 00
<t:    1957328>, access.c,  427, TX: [aop: 0x8008] 
<t:    1957330>, access.c,  428, TX: Msg: 00
<t:    2245679>, main.c,  336, Config client event
<t:    2245681>, node_setup.c,  617, Acknowledged message status not received 
<t:    2245684>, node_setup.c,  621, Retry ...
<t:    2245686>, node_setup.c,  349, Getting composition data
<t:    2245696>, access.c,  427, TX: [aop: 0x8008] 
<t:    2245698>, access.c,  428, TX: Msg: 00
<t:    2271921>, access.c,  427, TX: [aop: 0x8008] 
<t:    2271923>, access.c,  428, TX: Msg: 00
<t:    2298136>, access.c,  427, TX: [aop: 0x8008] 
<t:    2298138>, access.c,  428, TX: Msg: 00
<t:    2350565>, access.c,  427, TX: [aop: 0x8008] 
<t:    2350567>, access.c,  428, TX: Msg: 00
<t:    2455422>, access.c,  427, TX: [aop: 0x8008] 
<t:    2455424>, access.c,  428, TX: Msg: 00
<t:    2665137>, access.c,  427, TX: [aop: 0x8008] 
<t:    2665139>, access.c,  428, TX: Msg: 00
<t:    3084568>, access.c,  427, TX: [aop: 0x8008] 
<t:    3084570>, access.c,  428, TX: Msg: 00
<t:    3923429>, access.c,  427, TX: [aop: 0x8008] 
<t:    3923431>, access.c,  428, TX: Msg: 00
<t:    4211780>, main.c,  336, Config client event
<t:    4211783>, node_setup.c,  617, Acknowledged message status not received 
<t:    4211786>, node_setup.c,  621, Retry ...
<t:    4211788>, node_setup.c,  349, Getting composition data
<t:    4211798>, access.c,  427, TX: [aop: 0x8008] 
<t:    4211801>, access.c,  428, TX: Msg: 00
<t:    4238024>, access.c,  427, TX: [aop: 0x8008] 
<t:    4238026>, access.c,  428, TX: Msg: 00
<t:    4264239>, access.c,  427, TX: [aop: 0x8008] 
<t:    4264241>, access.c,  428, TX: Msg: 00
<t:    4316668>, access.c,  427, TX: [aop: 0x8008] 
<t:    4316670>, access.c,  428, TX: Msg: 00
<t:    4421525>, access.c,  427, TX: [aop: 0x8008] 
<t:    4421527>, access.c,  428, TX: Msg: 00
<t:    4631240>, access.c,  427, TX: [aop: 0x8008] 
<t:    4631242>, access.c,  428, TX: Msg: 00
<t:    5050671>, access.c,  427, TX: [aop: 0x8008] 
<t:    5050673>, access.c,  428, TX: Msg: 00
<t:    5889532>, access.c,  427, TX: [aop: 0x8008] 
<t:    5889534>, access.c,  428, TX: Msg: 00
<t:    6177883>, main.c,  336, Config client event
<t:    6177885>, node_setup.c,  617, Acknowledged message status not received 
<t:    6177889>, main.c,  279, Configuration of device 0 failed. Press Button 1 to retry.

Many thanks,

Ben.

[Edvin]

Hello Ben,

I just tested with SDK for Mesh v3.0.0, and I couldn't reproduce your issue.

The issue may be that you have some old data stored in the flash of the nrf on the device that you are trying to provision, causing some issues with the provisioning. You should check the log output on the device that you are trying to provision as well.

Please make sure that you:

1 - erase the flash of the nrf before programming it.

2 - program the correct pojects to all your development boards. Make sure you use the S132 project and softdevice, and not the S140 ones.

use e.g. Nordic Command line tools, open a CMD terminal and type "nrfjprog -e" before programming the DKs. Let me know if you are having problems doing this. You can alternatively use nRFgo Studio to erase the chips.

I suppose that you use Segger Embedded Studio, and if you do, Segger should upload the correct softdevice for you. If you use nrfjprog to program the devices, make sure that you program the correct version of the softdevice (S132 v 6.1.0).

If it still doesn't work, can you check the log for the client or server? (the one that you are trying to provision).

Best regards,

Edvin

[The Gribble]

Hi again Edvin,

Looking into it further the BT832X module seems to be the root of the problem - if I run a single PCA10040 board with the light switch client program then I can reliably provision it using the mobile app, while the BT832X version fails every time at 75%, with a Vector Catch if it's in the debugger.

We've got our own PCB with a BT832X module on it and that's failing in exactly the same way. 

I'll try the Fanstel technical support with this too, but have you got any ideas for what the problem might be? I kind of assumed that they should be pretty much identical.

Many thanks,

Ben.