STATE_DISCONNECTED not handle right for connecting BONDED device with useAutoConnect(true)

[kkkbird]

If connect a bonded device with useAutoConnect(true), and the BluetoothProfile.DISCONNECTED signal is received after BluetoothProfile.STATE_CONNECTED but before initialization is completed, then although connectRequest will show success, the device will actually be disconnected. In addition, calling manager.isConnected() after that will also return true despite the disconnection.

2023-05-18 16:06:44.242 26159-26159 nordic-lib     D  gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, LE 1M)
2023-05-18 16:06:45.753 26159-26159 nordic-lib     D  [Callback] Connection state changed with status: 0 and new state: 2 (CONNECTED)
2023-05-18 16:06:45.753 26159-26159 nordic-lib     I  Connected to CA:F7:23:23:59:67
2023-05-18 16:06:45.754 26159-26159 nordic-lib     D  wait(1600)
2023-05-18 16:06:47.356 26159-26159 nordic-lib     D  gatt.discoverServices()
2023-05-18 16:06:47.366 26159-26159 nordic-lib     I  Services discovered
2023-05-18 16:06:47.368 26159-26159 nordic-lib     D  gatt.requestMtu(512)
2023-05-18 16:06:51.640 26159-26159 nordic-lib     E  Error (0x85): GATT ERROR
2023-05-18 16:06:51.640 26159-26159 nordic-lib     D  gatt.readCharacteristic(00002a28-0000-1000-8000-00805f9b34fb)
2023-05-18 16:06:51.644 26159-26159 nordic-lib     D  [Callback] Connection state changed with status: 8 and new state: 0 (DISCONNECTED)
2023-05-18 16:06:51.645 26159-26159 nordic-lib     W  Error: (0x8): GATT CONN TIMEOUT
2023-05-18 16:06:51.647 26159-26159 nordic-lib     D  autoConnect = false called failed; retrying with autoConnect = true
2023-05-18 16:06:51.648 26159-26159 nordic-lib     D  gatt.readCharacteristic(00002a27-0000-1000-8000-00805f9b34fb)
2023-05-18 16:06:51.648 26159-26159 nordic-lib     D  gatt.readCharacteristic(00002a25-0000-1000-8000-00805f9b34fb)
2023-05-18 16:06:51.649 26159-26159 nordic-lib     D  gatt.readCharacteristic(00002a24-0000-1000-8000-00805f9b34fb)
2023-05-18 16:06:51.649 26159-26159 nordic-lib     D  gatt.readCharacteristic(00002a23-0000-1000-8000-00805f9b34fb)
2023-05-18 16:06:51.649 26159-26159 nordic-lib     D  gatt.setCharacteristicNotification(0000feb2-0000-1000-8000-00805f9b34fb, true)
2023-05-18 16:06:51.651 26159-26159 nordic-lib     D  gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x02-00)
2023-05-18 16:06:51.655 26159-26159 nordic-lib     D  gatt.setCharacteristicNotification(0000fe03-0000-1000-8000-00805f9b34fb, true)
2023-05-18 16:06:51.657 26159-26159 nordic-lib     D  gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x01-00)
2023-05-18 16:06:51.658 26159-26159 DeviceWrapper  D  connectRequest done: CA:F7:23:23:59:67, isConnected:true, isReady:true 

i just tested it on 2.5.1 and the code doesn't seem to have been modified in latest repo. this could be caused by the following code is not handling the connected field properly and call internalConnect().

https://github.com/NordicSemiconductor/Android-BLE-Library/blob/004e6645dfb391c253c13a8b75d38a86b0aeacc2/ble/src/main/java/no/nordicsemi/android/ble/BleManagerHandler.java#L2098C1-L2103

In order to make it easier to reproduce, you can increase the value of getServiceDiscoveryDelay(boned) to a larger value such as 3000 (default for bond device is 1600 now), and then power off the device immediately when you see the log [Callback] Connection state changed with status: 0 and new state: 2 (CONNECTED).

furthermore, i have noticed that in some situations the connectRequest.done() callback will return isReady false, but I have not yet investigated this issue further. and it may be necessary to review the code related to connection retry for the same reason.

[philips77]

Thank you for the bug report, reproduction steps and log! I will look into it. Have a nice day.

[philips77]

I'm about to release a version 2.7 of BLE library. Could you find some time and try with it? I did some fixes regarding connection states.

[kkkbird]

sorry for late reply, just back from vacation,

i have tested 2.7, and the issue still remain. please review the log below, the connect request was completed but connection state remain 'INITIALIZING'. if i call connect() again, it succeeds immediately even the device is powered off

2023-10-07 15:48:26.808 27663-27663 nordic-lib    I  Connected to C1:BB:04:F0:6B:08
2023-10-07 15:48:26.809 27663-27663 nordic-lib    D  wait(1600)
2023-10-07 15:48:26.812 27663-27663 MyService     D  getConnectionState: INITIALIZING
2023-10-07 15:48:28.411 27663-27885 nordic-lib    D  gatt.discoverServices()
2023-10-07 15:48:28.427 27663-27663 nordic-lib    I  Services discovered
2023-10-07 15:48:28.432 27663-27663 nordic-lib    D  gatt.readCharacteristic(00002a25-0000-1000-8000-00805f9b34fb)
2023-10-07 15:48:33.375 27663-27663 nordic-lib    E  Error (0x85): GATT ERROR
2023-10-07 15:48:33.376 27663-27663 nordic-lib    D  gatt.readCharacteristic(00002a23-0000-1000-8000-00805f9b34fb)
2023-10-07 15:48:33.378 27663-27663 nordic-lib    D  [Callback] Connection state changed with status: 8 and new state: 0 (DISCONNECTED)
2023-10-07 15:48:33.378 27663-27663 nordic-lib    W  Error: (0x8): GATT CONN TIMEOUT
2023-10-07 15:48:33.379 27663-27663 nordic-lib    D  autoConnect = false called failed; retrying with autoConnect = true
2023-10-07 15:48:33.380 27663-27663 nordic-lib    D  gatt.readCharacteristic(00002a24-0000-1000-8000-00805f9b34fb)
2023-10-07 15:48:33.382 27663-27663 nordic-lib    D  gatt.readCharacteristic(00002a28-0000-1000-8000-00805f9b34fb)
2023-10-07 15:48:33.382 27663-27663 nordic-lib    D  gatt.readCharacteristic(00002a27-0000-1000-8000-00805f9b34fb)
2023-10-07 15:48:33.383 27663-27663 nordic-lib    D  gatt.requestMtu(512)
2023-10-07 15:48:33.388 27663-27663 MyService     I  connect result: false

[kkkbird]

@philips77 I've created a PR(https://github.com/NordicSemiconductor/Android-BLE-Library/pull/555) to fix this issue, may you please check it? thank you.