Bluetooth device connection issue

[damian-ablett98]

After sending a BleManager.connect() request, a ConnectionObserver.onDeviceConnected() callback is received (after approx. 30s from calling connect) from the library but bluetooth device doesn't get connected (verified by checking the bluetooth connection indicator on the device). Additionally the BleManagerGattCallback.isRequiredServiceSupported() callback is not called by the library and hence we do not receive ConnectionObserver.onDeviceReady().

Given below is the snippet for the connect call:

manager.connect(device)
       .useAutoConnect(true)
       .retry(3, 250)
       .fail { _, code -> log.error("Connect request failed- status[$code]") }
       .enqueue()

The issue was noticed only for certain medical devices and is generally not reproducible. PS: We are using the nRF Android Scanner Compat Library, with scanMode set to SCAN_MODE_LOW_LATENCY, to discover the devices.

Any help will be greatly appreciated. Thanks!

[philips77]

Are you really getting ConnectionObserver.onDeviceConnected()? This looks like a timeout, so you should be getting ConnectionObserver.onDeviceFailedToConnected() with reason REASON_TIMEOUT. Have a look at: https://github.com/NordicSemiconductor/Android-BLE-Library/blob/ff965541b0835d84296c62dc1ae4dd9045e380b3/ble/src/main/java/no/nordicsemi/android/ble/BleManagerHandler.java#L1823-L1828 which calls: https://github.com/NordicSemiconductor/Android-BLE-Library/blob/ff965541b0835d84296c62dc1ae4dd9045e380b3/ble/src/main/java/no/nordicsemi/android/ble/BleManagerHandler.java#L1551-L1555

[philips77]

The only place where you would get onDeviceConnected() is here: https://github.com/NordicSemiconductor/Android-BLE-Library/blob/ff965541b0835d84296c62dc1ae4dd9045e380b3/ble/src/main/java/no/nordicsemi/android/ble/BleManagerHandler.java#L1754-L1760 which means that Android thinks the device has connected with status SUCCESS. If should then start service discovery and perhaps fail.

Do you have more logs from this event?

[damian-ablett98]

Are you really getting ConnectionObserver.onDeviceConnected()?

Yes, we are receiving the onDeviceConnected() callback and not the onDeviceFailedToConnected(). But it seems as though, isRequiredServiceSupported() and hence the onDeviceReady() is not invoked. Do you think this might be caused because we aren't invoking the connect() method correctly?

Do you have more logs from this event?

Unfortunately no, apart from our application logs for the callbacks. Is there any way to enable library level logs for the nordic library to gather more info on this issue?

Also we have noticed another rare issue where our peripherals are discovered repeatedly and does not connect for a long time. It takes many discovered-connect attempts before the peripheral connects successfully and in certain scenarios it doesn't connect at all(without any failed callbacks).

Please find our application logs below:

26-01-2022 16:29:13.902 DEBUG:: Device Discovered: 9C:35:83:00:AC:7B(RSSI:-72)
26-01-2022 16:29:13.916 INFO:: Connection request sent for: NiproBGM(9C:35:83:00:AC:7B)
26-01-2022 16:29:13.920 INFO:: Device connecting: NiproBGM(9C:35:83:00:AC:7B)
26-01-2022 16:29:17.918 DEBUG:: Device Discovered: 9C:35:83:00:AC:7B(RSSI:-66)
26-01-2022 16:29:17.924 INFO:: Connection request sent for: NiproBGM(9C:35:83:00:AC:7B)
26-01-2022 16:29:21.926 DEBUG:: Device Discovered: 9C:35:83:00:AC:7B(RSSI:-66)
26-01-2022 16:29:21.932 INFO:: Connection request sent for: NiproBGM(9C:35:83:00:AC:7B)
26-01-2022 16:29:25.932 DEBUG:: Device Discovered: 9C:35:83:00:AC:7B(RSSI:-66)
26-01-2022 16:29:25.937 INFO:: Connection request sent for: NiproBGM(9C:35:83:00:AC:7B)
26-01-2022 16:29:29.938 DEBUG:: Device Discovered: 9C:35:83:00:AC:7B(RSSI:-65)
26-01-2022 16:29:29.944 INFO:: Connection request sent for: NiproBGM(9C:35:83:00:AC:7B)
26-01-2022 16:29:33.946 DEBUG:: Device Discovered: 9C:35:83:00:AC:7B(RSSI:-65)
26-01-2022 16:29:33.951 INFO:: Connection request sent for: NiproBGM(9C:35:83:00:AC:7B)
26-01-2022 16:29:37.952 DEBUG:: Device Discovered: 9C:35:83:00:AC:7B(RSSI:-67)
26-01-2022 16:29:37.957 INFO:: Connection request sent for: NiproBGM(9C:35:83:00:AC:7B)
26-01-2022 16:29:41.959 DEBUG:: Device Discovered: 9C:35:83:00:AC:7B(RSSI:-68)
26-01-2022 16:29:41.964 INFO:: Connection request sent for: NiproBGM(9C:35:83:00:AC:7B)
26-01-2022 16:29:45.566 INFO:: Device connected: NiproBGM(9C:35:83:00:AC:7B)
26-01-2022 16:29:45.966 DEBUG:: Device Discovered: 9C:35:83:00:AC:7B(RSSI:-67)
26-01-2022 16:29:45.972 WARN:: Already connected to device: NiproBGM(9C:35:83:00:AC:7B)
26-01-2022 16:29:47.177 DEBUG:: Validating services and characteristics

Both these issues happen randomly. We have tried testing this on different android devices and BLE peripherals, but the results are the same.

[philips77]

You may enable logs by overriding log method in your ble manager implementation and logging from there.

[damian-ablett98]

Ok, thanks @philips77! We'll try to enable the logs and capture the issue when it happens.

[philips77]

Hello, any luck with the logs? Did you manage to fix your issue?

[DjToMeK27]

I also saw this issue trying to connect nonin pulse oximeter device. I get connected but no services found for like 20-30sec. It says device is waiting for "bond" and the state is Initializing. Then it prints some error bonding and then it initializes and discovers services but overall procedure is really slow.

[philips77]

Yes, the issue may be related to bonding. Remove bond information from Android and the device and try again.

I'm closing the issue due to inactivity.