espressif / esp-idf

Espressif IoT Development Framework. Official development framework for Espressif SoCs.
Apache License 2.0
13.79k stars 7.31k forks source link

[TW#17123] BLE security #2 #1412

Closed chegewara closed 6 years ago

chegewara commented 6 years ago

When we are trying to setup gatt_secure_server example with those settings

we have unexpected behavior. First logs from connecting esp32 with windows 10 laptop:

V (207668) SEC_GATTS_DEMO: event = e

I (207668) SEC_GATTS_DEMO: ESP_GATTS_CONNECT_EVT
V (207668) SEC_GATTS_DEMO: event = 4

E (207678) BT: Security Manager: BTM_SetEncryption busy, enqueue request

V (207678) SEC_GATTS_DEMO: GAP_EVT, event 10

E (207688) BT: Non bonding: No keys will be exchanged
E (207688) BT: lmp_version_below LMP version 6 < 8
E (207908) BT: Security Manager: BTM_SetEncryption not connected

D (207918) nvs: nvs_open_from_partition bt_config.conf 1
D (207918) nvs: nvs_set_blob bt_cfg_key 560
D (207918) nvs: nvs_close 7
V (207918) SEC_GATTS_DEMO: GAP_EVT, event 8

I (207928) SEC_GATTS_DEMO: remote BD_ADDR: 80a58982f5d2
I (207928) SEC_GATTS_DEMO: address type = 0
I (207938) SEC_GATTS_DEMO: pair status = fail
I (207938) SEC_GATTS_DEMO: Bonded devices number : 1

I (207948) SEC_GATTS_DEMO: Bonded devices list : 1

I (207948) SEC_GATTS_DEMO: e8 68 fd 3f f5 d2
E (208088) BT: btm_sec_clr_temp_auth_service() - no dev CB

E (208088) BT: Device not found

E (208088) BT: BTA got unregistered event id 31

E (208098) BT: BTA got unregistered event id 31

V (208098) SEC_GATTS_DEMO: event = f

I (208098) SEC_GATTS_DEMO: ESP_GATTS_DISCONNECT_EVT
V (208108) SEC_GATTS_DEMO: GAP_EVT, event 6

I (208108) SEC_GATTS_DEMO: advertising start success
V (208508) SEC_GATTS_DEMO: event = e

I (208508) SEC_GATTS_DEMO: ESP_GATTS_CONNECT_EVT
V (208508) SEC_GATTS_DEMO: event = 4

E (208518) BT: Non bonding: No keys will be exchanged
E (208518) BT: lmp_version_below LMP version 6 < 8
V (209288) SEC_GATTS_DEMO: GAP_EVT, event 20

D (209338) nvs: nvs_open_from_partition bt_config.conf 1
D (209348) nvs: nvs_set_blob bt_cfg_key 594
D (209348) nvs: nvs_close 8
V (209348) SEC_GATTS_DEMO: GAP_EVT, event 8

I (209348) SEC_GATTS_DEMO: remote BD_ADDR: 80a58982f5d2
I (209358) SEC_GATTS_DEMO: address type = 0
I (209358) SEC_GATTS_DEMO: pair status = success
I (209368) SEC_GATTS_DEMO: Bonded devices number : 2

I (209368) SEC_GATTS_DEMO: Bonded devices list : 2

I (209378) SEC_GATTS_DEMO: 64 67 fd 3f 02 00
I (209378) SEC_GATTS_DEMO: 00 00 00 00 00 00
V (209658) SEC_GATTS_DEMO: event = 1

V (209698) SEC_GATTS_DEMO: event = 1

V (209738) SEC_GATTS_DEMO: event = 1

V (213088) SEC_GATTS_DEMO: event = f

I (213088) SEC_GATTS_DEMO: ESP_GATTS_DISCONNECT_EVT
V (213088) SEC_GATTS_DEMO: GAP_EVT, event 6

I (213088) SEC_GATTS_DEMO: advertising start success

Second one logs from connecting with android phone. Samsung SGS 4 with android 5. Long time to connect and quick auto-disconnect:

I (678) SEC_GATTS_DEMO: advertising start success
V (7748) SEC_GATTS_DEMO: event = e

I (7748) SEC_GATTS_DEMO: ESP_GATTS_CONNECT_EVT
E (7748) BT: Non bonding: No keys will be exchanged
E (7748) BT: lmp_version_below LMP version 6 < 8
V (8378) SEC_GATTS_DEMO: GAP_EVT, event 8

I (8378) SEC_GATTS_DEMO: remote BD_ADDR: 781fdbc0c7f3
I (8378) SEC_GATTS_DEMO: address type = 0
I (8388) SEC_GATTS_DEMO: pair status = success
I (8388) SEC_GATTS_DEMO: Bonded devices number : 1

I (8398) SEC_GATTS_DEMO: Bonded devices list : 1

I (8398) SEC_GATTS_DEMO: 58 63 fd 3f c7 f3 
V (9758) SEC_GATTS_DEMO: GAP_EVT, event 20

V (15058) SEC_GATTS_DEMO: event = f

I (15058) SEC_GATTS_DEMO: ESP_GATTS_DISCONNECT_EVT
V (15058) SEC_GATTS_DEMO: GAP_EVT, event 6

I (15058) SEC_GATTS_DEMO: advertising start success
chegewara commented 6 years ago

When we are lucky and we are connected with nRF for long enough to perform some action then read/write action lasts for few seconds (logs from the same session):

android:

nRF Connect, 2017-12-20
ESP_BLE_SECURITY (50:B7:BB:F9:95:7C)
V   11:19:05.165    Connecting to 50:B7:BB:F9:95:7C...
D   11:19:05.166    gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE) (hidden)
D   11:19:05.404    [Callback] Connection state changed with status: 0 and new state: CONNECTED (2)
I   11:19:05.404    Connected to 50:B7:BB:F9:95:7C
D   11:19:05.416    [Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
V   11:19:05.416    Discovering services...
D   11:19:05.416    gatt.discoverServices()
D   11:19:05.444    [Broadcast] Action received: android.bluetooth.device.action.BOND_STATE_CHANGED, bond state changed to: BOND_BONDING (11)
D   11:19:06.078    [Broadcast] Action received: android.bluetooth.device.action.BOND_STATE_CHANGED, bond state changed to: BOND_BONDED (12)
I   11:19:06.079    Device bonded
D   11:19:36.628    [Callback] Services discovered with status: 0
I   11:19:36.629    Services discovered
V   11:19:36.649    Generic Attribute (0x1801)
- Service Changed [I] (0x2A05)
Generic Access (0x1800)
- Device Name [R] (0x2A00)
- Appearance [R] (0x2A01)
- Central Address Resolution [R] (0x2AA6)
Health Thermometer (0x1809)
- Heart Rate Measurement [N] (0x2A37)
   Client Characteristic Configuration (0x2902)
- Body Sensor Location [R] (0x2A38)
- Heart Rate Control Point [R W] (0x2A39)
V   11:19:58.455    Enabling notifications for 00002a37-0000-1000-8000-00805f9b34fb
D   11:19:58.455    gatt.setCharacteristicNotification(00002a37-0000-1000-8000-00805f9b34fb, true)
D   11:19:58.457    gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x0100)
I   11:20:01.869    Data written to descr. 00002902-0000-1000-8000-00805f9b34fb, value: (0x) 01-00
A   11:20:01.869    "Notifications enabled" sent
V   11:20:01.897    Notifications enabled for 00002a37-0000-1000-8000-00805f9b34fb
V   11:20:05.911    Disabling notifications for 00002a37-0000-1000-8000-00805f9b34fb
D   11:20:05.911    gatt.setCharacteristicNotification(00002a37-0000-1000-8000-00805f9b34fb, false)
D   11:20:05.912    gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x0000)
I   11:20:09.065    Data written to descr. 00002902-0000-1000-8000-00805f9b34fb, value: (0x) 00-00
A   11:20:09.065    "Notifications and indications disabled" sent
V   11:20:09.078    Notifications and indications disabled for 00002a37-0000-1000-8000-00805f9b34fb
V   11:20:44.016    Reading characteristic 00002a00-0000-1000-8000-00805f9b34fb
D   11:20:44.016    gatt.readCharacteristic(00002a00-0000-1000-8000-00805f9b34fb)
I   11:20:47.097    Read Response received from 00002a00-0000-1000-8000-00805f9b34fb, value: (0x) 45-53-50-5F-42-4C-45-5F-53-45-43-55-52-49-54-59, "ESP_BLE_SECURITY"
A   11:20:47.097    "ESP_BLE_SECURITY" received
D   11:21:21.955    [Callback] Connection state changed with status: 14 and new state: DISCONNECTED (0)
D   11:21:21.979    [Broadcast] Action received: android.bluetooth.device.action.ACL_DISCONNECTED
E   11:21:21.989    Error 14 (0xe): UNKNOWN (14)
I   11:21:21.989    Disconnected

esp32:

V (25048) SEC_GATTS_DEMO: event = e

I (25048) SEC_GATTS_DEMO: ESP_GATTS_CONNECT_EVT
E (25048) BT: Non bonding: No keys will be exchanged
E (25048) BT: lmp_version_below LMP version 6 < 8
D (25678) nvs: nvs_open_from_partition bt_config.conf 1
D (25678) nvs: nvs_set_blob bt_cfg_key 250
D (25678) nvs: nvs_close 4
V (25678) SEC_GATTS_DEMO: GAP_EVT, event 8

I (25688) SEC_GATTS_DEMO: remote BD_ADDR: 781fdbc0c7f3
I (25688) SEC_GATTS_DEMO: address type = 0
I (25698) SEC_GATTS_DEMO: pair status = success
I (25698) SEC_GATTS_DEMO: Bonded devices number : 1

I (25708) SEC_GATTS_DEMO: Bonded devices list : 1

I (25708) SEC_GATTS_DEMO: f0 60 fd 3f 02 00
V (27058) SEC_GATTS_DEMO: GAP_EVT, event 20

V (79888) SEC_GATTS_DEMO: event = 2

I (79888) SEC_GATTS_DEMO: ESP_GATTS_WRITE_EVT, write value:
I (79888) SEC_GATTS_DEMO: 01 00
V (87098) SEC_GATTS_DEMO: event = 2

I (87098) SEC_GATTS_DEMO: ESP_GATTS_WRITE_EVT, write value:
I (87098) SEC_GATTS_DEMO: 00 00
V (156908) SEC_GATTS_DEMO: event = f

I (156908) SEC_GATTS_DEMO: ESP_GATTS_DISCONNECT_EVT
V (156908) SEC_GATTS_DEMO: GAP_EVT, event 6

I (156908) SEC_GATTS_DEMO: advertising start success

esp-idf commit c69af42 but it exists also with master latest commit.