Time for configuring node increases after deleting from mesh network

[JeffZ]

Hi guys,

I have the same issue as coca1989 had 2 years ago. Did anybody found a solution?

I am using health model and simple message model. Client and Provisioner are running on one device (demoboard). I can provision and configure upto 5 server nodes (dongles). I get health events from each connected server (all 10 seconds) and I can send and receive small messages on all server nodes.

Now, I would like to remove nodes from the mesh network and reconnect them (reprovisioning and reconfiguration). This are the steps that I am doing:

1. config_client_server_bind() and config_client_server_set() to the server node I would like to remove from network
2. config_client_node_reset()
3. the server gets the node reset event (CONFIG_SERVER_EVT_NODE_RESET) from client and performs node_reset() with:  mesh_stack_config_clear() and mesh_stack_device_reset()
4. the server responds to the client with CONFIG_CLIENT_EVENT_TYPE_CANCELLED and I do dsm_devkey_delete()

After removing the server node, I can reprovision and reconfigure the node successfully (getting health events and send/receive messages). But the configuration takes longer then the first time. Repeating this process (removing node and reconnecting) increases the configuration time each time.

Here is a time table:

First configuration: 2-3 seconds
Second configuration (after removing node from mesh): 10-11 seconds
Third configuration (after removing node from mesh):20-30 seconds
Fourth configuration (after removing node from mesh): 45 -50 seconds
Fifth configuration (after removing node from mesh): >80 seconds

This is reproduceable. Rebooting the client/provisioner device after removing a server node reduces the configuration time back to 2-3 seconds, but I do not get health events and no messages.

During reconfiguration (after removing the server from network) I am getting SAR mesh events on the server node. At the first configuration (fresh device) I dont have this SAR events.

I guess I have to delete more on client side? Maybe the simple message or health is still active on the last address handles?

[Mttrinh]

Hi,

What is your setup? Which Mesh SDK are you using? Which device are you using?

Have you tried this with the latest Mesh SDK v4.2?

[JeffZ]

Hi Mttrinh, thank you for replying.

SDKs
Mesh v3.1.0
nrf5 v15.2.0_9412b96 with SoftDevice140.

Hardware
1x nordic demoboard (PCA10056, nrf52840)
3x nordic dongles (PCA10059,nrf52840)

Setup
On the Demoboard: Provisioner, Config Client, Health Client, Simple Message Client
On the 3 Dongles: Provisionee, Health Server, Simple Message Server

Mttrinh said:

Have you tried this with the latest Mesh SDK v4.2?

No, till this moment 3.1.0 was running perfectly for me.

Thx, Jeff

[JeffZ]

Mttrinh Sorry I forgot to mention that I have also running pb_remote_server on the dongles and pb_remote_client on the demoboard. Remote provisioning runs, but with the same issue (increasing time for configuration process after re-provisioning/-configuration).

[JeffZ]

Hi, I tried to look what is happening on the server node, after provisioning during configudation. This is how it looks like if I have a fresh device:

<t: 16480>, my_provisionee.c, 289, Provsionee stopped.
<t: 172720>, access.c, 246, RX: [aop: 0x8008]
<t: 172743>, my_common.c, 163, RSSI: -55
<t: 176098>, access.c, 246, RX: [aop: 0x8008]
<t: 176121>, my_common.c, 163, RSSI: -54
<t: 180618>, access.c, 246, RX: [aop: 0x0000] --> configuraion continues
<t: 180626>, config_server.c, 623, dsm_appkey_add(appkey_handle:0 appkey_index:0)
<t: 180636>, my_server.c, 61, Config_server_evt_cb (TYPE: 0)
<t: 180639>, my_common.c, 163, RSSI: -55
<t: 182332>, access.c, 246, RX: [aop: 0x803D]
<t: 182335>, config_server.c, 2414, Access Info:
element_index=0 model_id = 2-FFFF model_handle=1
<t: 182347>, my_server.c, 61, Config_server_evt_cb (TYPE: 22)
<t: 182351>, my_common.c, 163, RSSI: -54
<t: 183109>, access.c, 246, RX: [aop: 0x803D]
<t: 183112>, config_server.c, 2414, Access Info:
element_index=0 model_id = 0-91C model_handle=2
<t: 183124>, my_server.c, 61, Config_server_evt_cb (TYPE: 22)
<t: 183127>, my_common.c, 163, RSSI: -54
<t: 184562>, access.c, 246, RX: [aop: 0x0003]
<t: 184579>, my_server.c, 61, Config_server_evt_cb (TYPE: 2)
<t: 184582>, my_common.c, 163, RSSI: -55
<t: 188517>, access.c, 246, RX: [aop: 0x0003]
<t: 188534>, my_server.c, 61, Config_server_evt_cb (TYPE: 2)
<t: 188537>, my_common.c, 163, RSSI: -55
<t: 191548>, access.c, 246, RX: [aop: 0x801B]

You can see here, that aop 0x8008 (get_composition_data) is sent twice only and the configuration process start almost immediat.

This is how it looks like if I unprovision/delete the node from mesh (as I discribed in my ticket):

<t: 1029333>, my_provisionee.c, 289, Provsionee stopped.
<t: 1031812>, access.c, 246, RX: [aop: 0x8008]
<t: 1031835>, my_common.c, 163, RSSI: -54
<t: 1044671>, access.c, 246, RX: [aop: 0x8008]
<t: 1044676>, my_common.c, 163, RSSI: -54
<t: 1057725>, access.c, 246, RX: [aop: 0x8008]
<t: 1057730>, my_common.c, 163, RSSI: -54
<t: 1084273>, access.c, 246, RX: [aop: 0x8008]
<t: 1084277>, my_common.c, 163, RSSI: -54
<t: 1136351>, access.c, 246, RX: [aop: 0x8008]
<t: 1136355>, my_common.c, 163, RSSI: -55
<t: 1146584>, my_common.c, 201, SAR FAILED: token 1, reason 1
<t: 1239180>, nrf_mesh_dfu.c, 904, ERROR: No CMD handler!
<t: 1241178>, access.c, 246, RX: [aop: 0x8008]
<t: 1241201>, my_common.c, 163, RSSI: -54
<t: 1355949>, my_common.c, 201, SAR FAILED: token 6, reason 1
<t: 1451464>, access.c, 246, RX: [aop: 0x8008]
<t: 1451487>, my_common.c, 163, RSSI: -54
<t: 1566236>, my_common.c, 201, SAR FAILED: token 7, reason 1
<t: 1568045>, nrf_mesh_dfu.c, 904, ERROR: No CMD handler!
<t: 1860592>, my_common.c, 234, default:4
<t: 1870591>, access.c, 246, RX: [aop: 0x8008]
<t: 1870614>, my_common.c, 163, RSSI: -54
<t: 1985362>, my_common.c, 201, SAR FAILED: token 8, reason 1

... -> configuration continues after see time table above.

You can see here that the server node gets the aop 0x8008 too, but much more than two times. The number of aop 0x8008 (get_composition_data) messages increases after deleting the node again from the mesh network.

What can cause this issue/behaivor?

[Mttrinh]

I'm not sure why this happens, I will need more time to figure out what is causing this behavior. Do you see the same if you use the nRF Mesh app(Android/iOS) to provision/configure and reset the nodes?