NordicSemiconductor / Android-BLE-Library

A library that makes working with Bluetooth LE on Android a pleasure. Seriously.
BSD 3-Clause "New" or "Revised" License
2.03k stars 417 forks source link

Connection retries block on the main thread #514

Closed krioru closed 1 year ago

krioru commented 1 year ago

Hello.

I have the following suspend connect function:

  suspend fun connect() {
    connect(device)
      .retry(4)
      .useAutoConnect(false)
      .timeout(30000)
      .suspend()
  }

Which I call from my ViewModel as follows:

  private fun connectToDevice() {
    val exceptionHandler = CoroutineExceptionHandler { _, exception -> }
    viewModelScope.launch(Dispatchers.IO + exceptionHandler) {
      bluetoothController.connect()
    }
  }

I call it on the Dispatchers.IO thread pool.

If it can't connect on the first try, it retries 4 more times. However before every retry attempt, UI of my app freezes for a short duration, which shouldn't be happening, because UI is on the Main Thread, which doesn't belong to the IO pool.

I assume this is caused by the following code in the internalConnect() function of the BleManagerHandler: https://github.com/NordicSemiconductor/Android-BLE-Library/blob/004e6645dfb391c253c13a8b75d38a86b0aeacc2/ble/src/main/java/no/nordicsemi/android/ble/BleManagerHandler.java#L621-L634

It waits for 200 ms before every retry, but for some reason it waits on the Main Thread instead of a thread on Dispatchers.IO.

Also, it would be nice to get access to attempt and retries variables, so the attempt number could be shown in UI.

Thank you.

philips77 commented 1 year ago

You're right. Have a look here: https://github.com/NordicSemiconductor/Android-BLE-Library/blob/004e6645dfb391c253c13a8b75d38a86b0aeacc2/ble/src/main/java/no/nordicsemi/android/ble/BleManagerHandler.java#L2088-L2096

The delay is made using postDelayed(...) method, which is using the handler. By default it is using the main looper: https://github.com/NordicSemiconductor/Android-BLE-Library/blob/004e6645dfb391c253c13a8b75d38a86b0aeacc2/ble/src/main/java/no/nordicsemi/android/ble/BleManager.java#L163-L165 Actually, the intention for this handler was to call user callbacks, not to perform delayed operations.

I think it would be better to create a new Handler there, which takes the looper of the current thread.

krioru commented 1 year ago

I'm not using the delay of the retry() function: I call .retry(4) without delay. Actually, this delay doesn't block on the main thread (I tried calling .retry(4, 3000) and for 3 seconds of delay UI stayed responsive). I'm talking about the following line:

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

which is called right after the 'connection delay' and it blocks on the main thread.

Here's the log snippet of calling .retry(4, 3000):

Retrying...
gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, LE 1M)
[Callback] Connection state changed with status: 133 and new state: 0 (DISCONNECTED)
Error: (0x85): GATT ERROR
wait(3000)
gatt.close()
wait(200)
Retrying...

UI is frozen on wait(200). UI is NOT frozen on wait(3000).

I'm using the default constructor:

https://github.com/NordicSemiconductor/Android-BLE-Library/blob/004e6645dfb391c253c13a8b75d38a86b0aeacc2/ble/src/main/java/no/nordicsemi/android/ble/BleManager.java#L163-L165

krioru commented 1 year ago

So how do I properly use a different Handler?

I tried the following.

I added handler to my class as a parameter:

class BleConnectionManager(
  context: Context,
  private val device: BluetoothDevice,
  handler: Handler
) : BleManager(context, handler)

In viewModel changed the connect function:

fun connectToDevice(bleDevice: BluetoothDevice) {
  val exceptionHandler = CoroutineExceptionHandler { _, exception ->
    Log.e("BleConnection", "$exception")
  }

  viewModelScope.launch(Dispatchers.IO + exceptionHandler) {
    Looper.prepare()
    bleConnectionManager = BleConnectionManager(
      context = context,
      device = bleDevice,
      handler = Handler(Looper.myLooper() ?: Looper.getMainLooper())
    )
    bleConnectionManager?.connect()
  }
}

Connect function of the manager is still the same:

  suspend fun connect() {
    connect(device)
      .retry(4)
      .useAutoConnect(false)
      .timeout(30000)
      .suspend()
  }

I tried connecting with that method, but it didn't work. Connection was opened (I saw that on the peripheral device), but no further actions were performed.

I examined the logs and found out that none of the callbacks worked:

D  Attempting to connect to CC:86:EC:79:4B:43
V  Connecting...
D  gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, LE 1M)

And that's it. So there was no log that device was connected and also no service discovery was ever started, no initialize() queue was executed, connection state was never changed and BleManager.stateAsFlow() was never updated. Therefore I had no feedback at all in the UI.

So what did I do wrong and is there any example of using custom Handler?

krioru commented 1 year ago

Managed to get it working using HandlerThread:

In viewModel:

private var bleCallbackThread: HandlerThread? = null

fun connectToDevice(bleDevice: BluetoothDevice) {

  bleCallbackThread = HandlerThread("bleCallbackThread")
  if (bleCallbackThread?.isAlive == false) {
    bleCallbackThread?.start()
  }

  val exceptionHandler = CoroutineExceptionHandler { _, exception ->
    Log.e("BleConnection", "$exception")
  }

  viewModelScope.launch(Dispatchers.IO + exceptionHandler) {
    bleConnectionManager = BleConnectionManager(
      context = context,
      device = bleDevice,
      handler = Handler(bleCallbackThread?.looper ?: Looper.getMainLooper())
    )
    bleConnectionManager?.connect()
  }
}

On disconnect event:

bleCallbackThread?.quitSafely()
krioru commented 1 year ago

Another issue regarding the 200ms Thread sleep:

If I cancel the connection attempt using cancelQueue() precisely during the 200 ms Thread sleep, state of the connection doesn't change. Connection eventually times out and gatt.close() and onServicesInvalidated() are called. However BleManager.state doesn't change and no flow emission happens on BleManager.stateAsFlow(). In other words, app UI has no idea what happened and still hangs in CONNECTING state.

The only solution I found is to pass a callback function to the BleManager implementation class' constructor and call this callback from onServicesInvalidated(), where I update my UI state flow with DISCONNECTED state.

philips77 commented 1 year ago

Managed to get it working using HandlerThread

This has to be fixed in the library. I'm doing it just now.

philips77 commented 1 year ago

So what did I do wrong and is there any example of using custom Handler?

It may be that the looper created in the coroutine has already been killed.

krioru commented 1 year ago

2.7.0 release didn't fix the behavior when disconnect is cancelled during 200 ms wait, it got worse.

How it was before (2.6.1): If disconnect is cancelled during the Thread.sleep(200), connection state and BleManager.stateAsFlow() didn't get updated with the ConnectionState.Disconnected, so the main app didn't know what happened. However the connection itself was eventually cancelled/timed out after the first retry:

D  Attempting to connect to 58:8E:81:66:A5:DD
D  Disconnect reason: UNKNOWN
V  Connecting...
D  gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, LE 1M)
D  [Callback] Connection state changed with status: 133 and new state: 0 (DISCONNECTED)
W  Error: (0x85): GATT ERROR
D  wait(300)
D  gatt.close()
D  wait(200)
D  Attempting to manually disconnect. Physical state = 1
W  Request cancelled
V  Retrying...
D  gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, LE 1M)
D  [Callback] Connection state changed with status: 133 and new state: 0 (DISCONNECTED)
W  Error: (0x85): GATT ERROR
W  Connection attempt timed out
D  gatt.close()
D  onServicesInvalidated()

How it is now (2.7.0):

D  Attempting to connect to 58:8E:81:66:A5:DD
D  Disconnect reason: UNKNOWN
V  Connecting...
D  gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, LE 1M)
D  [Callback] Connection state changed with status: 133 and new state: 0 (DISCONNECTED)
W  Error: (0x85): GATT ERROR
D  wait(300)
D  gatt.close()
D  wait(200)
D  Attempting to manually disconnect. Physical state = 1
W  Request cancelled

Nothing happens after Request cancelled. No retry, no connection state update, no onServicesInvalidated() call. Connection state forever equals to Connecting.

Before, I could read the connection state from BleManager.getConnectionState() and it would eventually return BluetoothProfile.STATE_DISCONNECTED, but in 2.7.0 it always returns BluetoothProfile.STATE_CONNECTING.