Bonded peer cannot reconnect - PM_EVT_LOCAL_DB_CACHE_APPLY_FAILED

[Martyn]

Hi, I am using the ble_app_cscs_pca10056_s140 example application from nRF5_SDK_15.0.0_a53641a and I have made a single-line change (see below) to force the bonding process to run. This works flawlessly for a new device; I get a bond succeeded and can subscribe to the NOTIFY characteristic. However it fails whenever I disconnect and then try to reconnect.

To try and debug I've added log statements for all Peer Manager events and have included this below. I get a PM_EVT_STORAGE_FULL as part of the initial bond, then a lot of PM_EVT_LOCAL_DB_CACHE_APPLY_FAILED. I think this is suggesting the bond information cannot be stored &/or retrieved correctly from the flash?

I tried running: nrfprog --qspieraseall and nrfprog --eraseall but that doesn't seem to help.

The single change I made to the basic example in services_init() function is:

//BLE_GAP_CONN_SEC_MODE_SET_OPEN(&cscs_init.csc_meas_attr_md.cccd_write_perm);
BLE_GAP_CONN_SEC_MODE_SET_ENC_NO_MITM(&cscs_init.csc_meas_attr_md.cccd_write_perm);

Log output:

<info> app: Fast advertising
<info> app: Connected
<info> app: PM_EVT_CONN_SEC_START
<info> app: PM_EVT_PEER_DATA_UPDATE_SUCCEEDED
<info> app: PM_EVT_PEER_DELETE_SUCCEEDED
<info> app: PM_EVT_LOCAL_DB_CACHE_APPLIED
<info> app: PM_EVT_LOCAL_DB_CACHE_APPLY_FAILED
<info> app: PM_EVT_SERVICE_CHANGED_IND_SENT
<info> app: PM_EVT_SERVICE_CHANGED_IND_CONFIRMED
<info> app: PM_EVT_SLAVE_SECURITY_REQ
<info> app: PM_EVT_FLASH_GARBAGE_COLLECTED
<info> app: PM_EVT_CONN_SEC_PARAMS_REQ
<info> app: PM_EVT_STORAGE_FULL
<info> app: PM_EVT_FLASH_GARBAGE_COLLECTED
<info> app: Connection secured: role: 1, conn_handle: 0x0, procedure: 1.
<info> app: PM_EVT_PEER_DATA_UPDATE_SUCCEEDED
<info> app: PM_EVT_PEER_DELETE_SUCCEEDED
<info> app: PM_EVT_LOCAL_DB_CACHE_APPLIED
<info> app: PM_EVT_LOCAL_DB_CACHE_APPLY_FAILED
<info> app: PM_EVT_SERVICE_CHANGED_IND_SENT
<info> app: PM_EVT_SERVICE_CHANGED_IND_CONFIRMED
<info> app: PM_EVT_SLAVE_SECURITY_REQ
<info> app: PM_EVT_FLASH_GARBAGE_COLLECTED
<info> app: PM_EVT_PEER_DATA_UPDATE_SUCCEEDED
<info> app: PM_EVT_PEER_DELETE_SUCCEEDED
<info> app: PM_EVT_LOCAL_DB_CACHE_APPLIED
<info> app: PM_EVT_LOCAL_DB_CACHE_APPLY_FAILED
<info> app: PM_EVT_SERVICE_CHANGED_IND_SENT
<info> app: PM_EVT_SERVICE_CHANGED_IND_CONFIRMED
<info> app: PM_EVT_SLAVE_SECURITY_REQ
<info> app: PM_EVT_FLASH_GARBAGE_COLLECTED
<info> app: PM_EVT_PEER_DATA_UPDATE_SUCCEEDED
<info> app: PM_EVT_PEER_DELETE_SUCCEEDED
<info> app: PM_EVT_LOCAL_DB_CACHE_APPLIED
<info> app: PM_EVT_LOCAL_DB_CACHE_APPLY_FAILED
<info> app: PM_EVT_SERVICE_CHANGED_IND_SENT
<info> app: PM_EVT_SERVICE_CHANGED_IND_CONFIRMED
<info> app: PM_EVT_SLAVE_SECURITY_REQ
<info> app: PM_EVT_FLASH_GARBAGE_COLLECTED
<info> app: Fast advertising
<info> app: Disconnected
<info> app: Connected to a previously bonded device.
<info> app: PM_EVT_LOCAL_DB_CACHE_APPLIED
<info> app: PM_EVT_LOCAL_DB_CACHE_APPLY_FAILED
<info> app: PM_EVT_SERVICE_CHANGED_IND_SENT
<info> app: PM_EVT_SERVICE_CHANGED_IND_CONFIRMED
<info> app: PM_EVT_SLAVE_SECURITY_REQ
<info> app: PM_EVT_FLASH_GARBAGE_COLLECTED
<info> app: Connected
<error> app: Fatal error
<warning> app: System reset

I'm not sure what to try next to be honest...any help or suggestions appreciated!

Many thanks.

[Susheel Nuguru]

The last few lines of your logs are little confusing

<info> app: Connected to a previously bonded device.
<info> app: PM_EVT_LOCAL_DB_CACHE_APPLIED
<info> app: PM_EVT_LOCAL_DB_CACHE_APPLY_FAILED
<info> app: PM_EVT_SERVICE_CHANGED_IND_SENT
<info> app: PM_EVT_SERVICE_CHANGED_IND_CONFIRMED
<info> app: PM_EVT_SLAVE_SECURITY_REQ
<info> app: PM_EVT_FLASH_GARBAGE_COLLECTED
<info> app: Connected

Why does it say it is connected twice?

[Martyn]

Hi, thanks for taking a look, the two messages are output by:

"Connected to a previously bonded device" comes from the pm_evt_handler() function in the PM_EVT_BONDED_PEER_CONNECTED case.

"Connected" comes from the ble_evt_handler() function in the BLE_GAP_EVT_CONNECTED case.

So the former is the Peer Manager informing me it has connected to a peer it has bonded with in a previous connection, and the latter is the BLE event handler informing me that a connection has been made.

I think the Peer Manager fires that event off as soon as it recognises a device, before it then checks whether it can talk to the device properly. The BLE event is then fired as it connects, before the fatal error is then thrown presumably because of a credentials mismatch? But that's just my guess, the creds might be fine and it's some other error.

[Susheel Nuguru]

Martyn, sorry for late reply. I changed the same line as you did and found no problems to reconnect with bond after disconnection.

Are you sure there is nothing else you changed? I tested on PCA10056 DK, SDK15 and phone with android 8.0.0

[Martyn]

Hi Aryan, how many times did you try disconnecting and reconnecting? I found it was ok once or twice, but soon reverts to the behaviour I'm seeing. Are you using nRF Connect on the other side of the connection?

I just unzipped the example folder and changed literally that one line and checked it again with the same result, i.e. connects and bonds, but then disconnecting and reconnecting a few times guarantees a fail from which it never recovers.

I am using the nRF52840-Preview-DK with a PCA10056 and the example is from SDK15.

I can't get past this as it is repeatable, i.e. when I use nrfjprog --qspieraseall and reflash the board with the example and delete the bond information from the nRF Connect app, I can then create a new bond with the board and the whole cycle repeats itself.

Do you have any ideas of what I can try next? Any particular example I can try that uses bonding and the nRF Connect app?

[Susheel Nuguru]

This is really strange. Could it be something with the phone side? You should be able to get the sniffer trace for the packets in air and you should be able to deduce the reason for disconnections there easily.