What can cause a freshly provisioned mesh node to drop connection? (Android status 19)

[BlueMike]

Dear Nordic Bluetooth Experts,

My project is quite simple: A BT Mesh device (generic level server model) powered by a Nordic nRF53832 and an Android app that is used to provision nodes and operate the mesh. The Android app uses Nordic's BLE and Mesh libraries. The product is working well, except for one occasional issue during provisioning, for which I would appreciate your advise:

When adding a new node to the mesh, the app:

1. Provisions the device.
2. Connects to the new node.
3. Assigns the keys.

The problem is that sometimes after connecting to the freshly provisioned node, the Bluetooth connection updates to status 19 (BLE_HCI_REMOTE_USER_TERMINATED_CONNECTION), which apparently means that the mesh node terminated the connection. If it happens, this is whats showing up at Android's logcat:

14:02:12.177 21374-21374/com.xxx.mesh D/BluetoothGatt: connect() - device: F2:8A:20:B2:57:A6, auto: false
14:02:12.177 21374-21374/com.xxx.mesh D/BluetoothAdapter: isSecureModeEnabled
14:02:12.178 21374-21374/com.xxx.mesh D/BluetoothGatt: registerApp()
14:02:12.178 21374-21374/com.xxx.mesh D/BluetoothGatt: registerApp() - UUID=1db0e7d0-7f91-4213-841c-a65df21b4e94
14:02:12.181 21374-21399/com.xxx.mesh D/BluetoothGatt: onClientRegistered() - status=0 clientIf=10
14:02:14.152 21374-21399/com.xxx.mesh D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=10 device=F2:8A:20:B2:57:A6
14:02:14.467 21374-21374/com.xxx.mesh D/BluetoothGatt: discoverServices() - device: F2:8A:20:B2:57:A6
14:02:14.768 21374-21399/com.xxx.mesh D/BluetoothGatt: onConnectionUpdated() - Device=F2:8A:20:B2:57:A6 interval=198 latency=0 timeout=400 status=0
14:02:16.377 21374-21399/com.xxx.mesh D/BluetoothGatt: onConnectionUpdated() - Device=F2:8A:20:B2:57:A6 interval=6 latency=0 timeout=500 status=19
14:02:16.378 21374-21374/com.xxx.mesh E/BleManager: onConnectionUpdated received status: 19, interval: 6, latency: 0, timeout: 500
14:02:16.385 21374-21399/com.xxx.mesh D/BluetoothGatt: onClientConnectionState() - status=19 clientIf=10 device=F2:8A:20:B2:57:A6

The last three lines is where the disconnect happens.
Now the question is what can possibly cause this sporadic disconnect? And how can it be prevented? Please note that the mesh node is in range and powered on.

Here's a little detail that could be relevant:
In both, the error case and the OK case, two log messages starting with "D/BluetoothGatt: onConnectionUpdated()....." appear in logcat. In the error case, the second message shows status 19 (like above), whereas in the OK case the status is 0. Oddly enough, the second messages always appears about a 1.6 seconds after the first one, in both the error and the OK case. I don't know if it's relevant, but it's a remarkable consistent timing...

What makes this problem so difficult to debug is that it happens only once every 10-20 provisioned nodes, so any advise is very much appreciated. Thank you.

[Mttrinh]

Hi,

Which nRF5 SDK and Mesh SDK are you using? The status you are getting, BLE_HCI_REMOTE_USER_TERMINATED_CONNECTION, means that the connection was terminated by the phone. 

What phone are you testing this on? Can you try testing with other phones as well?

The Android app uses Nordic's BLE and Mesh libraries

I assume this is your own app, a custom app. If so, could you try using our nRF Mesh to provision your node? Are you able to reproduce the issue using our app?

[BlueMike]

Dear Mttrinh,

Thanks for your help!
SDKs in use are:

• nRF5 SDK 17.0.2
• nRF5 SDK for Mesh 4.2.0
• Android BLE Library v2.2.4
• Android nRF Mesh v3.1.5

The issue happens on a wide range of phones (Samsung, Google, Volla, Huawei) and all Android versions from 8.1 upwards (haven't tested any older versions).

I'll try to reproduce the issue with Nordic's app. Meanwhile, do you have any ideas how to figure out why the connection sporadically gets lost? I've tried to set NRF_LOG_ENABLED and NRF_PWR_MGMT_CONFIG_LOG_ENABLED at the firmware, hoping they will shed some light onto what's going on, but haven't been able to reproduce the problem since. It's a little difficult: If 20+ nodes are provisioned in a loop (a feature of the app), then there's always at least one node that shows the issue. But if only a single node is provisioned (like during automated tests), then it almost never happens. Anyway, can you think of any other debug switches in the firmware that can help in finding the cause of the connection lost? Any idea is very much welcome!

Again, thanks for your help,
Michael.

[Mttrinh]

Hi,

You would have to add some logging in the code to see what is actually happening during these disconnects. Logs with LOG_SRC_ACCESS | LOG_SRC_BEARER and LOG_LEVEL_DBG3, might also help.