NimBLE: Error while removing IRK

[ahammouri]

Checklist

• Checked the issue tracker for similar issues to ensure this is not a duplicate
• Read the documentation to confirm the issue is not addressed there and your configuration is set correctly
• Tested with the latest version to ensure the issue hasn't been fixed

How often does this bug occurs?

often

Expected behavior

I expected to see BLE pairing working fine after an esp32 factory reset

Actual behavior (suspected bug)

After an esp32 factory reset, some devices fail to connect over BLE again (does not always happen). I get an error saying NimBLE: Error while removing IRK and I could not find a way to get it to work again.

Error logs or terminal output

I (5864) NimBLE: GATT procedure initiated: notify;
I (5874) NimBLE: att_handle=20
I (12714) NimBLE: GAP procedure initiated: terminate connection; conn_handle=0 hci_reason=19
E (12724) NimBLE: Error while removing IRK
I (12944) ble: disconnect, reason=534 
W (12944) ble: client disconnected, connection id=0 [MAC ADDRESS]
I (12974) NimBLE: GAP procedure initiated: advertise; 
I (12974) NimBLE: disc_mode=2
I (12984) NimBLE:  adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
I (12994) NimBLE:

Steps to reproduce the behavior

Perform a factory reset on esp32, Bonds are deleted using the ble_store_clear() function.
Attempt to connect over BLE again.
Get the above error

Project release version

Shipped with ESP-IDF 5.2.2

System architecture

Intel/AMD 64-bit (modern PC, older Mac)

Operating system

Windows

Operating system version

Windows 11

Shell

CMD

Additional context

No response

[rahult-github]

Hi @ahammouri ,

So, the below print implies that during unpair, there was attempt to delete IRK, but it didn't find any in the nvs. This is more of a debug print rather than an issue.

E (12724) NimBLE: Error while removing IRK

However, the below is something we should debug.

I (12714) NimBLE: GAP procedure initiated: terminate connection; conn_handle=0 hci_reason=19
E (12724) NimBLE: Error while removing IRK
I (12944) ble: disconnect, reason=534
W (12944) ble: client disconnected, connection id=0 [MAC ADDRESS]

can you possibly share a nimble debug enabled console log ? We need to check if disconnect event was received OR stack internally initiated disconnect. If stack did, then we will have to check the reason for it. If remote has sent the event, then remote side would need to be debugged.

[ahammouri]

Thanks for the reply @rahult-github

I tried to set my sdkconfig to use CONFIG_BT_NIMBLE_LOG_LEVEL_DEBUG=y
But that did not produce any BLE debug logs 🤔 Any idea why is this happening ?

[rahult-github]

Hi @ahammouri ,

Please use:

Component config → Log output → Default log verbosity --> Set to Debug

Component config → Bluetooth → NimBLE Options → NimBLE Host log verbosity --> Set to Debug

[ahammouri]

Thanks for the help @rahult-github

When debug logs were enabled, an assert occurred which rebooted esp. Did the assert fail because debug logs are now enabled and did not print NimBLE: Error while removing IRK instead ?

Logs before the assert happened. Let me know if you need more logs. Thanks !

debug logs.txt

[ahammouri]

A different log from one of my colleagues

D (69572) NimBLE ble_hs_hci_cmd_sen.txt

[achugbGL]

I have a similar issue. For the factory reset routine in our device, I call ble_gap_unpair_oldest_peer() in a loop until all bonds are removed which should then call ble_gap_reset_irk() since I have BT_BLE_SMP_ID_RESET_ENABLE enabled. I considered using ble_store_clear() but it does not seem to call ble_gap_reset_irk().

When it deletes the last bond, I see this message printed to the terminal:

E (2086938) NimBLE: Error while removing IRK , rc = 20c
I (2086958) NimBLE: Failed to remove old all zero IRK

Is this also more of a debug print rather than an issue? The device appears to be resetting its IRK.

We are using the ESP32 c3 and are on IDF v5.4.0