NimBLE-Arduino icon indicating copy to clipboard operation
NimBLE-Arduino copied to clipboard

Published 20 hours ago • verified publisher icon h2zero

Version 2.1.2 bonded device not recognized after reconnection with random address

Open sanastasiou opened this issue 11 months ago • 4 comments

Hi @h2zero , I just tested 2.1.2 and here's is a sample from a log output. I can reproduce this 100%.

  1. Bond device
  2. Disconnect device
  3. Reconnect device with different random id address
  4. Try to access encrypted characteristic issues bonding request again
D NimBLEAdvertising: >> Advertising start: duration=0, dirAddr=NULL
primary service
           uuid 0x1800
         handle 1
     end_handle 5
characteristic
           uuid 0x2a00
     def_handle 2
     val_handle 3
   min_key_size 0
          flags [READ]
characteristic
           uuid 0x2a01
     def_handle 4
     val_handle 5
   min_key_size 0
          flags [READ]
primary service
           uuid 0x1801
         handle 6
     end_handle 13
characteristic
           uuid 0x2a05
     def_handle 7
     val_handle 8
   min_key_size 0
          flags [INDICATE]
ccc descriptor
           uuid 0x2902
         handle 9
   min_key_size 0
          flags [READ|WRITE]
characteristic
           uuid 0x2b3a
     def_handle 10
     val_handle 11
   min_key_size 0
          flags [READ]
characteristic
           uuid 0x2b29
     def_handle 12
     val_handle 13
   min_key_size 0
          flags [READ|WRITE]
primary service
           uuid 00002ffa-0000-1000-8000-00805f9b34fb
         handle 14
     end_handle 20
characteristic
           uuid 82c314b2-e53a-4d5e-b021-fc5887b4373f
     def_handle 15
     val_handle 16
   min_key_size 0
          flags [READ|NOTIFY|INDICATE]
ccc descriptor
           uuid 0x2902
         handle 17
   min_key_size 0
          flags [READ|WRITE]
characteristic
           uuid 3c5577d7-d182-482a-940a-7e5062441f43
     def_handle 18
     val_handle 19
   min_key_size 0
          flags [READ|WRITE|NOTIFY|INDICATE|READ_ENC|READ_AUTHEN|WRITE_ENC|WRITE_AUTHEN]
ccc descriptor
           uuid 0x2902
         handle 20
   min_key_size 0
          flags [READ|WRITE]
D NimBLEAdvertising: << Advertising start
Pairing time remaining: 119 seconds...
Pairing time remaining: 118 seconds...
Pairing time remaining: 117 seconds...
Pairing time remaining: 116 seconds...
Real voltage:      17.41 V
Is advertising: true
Is connected: false
Is bonded: true
Number of peer devices: 0
Ping value: 500
LedControl::update() - state: Pairing
Pairing time remaining: 115 seconds...
Pairing time remaining: 114 seconds...
Pairing time remaining: 113 seconds...
Pairing time remaining: 112 seconds...
Pairing time remaining: 111 seconds...
D NimBLEServer: >> handleGapEvent: 
ServerCallbacks::onConnect()Connection Info:
  Peer ID Address: 44:e4:b1:46:dc:d7 (Type: Random)
  Peer OTA Address: 44:e4:b1:46:dc:d7 (Type: Random)
  Connection Handle: 1
  Security State:
    Encrypted: false
    Authenticated: false
    Bonded: false
    Key Size: 0
  Connection Parameters:
    Interval: 36
    Latency: 0
    Supervision Timeout: 500
    Role: Slave
Client with address: 44:e4:b1:46:dc:d7 (Type: Random) connected.
D NimBLEServer: << handleGapEvent
WhitelistedAdvertiser::update() - switch from: State_Broadcast to: State_Stopped
D NimBLEServer: >> handleGapEvent: 
D NimBLEServer: << handleGapEvent
Real voltage: 0000017.41 V
Is advertising: false
Is connected: true
Is bonded: true
Number of peer devices: 1
Ping value: 1000
LedControl::update() - state: Pairing
Pairing time remaining: 110 seconds...
D NimBLEServer: >> handleGapEvent: 
D NimBLEServer: << handleGapEvent
D NimBLEServer: >> handleGapEvent: 
D NimBLEServer: << handleGapEvent
D NimBLEServer: >> handleGapEvent: 
D NimBLEServer: << handleGapEvent
Pairing time remaining: 109 seconds...
Pairing time remaining: 108 seconds...
Pairing time remaining: 107 seconds...
Pairing time remaining: 106 seconds...
Real voltage: 0000017.41 V
Is advertising: false
Is connected: true
Is bonded: true
Number of peer devices: 1
Ping value: 1500
LedControl::update() - state: Pairing
Pairing time remaining: 105 seconds...
D NimBLEServer: >> handleGapEvent: 
D NimBLEServer: BLE_SM_IOACT_DISP; ble_sm_inject_io result: 0
D NimBLEServer: << handleGapEvent
Pairing time remaining: 104 seconds...
Pairing time remaining: 103 seconds...
Pairing time remaining: 102 seconds...
Pairing time remaining: 101 seconds...
Real voltage: 0000017.41 V
Is advertising: false
Is connected: true
Is bonded: true
Number of peer devices: 1
Ping value: 2000
LedControl::update() - state: Pairing
Pairing time remaining: 100 seconds...
Pairing time remaining: 99 seconds...
Pairing time remaining: 98 seconds...
Pairing time remaining: 97 seconds...
Pairing time remaining: 96 seconds...
Real voltage: 0000017.41 V
Is advertising: false
Is connected: true
Is bonded: true
Number of peer devices: 1
Ping value: 2500
LedControl::update() - state: Pairing
Pairing time remaining: 95 seconds...
Pairing time remaining: 94 seconds...
Pairing time remaining: 93 seconds...
D NimBLEServer: >> handleGapEvent: 
ServerCallbacks::onAuthenticationComplete()Connection Info:
  Peer ID Address: 44:e4:b1:46:dc:d7 (Type: Random)
  Peer OTA Address: 44:e4:b1:46:dc:d7 (Type: Random)
  Connection Handle: 1
  Security State:
    Encrypted: true
    Authenticated: true
    Bonded: true
    Key Size: 16
  Connection Parameters:
    Interval: 36
    Latency: 0
    Supervision Timeout: 500
    Role: Slave
D NimBLEServer: << handleGapEvent
D NimBLEServer: >> handleGapEvent: 
D NimBLEServer: << handleGapEvent
BluetoothController::pairingStateHandler(): isConnectedDeviceBonded() : true
BluetoothController::update() - switch from: State_Pairing to: State_Connected
D NimBLEServer: Gatt Read event
BatteryLockCallbacks::onRead() value: 1
D NimBLEServer: >> handleGapEvent: 
I NimBLEServer: subscribe event; attr_handle=8, subscribed: true
D NimBLEServer: << handleGapEvent
Real voltage: 0000017.41 V
Is advertising: false
Is connected: true
Is bonded: true
Number of peer devices: 1
Ping value: 3000
LedControl::update() - state: Connected
D NimBLEServer: Gatt Read event
BatteryLockCallbacks::onRead() value: 1
D NimBLEServer: Gatt Read event
BatteryLockCallbacks::onRead() value: 1
D NimBLEServer: Gatt Read event
BatteryLockCallbacks::onRead() value: 1
D NimBLEServer: Gatt Read event
BatteryLockCallbacks::onRead() value: 1
D NimBLEServer: Gatt Read event
BatteryLockCallbacks::onRead() value: 1
D NimBLEServer: >> handleGapEvent: 
I NimBLEServer: subscribe event; attr_handle=8, subscribed: false
D NimBLEServer: << handleGapEvent
D NimBLEServer: >> handleGapEvent: 
ServerCallbacks::onDisconnect() - Client with address: f0:5c:77:f5:bb:25 (Type: Public) disconnected. Reason: 531
D NimBLEServer: << handleGapEvent
WhitelistedAdvertiser::loadBondedDevices()
WhitelistedAdvertiser::loadBondedDevices() - number of bonded devices: 1
Adding address to whitelist: f0:5c:77:f5:bb:25
D NimBLEAdvertising: >> Advertising start: duration=0, dirAddr=NULL
D NimBLEAdvertising: << Advertising start
Whitelist Advertising to bonded devices!
WhitelistedAdvertiser::update() - switch from: State_Stopped to: State_Whitelisted
BluetoothController::update() - switch from: State_Connected to: State_Disconnected
BluetoothController::update() - switch from: State_Disconnected to: State_Advertising
Real voltage: 0000017.41 V
Is advertising: true
Is connected: false
Is bonded: true
Number of peer devices: 0
Ping value: 3500
LedControl::update() - state: Disconnected
Real voltage: 0000017.41 V
Is advertising: true
Is connected: false
Is bonded: true
Number of peer devices: 0
Ping value: 4000
LedControl::update() - state: Disconnected
D NimBLEServer: >> handleGapEvent: 
ServerCallbacks::onConnect()Connection Info:
  Peer ID Address: 44:e4:b1:46:dc:d7 (Type: Random)
  Peer OTA Address: 44:e4:b1:46:dc:d7 (Type: Random)
  Connection Handle: 1
  Security State:
    Encrypted: false
    Authenticated: false
    Bonded: false
    Key Size: 0
  Connection Parameters:
    Interval: 36
    Latency: 0
    Supervision Timeout: 500
    Role: Slave
Client with address: 44:e4:b1:46:dc:d7 (Type: Random) connected.
D NimBLEServer: << handleGapEvent
WhitelistedAdvertiser::update() - switch from: State_Whitelisted to: State_Stopped
BluetoothController::update() - switch from: State_Advertising to: State_Connected
D NimBLEServer: >> handleGapEvent: 
D NimBLEServer: << handleGapEvent
D NimBLEServer: >> handleGapEvent: 
D NimBLEServer: << handleGapEvent
D NimBLEServer: >> handleGapEvent: 
D NimBLEServer: << handleGapEvent
D NimBLEServer: >> handleGapEvent: 
D NimBLEServer: << handleGapEvent
Real voltage: 0000017.41 V
Is advertising: false
Is connected: true
Is bonded: true
Number of peer devices: 1
Ping value: 4500
LedControl::update() - state: Connected
Real voltage: 0000017.41 V
Is advertising: false
Is connected: true
Is bonded: true
Number of peer devices: 1
Ping value: 5000
LedControl::update() - state: Connected
Real voltage: 0000017.41 V
Is advertising: false
Is connected: true
Is bonded: true
Number of peer devices: 1
Ping value: 5500
LedControl::update() - state: Connected
D NimBLEServer: >> handleGapEvent: 
D NimBLEServer: BLE_SM_IOACT_DISP; ble_sm_inject_io result: 0
D NimBLEServer: << handleGapEvent
Real voltage: 0000017.41 V
Is advertising: false
Is connected: true
Is bonded: true
Number of peer devices: 1
Ping value: 6000
LedControl::update() - state: Connected
Real voltage: 0000017.41 V
Is advertising: false
Is connected: true
Is bonded: true
Number of peer devices: 1
Ping value: 6500
LedControl::update() - state: Connected
Real voltage: 0000017.41 V
Is advertising: false
Is connected: true
Is bonded: true
Number of peer devices: 1
Ping value: 7000
LedControl::update() - state: Connected
Real voltage: 0000017.41 V
Is advertising: false
Is connected: true
Is bonded: true
Number of peer devices: 1
Ping value: 7500
LedControl::update() - state: Connected
Real voltage: 0000017.41 V
Is advertising: false
Is connected: true
Is bonded: true
Number of peer devices: 1
Ping value: 8000
LedControl::update() - state: Connected
D NimBLEServer: >> handleGapEvent: 
ServerCallbacks::onAuthenticationComplete()Connection Info:
  Peer ID Address: 44:e4:b1:46:dc:d7 (Type: Random)
  Peer OTA Address: 44:e4:b1:46:dc:d7 (Type: Random)
  Connection Handle: 1
  Security State:
    Encrypted: false
    Authenticated: false
    Bonded: false
    Key Size: 0
  Connection Parameters:
    Interval: 36
    Latency: 0
    Supervision Timeout: 500
    Role: Slave
Attempted to authenticate while not pairing -> reject connection.
D NimBLEServer: << handleGapEvent
D NimBLEServer: >> handleGapEvent: 
ServerCallbacks::onDisconnect() - Client with address: 44:e4:b1:46:dc:d7 (Type: Random) disconnected. Reason: 534
D NimBLEServer: << handleGapEvent

Chips used:

board = seeed_xiao_esp32c3

Config options used:

; Bluetooth Configuration - BLE 5.0 Only
    -D CONFIG_BT_ENABLED=1    ; Master switch for Bluetooth
    -D CONFIG_BTDM_CTRL_MODE_BLE_ONLY=1    ; Enable only BLE 5.0, save memory
    -D CONFIG_BTDM_CTRL_MODE_BR_EDR_ONLY=0    ; Disable classic Bluetooth
    -D CONFIG_BTDM_CTRL_MODE_BTDM=0    ; Disable dual mode operation
    -D CONFIG_BT_NIMBLE_ENABLED=1    ; Use NimBLE stack (lighter than BlueDroid)
    -D CONFIG_BT_NIMBLE_MAX_CONNECTIONS=4    ; Maximum simultaneous BLE connections
    -D CONFIG_BT_NIMBLE_MAX_BONDS=8    ; Maximum number of bonded devices
    -D CONFIG_BT_NIMBLE_PINNED_TO_CORE=0    ; Run BLE stack on core 0
    -D CONFIG_BT_NIMBLE_TASK_STACK_SIZE=8192 ; Stack size for NimBLE tasks
    -D CONFIG_BT_NIMBLE_ATT_PREFERRED_MTU=50       ; Larger MTU size (default is 23)
    -D CONFIG_BT_NIMBLE_HOST_TASK_PRIORITY=5        ; Higher priority for BLE tasks
    ; Add these power saving flags
    -D CONFIG_BT_NIMBLE_LP_CONNECT=1           ; Enable low power connection mode
    -D CONFIG_BT_NIMBLE_ROLE_CENTRAL_DISABLED=1    ; Disable central role
    -D CONFIG_BT_NIMBLE_ROLE_OBSERVER_DISABLED=1   ; Disable observer role
    -D CONFIG_BT_NIMBLE_MESH=0                      ; Disable mesh if not needed
    -D CONFIG_BT_NIMBLE_CRYPTO_STACK_MBEDTLS=0      ; Use internal crypto (faster)

Security options:

        NimBLEDevice::setSecurityAuth(true, true, true);
        NimBLEDevice::setSecurityPasskey(pin);
        NimBLEDevice::setSecurityIOCap(BLE_HS_IO_DISPLAY_ONLY);
        NimBLEDevice::setSecurityInitKey(BLE_SM_PAIR_KEY_DIST_ID | BLE_SM_PAIR_KEY_DIST_ENC);
        NimBLEDevice::setSecurityRespKey(BLE_SM_PAIR_KEY_DIST_ID | BLE_SM_PAIR_KEY_DIST_ENC);

        uint8_t adv_flags = BLE_HS_ADV_F_DISC_GEN | BLE_HS_ADV_F_BREDR_UNSUP;
        advData.setFlags(adv_flags);
        fNimbleAdvertising->setAdvertisementData(advData);

The peer is an android phone with Android 13. Note that after sometime, the android tries to connect with the same address it did the bonding with f0:5c:77:f5:bb:25 which is the BLE Mac Address and then obviously everything works.

So I am not sure whether this is some bug or not.. Shouldn't the C3 be able to identify that the device is indeed bonded when the peer ID adress is random?

sanastasiou avatar Dec 26 '24 23:12 sanastasiou

Further testing reveals following. If after the bonding is finished in ESP32 the peer is disconnected withing the first 5 seconds, the peer still thinks it is not bonded.

After a little more time ( currently testing via trial and error ) the bonding information is also present on the peer device and then everything works as it should. So the question is, how do know if the peer has also received the bonding information before we attempt a disconnect? Apparently onAuthenticationComplete is not enough for this.

sanastasiou avatar Dec 28 '24 15:12 sanastasiou

Additional further testing..

  1. Bonding first with iOS device and afterwards with Android device works fine all the time.
  2. Bonding first with Android device leads to Android not seeing the bonded device after whitelisting is active. Bonding afterwards with iOS device also fixes miraculously the Android issue.
  3. Also found this: https://issuetracker.google.com/issues/242755161?pli=1 it appears, Android 13 is pure trashware.

Will switch over to Android 14 and try again. Will keep this thread updated.

sanastasiou avatar Jan 01 '25 14:01 sanastasiou

@sanastasiou this is also of interest: https://devzone.nordicsemi.com/f/nordic-q-a/38247/android-automatically-unbonding-on-reconnection

h2zero avatar Jan 02 '25 16:01 h2zero

@h2zero yeah, this is pretty much the issue. Disconnecting after a short time somehow removes bodning info from android while ESP32 thinks it is still bonded.. leading to all kinds of mess. Thanks for the link. I hope they fixed it in Android 14..

sanastasiou avatar Jan 02 '25 17:01 sanastasiou