Connection failed

[bpfingsten-crestron]

Description

After scanning and locating my ESP32 device I call the connect method, but this fails to connect and when I register a ESPBLEDelegate the periperalFailedToConnect is called with an error description of "Connection timeout. Unable to read BLE characteristic on time." I am able to use just CoreBluetooth code and discover my expected service (UUID: FFFF) and the characteristics of that service (UUID: FF01 and FF02). The device I am using has an LED that turns blue when it has a BLE connection which does happen for a few seconds before turning back to white indicating a waiting/pending status. The logs show that is discovering the service and characteristics...

10:08:36.637 | ESPBleTransport.peripheral(:didDiscoverServices:) (304) : Peripheral did discover services. 10:08:36.758 | ESPBleTransport.peripheral(:didDiscoverCharacteristicsFor:error:) (315) : Peripheral did discover chatacteristics. 10:08:36.762 | ESPBleTransport.peripheral(:didDiscoverDescriptorsFor:error:) (358) : Did sicover descriptor for characterisitic: <CBCharacteristic: 0x282bd02a0, UUID = FF01, properties = 0x8, value = (null), notifying = NO> 10:08:36.877 | ESPBleTransport.peripheral(:didDiscoverDescriptorsFor:error:) (358) : Did sicover descriptor for characterisitic: <CBCharacteristic: 0x282bd0120, UUID = FF02, properties = 0x12, value = (null), notifying = NO> 10:08:36.936 | ESPBleTransport.peripheral(_:didUpdateValueFor:error:) (365) : Did update value for descriptor: <CBDescriptor: 0x2801b05a0, UUID = Client Characteristic Configuration, value = (null)> 10:08:55.793 | ESPBleTransport.bleConnectionTimeout() (176) : Peripheral connection timeout occured.

I don't know how to proceed at this point.

To Reproduce Steps to reproduce the behavior:

1. Go to '...'
2. Click on '....' ...

Frequency 100%

Expected behavior Should connect to the device

Screenshots

ESP Device Information:

• ESP-IDF version: not sure
• Example referenced: not sure
• Board type: ESP32-WROVER-E (from ESP32 chip)

iOS information:

• Device type: iPhone
• Device model: iPhone 14
• iOS version: iOS 16.6
• App Version: 1.0

Provisioning information:

• ESPProvision iOS SDK version: 2.1.2
• Device type: BLE

• Security: Unsecure but tried both

  ESP Device logs: From the app: 10:08:26.439 | ESPProvisionManager.searchESPDevices(devicePrefix:transport:security:completionHandler:) (99) : Search ESPDevices called. 10:08:26.440 | ESPBleTransport.init(scanTimeout:deviceNamePrefix:proofOfPossession:username:) (100) : Initalising BLE transport class with scan timeout 5.0 10:08:26.443 | ESPBleTransport.scan(delegate:) (196) : Ble scan started... 10:08:26.460 | ESPBleTransport.centralManagerDidUpdateState(:) (258) : Bluetooth state on 10:08:26.508 | ESPBleTransport.centralManager(:didDiscover:advertisementData:rssi:) (274) : Peripheral devices discovered.["kCBAdvDataLocalName": FF2_5C0E2799, "kCBAdvDataTimestamp": 721850906.505408, "kCBAdvDataRxSecondaryPHY": 0, "kCBAdvDataIsConnectable": 1, "kCBAdvDataRxPrimaryPHY": 129] 10:08:26.510 | ESPDevice.init(name:security:transport:proofOfPossession:username:softAPPassword:advertisementData:) (149) : Intializing ESPDevice with name:FF25C0E2799, security:secure, transport:ble, proofOfPossession:nil and softAPPassword:nil 10:08:26.511 | ESPBleTransport.centralManager(:didDiscover:advertisementData:rssi:) (274) : Peripheral devices discovered.["kCBAdvDataTimestamp": 721850906.507284, "kCBAdvDataIsConnectable": 1, "kCBAdvDataRxPrimaryPHY": 129, "kCBAdvDataRxSecondaryPHY": 0, "kCBAdvDataLocalName": FF2_5C0E2799, "kCBAdvDataServiceUUIDs": <NSArrayM 0x2801e03f0>( 6E400001-B5A3-F393-E0A9-E50E24DCCA9E ) ] 10:08:26.512 | ESPDevice.init(name:security:transport:proofOfPossession:username:softAPPassword:advertisementData:) (149) : Intializing ESPDevice with name:FF25C0E2799, security:secure, transport:ble, proofOfPossession:nil and softAPPassword:nil 10:08:26.559 | ESPBleTransport.centralManager(:didDiscover:advertisementData:rssi:) (274) : Peripheral devices discovered.["kCBAdvDataRxSecondaryPHY": 0, "kCBAdvDataIsConnectable": 1, "kCBAdvDataTimestamp": 721850906.557611, "kCBAdvDataRxPrimaryPHY": 129] 10:08:26.560 | ESPDevice.init(name:security:transport:proofOfPossession:username:softAPPassword:advertisementData:) (149) : Intializing ESPDevice with name:CE-C02DV5LXMD6R, security:secure, transport:ble, proofOfPossession:nil and softAPPassword:nil 10:08:26.592 | ESPBleTransport.centralManager(:didDiscover:advertisementData:rssi:) (274) : Peripheral devices discovered.["kCBAdvDataTimestamp": 721850906.589628, "kCBAdvDataRxPrimaryPHY": 129, "kCBAdvDataIsConnectable": 0, "kCBAdvDataRxSecondaryPHY": 0] 10:08:26.595 | ESPBleTransport.centralManager(:didDiscover:advertisementData:rssi:) (274) : Peripheral devices discovered.["kCBAdvDataTimestamp": 721850906.594036, "kCBAdvDataIsConnectable": 1, "kCBAdvDataRxPrimaryPHY": 129, "kCBAdvDataRxSecondaryPHY": 0, "kCBAdvDataServiceUUIDs": <NSArrayM 0x2801e04e0>( FFFF ) , "kCBAdvDataManufacturerData": <ba040300 83000d01 32333431 43525830 34353238>] 10:08:26.596 | ESPDevice.init(name:security:transport:proofOfPossession:username:softAPPassword:advertisementData:) (149) : Intializing ESPDevice with name:DSS, security:secure, transport:ble, proofOfPossession:nil and softAPPassword:nil 10:08:26.598 | ESPBleTransport.centralManager(_:didDiscover:advertisementData:rssi:) (274) : Peripheral devices discovered.["kCBAdvDataRxPrimaryPHY": 129, "kCBAdvDataTimestamp": 721850906.594072, "kCBAdvDataServiceUUIDs": <NSArrayM 0x2801a2f10>( FFFF ) , "kCBAdvDataManufacturerData": <ba040300 83000d01 32333431 43525830 34353238 10023003 fd3f5436 4a3f773c ebf61400 00000000 00000000 000000>, "kCBAdvDataIsConnectable": 1, "kCBAdvDataRxSecondaryPHY": 0] 10:08:26.599 | ESPDevice.init(name:security:transport:proofOfPossession:username:softAPPassword:advertisementData:) (149) : Intializing ESPDevice with name:DSS, security:secure, transport:ble, proofOfPossession:nil and softAPPassword:nil 10:08:26.667 | ESPBleTransport.centralManager(_:didDiscover:advertisementData:rssi:) (274) : Peripheral devices discovered.["kCBAdvDataTimestamp": 721850906.66544, "kCBAdvDataRxPrimaryPHY": 129, "kCBAdvDataServiceUUIDs": <_NSArrayM 0x2801b0540>( 802A0000-4EF4-4E59-B573-2BED4A4AC159 ) , "kCBAdvDataIsConnectable": 1, "kCBAdvDataRxSecondaryPHY": 0, "kCBAdvDataManufacturerData": <4000006c 02>] 10:08:26.668 | ESPDevice.init(name:security:transport:proofOfPossession:username:softAPPassword:advertisementData:) (149) : Intializing ESPDevice with name:ET-2800 Series, security:secure, transport:ble, proofOfPossession:nil and softAPPassword:nil 10:08:26.752 | ESPBleTransport.centralManager(:didDiscover:advertisementData:rssi:) (274) : Peripheral devices discovered.["kCBAdvDataServiceUUIDs": <NSArrayM 0x2801aa910>( 03FE ) , "kCBAdvDataIsConnectable": 1, "kCBAdvDataRxSecondaryPHY": 0, "kCBAdvDataServiceData": { 03FE = {length = 18, bytes = 0x017110020001010000000000000000000000}; }, "kCBAdvDataTimestamp": 721850906.75098, "kCBAdvDataRxPrimaryPHY": 129] 10:08:26.753 | ESPDevice.init(name:security:transport:proofOfPossession:username:softAPPassword:advertisementData:) (149) : Intializing ESPDevice with name:Lenovo Smart Dock 27AFC5, security:secure, transport:ble, proofOfPossession:nil and softAPPassword:nil 10:08:26.755 | ESPBleTransport.centralManager(_:didDiscover:advertisementData:rssi:) (274) : Peripheral devices discovered.["kCBAdvDataRxSecondaryPHY": 0, "kCBAdvDataServiceData": { 03FE = {length = 18, bytes = 0x017110020001010000000000000000000000}; }, "kCBAdvDataTimestamp": 721850906.753227, "kCBAdvDataServiceUUIDs": <NSArrayM 0x2801e4750>( 03FE ) , "kCBAdvDataLocalName": Lenovo Smart Dock 27AFC5, "kCBAdvDataRxPrimaryPHY": 129, "kCBAdvDataIsConnectable": 1] 10:08:26.756 | ESPDevice.init(name:security:transport:proofOfPossession:username:softAPPassword:advertisementData:) (149) : Intializing ESPDevice with name:Lenovo Smart Dock 27AFC5, security:secure, transport:ble, proofOfPossession:nil and softAPPassword:nil 10:08:27.171 | ESPBleTransport.centralManager(_:didDiscover:advertisementData:rssi:) (274) : Peripheral devices discovered.["kCBAdvDataIsConnectable": 1, "kCBAdvDataManufacturerData": <4000006b 02>, "kCBAdvDataRxSecondaryPHY": 0, "kCBAdvDataRxPrimaryPHY": 129, "kCBAdvDataTimestamp": 721850907.170355, "kCBAdvDataServiceUUIDs": <_NSArrayM 0x2801e3720>( 802A0000-4EF4-4E59-B573-2BED4A4AC159 ) ] 10:08:27.173 | ESPDevice.init(name:security:transport:proofOfPossession:username:softAPPassword:advertisementData:) (149) : Intializing ESPDevice with name:ET-4800 Series, security:secure, transport:ble, proofOfPossession:nil and softAPPassword:nil 10:08:27.178 | ESPBleTransport.centralManager(:didDiscover:advertisementData:rssi:) (274) : Peripheral devices discovered.["kCBAdvDataLocalName": ET-2800 Series, "kCBAdvDataRxPrimaryPHY": 129, "kCBAdvDataRxSecondaryPHY": 0, "kCBAdvDataManufacturerData": <4000006c 02>, "kCBAdvDataServiceUUIDs": <NSArrayM 0x2801b9380>( 802A0000-4EF4-4E59-B573-2BED4A4AC159 ) , "kCBAdvDataIsConnectable": 1, "kCBAdvDataTimestamp": 721850907.177012] 10:08:27.179 | ESPDevice.init(name:security:transport:proofOfPossession:username:softAPPassword:advertisementData:) (149) : Intializing ESPDevice with name:ET-2800 Series, security:secure, transport:ble, proofOfPossession:nil and softAPPassword:nil 10:08:27.410 | ESPBleTransport.centralManager(_:didDiscover:advertisementData:rssi:) (274) : Peripheral devices discovered.["kCBAdvDataRxSecondaryPHY": 0, "kCBAdvDataServiceData": { 1826 = {length = 3, bytes = 0x012000}; }, "kCBAdvDataServiceUUIDs": <_NSArrayM 0x2801b9890>( 1826, Cycling Speed and Cadence, 1818 ) , "kCBAdvDataManufacturerData": <f400cc86 ec98832b 01>, "kCBAdvDataRxPrimaryPHY": 129, "kCBAdvDataIsConnectable": 0, "kCBAdvDataTimestamp": 721850907.408365] 10:08:27.411 | ESPDevice.init(name:security:transport:proofOfPossession:username:softAPPassword:advertisementData:) (149) : Intializing ESPDevice with name:C9/C10-832B, security:secure, transport:ble, proofOfPossession:nil and softAPPassword:nil 10:08:27.412 | ESPBleTransport.centralManager(:didDiscover:advertisementData:rssi:) (274) : Peripheral devices discovered.["kCBAdvDataLocalName": C9/C10-832B, "kCBAdvDataServiceUUIDs": <_NSArrayM 0x2801b0540>( 1826, Cycling Speed and Cadence, 1818 ) , "kCBAdvDataRxPrimaryPHY": 129, "kCBAdvDataTxPowerLevel": 0, "kCBAdvDataManufacturerData": <f400cc86 ec98832b 01>, "kCBAdvDataIsConnectable": 0, "kCBAdvDataServiceData": { 1826 = {length = 3, bytes = 0x012000}; }, "kCBAdvDataRxSecondaryPHY": 0, "kCBAdvDataTimestamp": 721850907.4103431] 10:08:27.414 | ESPDevice.init(name:security:transport:proofOfPossession:username:softAPPassword:advertisementData:) (149) : Intializing ESPDevice with name:C9/C10-832B, security:secure, transport:ble, proofOfPossession:nil and softAPPassword:nil 10:08:27.810 | ESPBleTransport.centralManager(:didDiscover:advertisementData:rssi:) (274) : Peripheral devices discovered.["kCBAdvDataRxSecondaryPHY": 0, "kCBAdvDataIsConnectable": 1, "kCBAdvDataTimestamp": 721850907.808724, "kCBAdvDataRxPrimaryPHY": 129] 10:08:27.812 | ESPDevice.init(name:security:transport:proofOfPossession:username:softAPPassword:advertisementData:) (149) : Intializing ESPDevice with name:CE-C02DV5LXMD6R, security:secure, transport:ble, proofOfPossession:nil and softAPPassword:nil 10:08:28.039 | ESPBleTransport.centralManager(:didDiscover:advertisementData:rssi:) (274) : Peripheral devices discovered.["kCBAdvDataIsConnectable": 0, "kCBAdvDataRxSecondaryPHY": 0, "kCBAdvDataTimestamp": 721850908.038304, "kCBAdvDataRxPrimaryPHY": 129] 10:08:31.030 | ESPBleTransport.centralManager(:didDiscover:advertisementData:rssi:) (274) : Peripheral devices discovered.["kCBAdvDataRxSecondaryPHY": 0, "kCBAdvDataRxPrimaryPHY": 129, "kCBAdvDataIsConnectable": 1, "kCBAdvDataTimestamp": 721850911.028445] 10:08:31.031 | ESPDevice.init(name:security:transport:proofOfPossession:username:softAPPassword:advertisementData:) (149) : Intializing ESPDevice with name:CE-C02DV5LXMD6R, security:secure, transport:ble, proofOfPossession:nil and softAPPassword:nil 10:08:31.387 | ESPBleTransport.centralManager(_:didDiscover:advertisementData:rssi:) (274) : Peripheral devices discovered.["kCBAdvDataRxSecondaryPHY": 0, "kCBAdvDataIsConnectable": 0, "kCBAdvDataTimestamp": 721850911.384437, "kCBAdvDataRxPrimaryPHY": 129] 10:08:31.462 | ESPBleTransport.stopScan(timer:) (214) : Ble scan stopped. 10:08:31.464 | ESPProvisionManager.peripheralsFound(peripherals:) (352) : Ble devices found :["FF25C0E2799": ESPProvision.ESPDevice, "C9/C10-832B": ESPProvision.ESPDevice, "ET-2800 Series": ESPProvision.ESPDevice, "DSS": ESPProvision.ESPDevice, "ET-4800 Series": ESPProvision.ESPDevice, "CE-C02DV5LXMD6R": ESPProvision.ESPDevice, "Lenovo Smart Dock 27AFC5": ESPProvision.ESPDevice] 2023-11-16T10:08:31-0800 debug device-assistant : [DeviceAssistant] found devices 2023-11-16T10:08:31-0800 debug device-assistant : [DeviceAssistant] Parsing message from byte data [3, 0, 131, 0] 2023-11-16T10:08:31-0800 debug device-assistant : [DeviceAssistant] Parsing message from byte data [13, 1, 50, 51, 52, 49, 67, 82, 88, 48, 52, 53, 50, 56] 2023-11-16T10:08:31-0800 debug device-assistant : [DeviceAssistant] Parsing message from byte data [16, 2, 48, 3, 253, 63, 84, 54, 74, 63, 119, 60, 235, 246, 20, 0, 0] 2023-11-16T10:08:31-0800 debug device-assistant : [DeviceAssistant] message data: [48, 3, 253, 63, 84, 54, 74, 63, 119, 60, 235, 246, 20, 0, 0] 2023-11-16T10:08:31-0800 debug device-assistant : [DeviceAssistant] Found the device 10:08:35.788 | ESPDevice.connect(delegate:completionHandler:) (165) : Connecting ESPDevice... 10:08:35.789 | ESPDevice.connect(delegate:completionHandler:) (169) : Start connecting ble device. 10:08:35.790 | ESPBleTransport.connect(peripheral:withOptions:delegate:) (159) : Connecting peripheral device... 10:08:35.791 | ESPBleTransport.connect(peripheral:withOptions:delegate:) (169) : Initiating timeout for connection completion. 10:08:36.222 | ESPBleTransport.centralManager(:didConnect:) (285) : Connected to peripheral. Discover services. 10:08:36.637 | ESPBleTransport.peripheral(:didDiscoverServices:) (304) : Peripheral did discover services. 10:08:36.758 | ESPBleTransport.peripheral(:didDiscoverCharacteristicsFor:error:) (315) : Peripheral did discover chatacteristics. 10:08:36.762 | ESPBleTransport.peripheral(:didDiscoverDescriptorsFor:error:) (358) : Did sicover descriptor for characterisitic: <CBCharacteristic: 0x282bd02a0, UUID = FF01, properties = 0x8, value = (null), notifying = NO> 10:08:36.877 | ESPBleTransport.peripheral(:didDiscoverDescriptorsFor:error:) (358) : Did sicover descriptor for characterisitic: <CBCharacteristic: 0x282bd0120, UUID = FF02, properties = 0x12, value = (null), notifying = NO> 10:08:36.936 | ESPBleTransport.peripheral(:didUpdateValueFor:error:) (365) : Did update value for descriptor: <CBDescriptor: 0x2801b05a0, UUID = Client Characteristic Configuration, value = (null)> 10:08:55.793 | ESPBleTransport.bleConnectionTimeout() (176) : Peripheral connection timeout occured. 10:08:55.794 | ESPBleTransport.disconnect() (186) : Cancelling peripheral connection. 10:08:55.796 | ESPDevice.peripheralFailedToConnect(peripheral:error:) (661) : Peripheral failed to connect. 2023-11-16T10:08:55-0800 error device-assistant : [DeviceAssistant] Device failed to connect: Failed to connect with BLE device 2023-11-16T10:09:51-0800 debug device-assistant : [DeviceAssistant] failed to connect to peripheral 10:09:51.433 | ESPBleTransport.centralManager(:didDisconnectPeripheral:error:) (295) : Disconnected with peripheral 10:09:51.434 | ESPDevice.peripheralDisconnected(peripheral:error:) (654) : Peripheral disconnected. 2023-11-16T10:09:52-0800 debug device-assistant : [DeviceAssistant] peripheral disconnected

Additional context Add any other context about the problem here.

[bpfingsten-crestron]

So after some review of the library code I see that its requiring a descriptor to be returned for each characteristic before it changes state to connected and my FF01 characteristic is not responding with a descriptor. ESPBleTransport::func peripheral(: CBPeripheral, didUpdateValueFor descriptor: CBDescriptor, error : Error?) is the function involved and does the state change to connected or at least it kills the timer and signals the connected state.

[vikas-chandra-mnnit]

Hi @bpfingsten-crestron, your observation is accurate. The SDK attempts to read the value for each descriptor in a characteristic, after which it propagates the BLE connection successful message. A 20-second timer is established for this process, and if not completed, the connection terminates. Please feel free to reach out if you require additional assistance on this matter.