NRF MESH provisioner node - appKey error

[loulou1844]

Hi,

I am in the process of provisioning and configuring a 2-element light switch server node and a common light switch server. I am using the orginal exemple for the provisioner and common light switch server and a modified 2-element light switch server node.

When I start the configuration with the 2-element node it works but the following configuration freezes while searching for the appKey. (Terminal_provisioner_view)

In the reverse order everything works normally.

I have attached debug terminal from each point of view.

Thanks.

(using nrf52840-DK / Mesh v4.1.0 / SDK v16.0.0)

Fullscreen Terminal_provisioner_view.txt Download

<t:     300644>, main.c,  174, Configuration of device 0 successful
<t:     300651>, provisioner_helper.c,  326, Scanning For Unprovisioned Devices
<t:     328492>, provisioner_helper.c,  168, UUID : 07C5A7ED6C9D4B869FAB8C12A2DFE0F6
<t:     328495>, provisioner_helper.c,  171, ^RSSI: -40
<t:     328497>, provisioner_helper.c,  177, ^URI Hash: 74F97940
<t:     328512>, node_setup.c,  768, true<t:     328513>, provisioner_helper.c,  332, Stop Scanning For Unprovisioned Devices
<t:     328516>, provisioner_helper.c,  183, URI hash matched to ¹URI for LS Server example. Provisioning ...
<t:     335229>, provisioner_helper.c,  300, Provisioning link established
<t:     350923>, provisioner_helper.c,  295, Static authentication data provided
<t:     364631>, provisioner_helper.c,  233, Provisioning completed received
<t:     364634>, provisioner_helper.c,  238, Adding device address, and device keys
<t:     364658>, provisioner_helper.c,  251, Addr: 0x0201 addr_handle: 1 netkey_handle: 0 devkey_handle: 3
<t:     370193>, provisioner_helper.c,  192, Local provisioning link closed: prov_state: 2  remaining retries: 2
<t:     370201>, main.c,  194, Provisioning successful
<t:     370207>, provisioner_helper.c,  216, Provisioning complete. ¹URI for LS Server example - address: 0x0201 elements: 2
<t:     370211>, node_setup.c,  742, Configuring Node: 0x0201
<t:     370214>, node_setup.c,  638, Config client setup: devkey_handle:3 addr_handle:1
<t:     370218>, node_setup.c,  413, Getting composition data
<t:     373735>, main.c,  247, Config client event
<t:     373738>, node_setup.c,  422, Updating network transmit: count: 2 steps: 1
<t:     376261>, main.c,  247, Config client event
<t:     376263>, node_setup.c,  433, Adding appkey
<t:     381330>, main.c,  247, Config client event
<t:     381332>, node_setup.c,  273, opcode status field: 0 
<t:     381335>, node_setup.c,  472, App key bind: Health server on element address 0x0201
<t:     383875>, main.c,  247, Config client event
<t:     383877>, node_setup.c,  273, opcode status field: 0 
<t:     383894>, node_setup.c,  491, Setting publication address for Health server to 0x0001
<t:     391050>, main.c,  247, Config client event
<t:     391053>, node_setup.c,  273, opcode status field: 0 
<t:     391055>, node_setup.c,  472, App key bind: Generic OnOff server on element address 0x0201
<t:     393513>, main.c,  247, Config client event
<t:     393515>, node_setup.c,  273, opcode status field: 0 
<t:     393526>, node_setup.c,  577, Adding subscription to address 0xC002 for Generic OnOff server on element address 0x0201
<t:     395878>, main.c,  247, Config client event
<t:     395880>, node_setup.c,  273, opcode status field: 0 
<t:     395883>, node_setup.c,  443, Adding next element
<t:     395885>, node_setup.c,  472, App key bind: Generic OnOff server on element address 0x0202
<t:     398339>, main.c,  247, Config client event
<t:     398341>, node_setup.c,  273, opcode status field: 0 
<t:     398352>, node_setup.c,  577, Adding subscription to address 0xC003 for Generic OnOff server on element address 0x0202
<t:     400886>, main.c,  247, Config client event
<t:     400888>, node_setup.c,  273, opcode status field: 0 
<t:     400891>, main.c,  174, Configuration of device 1 successful
<t:     400898>, provisioner_helper.c,  326, Scanning For Unprovisioned Devices
<t:     496372>, main.c,  219, Node 0x0100 alive with 0 active fault(s), RSSI: -51
<t:     498792>, main.c,  219, Node 0x0100 alive with 0 active fault(s), RSSI: -51
<t:     713860>, main.c,  219, Node 0x0201 alive with 0 active fault(s), RSSI: -41
<t:     716373>, main.c,  219, Node 0x0201 alive with 0 active fault(s), RSSI: -41
<t:     823925>, main.c,  219, Node 0x0100 alive with 0 active fault(s), RSSI: -49
<t:     826680>, main.c,  219, Node 0x0100 alive with 0 active fault(s), RSSI: -49
<t:    1041723>, main.c,  219, Node 0x0201 alive with 0 active fault(s), RSSI: -33
<t:    1043935>, main.c,  219, Node 0x0201 alive with 0 active fault(s), RSSI: -33
<t:    1048962>, provisioner_helper.c,  168, UUID : B6942EF07507481AA0DFBF5FEEB35AFD
<t:    1048965>, provisioner_helper.c,  171, ^RSSI: -40
<t:    1048968>, provisioner_helper.c,  177, ^URI Hash: 74F97940
<t:    1048982>, node_setup.c,  768, true
<t:    1048984>, provisioner_helper.c,  332, Stop Scanning For Unprovisioned Devices
<t:    1048987>, provisioner_helper.c,  183, URI hash matched to ¹URI for LS Server example. Provisioning ...
<t:    1056118>, provisioner_helper.c,  300, Provisioning link established
<t:    1068742>, provisioner_helper.c,  295, Static authentication data provided
<t:    1082830>, provisioner_helper.c,  233, Provisioning completed received
<t:    1082833>, provisioner_helper.c,  238, Adding device address, and device keys
<t:    1082857>, provisioner_helper.c,  251, Addr: 0x0202 addr_handle: 2 netkey_handle: 0 devkey_handle: 4
<t:    1088688>, provisioner_helper.c,  192, Local provisioning link closed: prov_state: 2  remaining retries: 2
<t:    1088696>, main.c,  194, Provisioning successful
<t:    1088702>, provisioner_helper.c,  216, Provisioning complete. ¹URI for LS Server example - address: 0x0202 elements: 2
<t:    1088706>, node_setup.c,  742, Configuring Node: 0x0202
<t:    1088709>, node_setup.c,  638, Config client setup: devkey_handle:4 addr_handle:2
<t:    1088713>, node_setup.c,  413, Getting composition data
<t:    1111177>, main.c,  247, Config client event
<t:    1111180>, node_setup.c,  422, Updating network transmit: count: 2 steps: 1
<t:    1113811>, main.c,  247, Config client event
<t:    1113813>, node_setup.c,  433, Adding appkey
	

Fullscreen Terminal_2_element_view.txt Download

<t:          0>, main.c,  336, ----- BLE Mesh Light Switch Server Demo -----
<t:      12559>, main.c,  304, Initializing and adding models
<t:      12563>, main.c,  171, App OnOff Model Handle: 3
<t:      12616>, main.c,  282, Node Address: 0x0205 
<t:      12619>, mesh_app_utils.c,   66, Device UUID (raw): B6942EF07507481AA0DFBF5FEEB35AFD
<t:      12623>, mesh_app_utils.c,   67, Device UUID : B6942EF0-7507-481A-A0DF-BF5FEEB35AFD
<t:      12651>, main.c,  383, 
		-------------------------------------------------------------------------------
		 Button/RTT 1) LED state will toggle and inform clients about the state change.
		 Button/RTT 4) Clear all the states to reset the node.
		-------------------------------------------------------------------------------
<t:      55199>, main.c,  287, Successfully provisioned
<t:      55204>, main.c,  282, Node Address: 0x0201 
<t:      66570>, config_server.c,  630, dsm_appkey_add(appkey_handle:0 appkey_index:0)

Fullscreen Terminal_1_element_view.txt Download

<t:          0>, main.c,  296, ----- BLE Mesh Light Switch Server Demo -----
<t:      12760>, main.c,  264, Initializing and adding models
<t:      12764>, main.c,  139, App OnOff Model Handle: 2
<t:      17540>, mesh_app_utils.c,   66, Device UUID (raw): 5E612FCB7BA041B6A40B5663B8F9DA2D
<t:      17543>, mesh_app_utils.c,   67, Device UUID : 5E612FCB-7BA0-41B6-A40B-5663B8F9DA2D
<t:      17556>, main.c,  343, 
		-------------------------------------------------------------------------------
		 Button/RTT 1) LED state will toggle and inform clients about the state change.
		 Button/RTT 4) Clear all the states to reset the node.
		-------------------------------------------------------------------------------
<t:     115352>, main.c,  247, Successfully provisioned
<t:     115357>, main.c,  242, Node Address: 0x0204 
<t:     161186>, config_server.c,  630, dsm_appkey_add(appkey_handle:0 appkey_index:0)
<t:     195024>, config_server.c,  630, dsm_appkey_add(appkey_handle:0 appkey_index:0)
<t:     263057>, config_server.c,  630, dsm_appkey_add(appkey_handle:0 appkey_index:0)
<t:     399591>, config_server.c,  630, dsm_appkey_add(appkey_handle:0 appkey_index:0)
<t:     672302>, config_server.c,  630, dsm_appkey_add(appkey_handle:0 appkey_index:0)
<t:    1218544>, config_server.c,  630, dsm_appkey_add(appkey_handle:0 appkey_index:0)
<t:    2092800>, config_server.c,  630, dsm_appkey_add(appkey_handle:0 appkey_index:0)
<t:    2638085>, config_server.c,  630, dsm_appkey_add(appkey_handle:0 appkey_index:0)

[Hung Bui]

Hi Loulou, 

Could you debug and check what's the value of the return code when config_client_appkey_add() called in the provisioner ? 

What's the output of the log on the client ? has it receive the app_key adding packet ?

The node_setup.c is designed with some specific scenario so it might not work out of the box when you add more element into the server. The node_setup.c might need to be modified, I'm not sure.
If you configure 2 servers each with 2 elements would it work ? 

[loulou1844]

Hi,

This function returns 0 in any case. (bug and not)

No problem with the client, its configuration is a success every time.

I can understand that senario are quite rigid but an unconfigured element should not cause probleme.

Hung Bui said:

If you configure 2 servers each with 2 elements would it work ? 

It depends, sometimes yes, sometimes no. It's very difficult to study this kind of random bug. That's why I found a case where it crashes every time: configuring a node with 2 elements and then a node with 1 element.

Thanks

BR

[Hung Bui]

Hi Loulou, 

I think we found where the issue is. In next_target_address_get(), if you have 2 elements in the server you need to change the code from 

  target_address = ONOFF_SERVER_INITIAL_ADDRESS + m_provisioner.p_nw_data->onoff_server_counter

to 

  target_address = ONOFF_SERVER_INITIAL_ADDRESS + m_provisioner.p_nw_data->onoff_server_counter*2

diff --git a/examples/provisioner/src/provisioner_helper.c b/examples/provisioner/src/provisioner_helper.c
index 2caf61b97..0a118dca5 100644
--- a/examples/provisioner/src/provisioner_helper.c
+++ b/examples/provisioner/src/provisioner_helper.c
@@ -86,7 +86,7 @@ static uint16_t next_target_address_get(void)
     }
     else if (strcmp(EX_URI_LS_SERVER, m_provisioner.p_nw_data->current_uri) == 0)
     {
-        target_address = ONOFF_SERVER_INITIAL_ADDRESS + m_provisioner.p_nw_data->onoff_server_counter;
+        target_address = ONOFF_SERVER_INITIAL_ADDRESS + m_provisioner.p_nw_data->onoff_server_counter * 2;
         m_provisioner.p_nw_data->onoff_server_counter++;
     }
     else if (strcmp(EX_URI_LL_SERVER, m_provisioner.p_nw_data->current_uri) == 0)

[Hung Bui]

Just an update: 
If you do:

  target_address = ONOFF_SERVER_INITIAL_ADDRESS + m_provisioner.p_nw_data->onoff_server_counter*2

The configuration would work, but you may notice that both of the server on 2 elements on the same node will subscribe to same group address (most likely the odd one) 
And when you configure the next node, if the primary address is odd, both of the elements will subscribe to the odd address again. 
So either you modify the node_setup.c to configure the subscription address to use the element address instead of address or you change the code to:

target_address = ONOFF_SERVER_INITIAL_ADDRESS + m_provisioner.p_nw_data->onoff_server_counter*3 

Then you will have odd and even servers. But both elements on same node will still subscribe to same address.

[loulou1844]

Thank you for the update. I will try it.

I am not sure to understand why we should add *2 or *3.

I have identified the subscription part, I think I can manage it.

BR

[Hung Bui]

So we do *2 or *3 instead of *1 as in the original code because on each of our server we have 2 elements, instead of 1 element as in the original example, hence *2. But when we do *2 we still end up each of the server primary element will be all odd address (0x0201, 0x0203...), if we want odd and even (and so on) we do *3 so we have 0x0201, 0x0204, 0x0207 and so on. Having both odd and even primary address will allow us to receive the command from both button 1 and button 2 on the client. 
But if you have your own way of configuring the subscription address, that doesn't really matter. 

[loulou1844]

I get it now and it seems obvious. Correct me if I am wrong, it is because the address has been used before that it can't add the key.

It was 100% my fault, but a little error saying "this address has been used before" might have helped. ;-)

Thank you for what you did. You have been great.