Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Significant BLE Slowness After Reconnection on Android 15 QPR1 with RxAndroidBle #858

Open
yd-threra-and opened this issue Sep 4, 2024 · 4 comments
Labels
awaiting feedback bug Bug that is caused by the library

Comments

@yd-threra-and
Copy link

Describe the bug
After successfully connecting and bonding with a BLE device using RxAndroidBle, subsequent connections experience significant delays, particularly during MTU requests and characteristic read/write operations. This issue is observed primarily on devices running Android 15 QPR1 Beta and appears to be related to changes in the Bluetooth stack on this version.

To Reproduce
Steps to reproduce the behavior:

  1. Pair and connect to a BLE device using RxAndroidBle.
  2. Disconnect the device or restart the BLE peripheral.
  3. Attempt to reconnect and perform the same operations.
  4. Observe the significant delay in operations during the reconnection phase.

Expected behavior
BLE connections should be stable and fast across initial and subsequent reconnections, similar to the behavior observed on Android 14 and below.

Smartphone:

  • Device: Google Pixel 6, Google Pixel 9
  • OS: Android 15 QPR1 Beta 4.1 (Build: AP41.240726.010 - August 29, 2024)
  • Library version: RxAndroidBle 1.18.1

Logs from the application when bug occurs

  • Start of connection and noticeable delay during MTU request
    2024-09-04 19:03:43.205 12221-12439 [Bluetooth...vity L:119 app.theranica.neriviomigra D QUEUED ConnectOperation(128601542)
    2024-09-04 19:03:43.207 12221-12361 [Bluetooth...vity L:119 app.theranica.neriviomigra D STARTED ConnectOperation(128601542)
    2024-09-04 19:03:43.211 12221-12363 BluetoothGatt app.theranica.neriviomigra D connect() - device: XX:XX:XX:XX:17:3F, auto: false
    2024-09-04 19:03:43.590 12221-12461 BluetoothGatt app.theranica.neriviomigra D onClientConnectionState() - status=0 clientIf=6 connected=true device=00:A0:50:0D:17:3F
    2024-09-04 19:03:44.600 12221-12451 [Bluetooth...$2$2 L:352 app.theranica.neriviomigra D Requesting MTU
    2024-09-04 19:03:44.614 12221-12363 BluetoothGatt app.theranica.neriviomigra D configureMTU() - device: XX:XX:XX:XX:17:3F mtu: 512
    2024-09-04 19:03:47.607 12221-12453 [Bluetooth...$2$1 L:470 app.theranica.neriviomigra D Retrying MTU request: attempt 1
    2024-09-04 19:03:48.928 12221-12461 BluetoothGatt app.theranica.neriviomigra D onConfigureMTU() - Device=00:A0:50:0D:17:3F mtu=512 status=0
    2024-09-04 19:03:48.937 12221-13137 [Bluetooth...vity L:119 app.theranica.neriviomigra D FINISHED MtuRequestOperation(104128157) in 4328 ms

  • Delay in characteristic read after service discovery
    2024-09-04 19:03:48.958 12221-12363 BluetoothGatt app.theranica.neriviomigra D discoverServices() - device: XX:XX:XX:XX:17:3F
    2024-09-04 19:03:48.967 12221-12461 BluetoothGatt app.theranica.neriviomigra D onSearchComplete() = Device=00:A0:50:0D:17:3F Status=0
    2024-09-04 19:03:48.973 12221-13137 [Bluetooth...vity L:119 app.theranica.neriviomigra D STARTED CharacteristicReadOperation(204334072)
    2024-09-04 19:03:50.909 12221-12461 [Bluetooth...vity L:118 app.theranica.neriviomigra I MAC='00:A0:50:0D:17:3F' onCharacteristicRead(), status=0, value=[uuid='71387662-eb78-11e6-b006-92361f002671', hexValue=[31, 20, 30, 20, 65, 62, 39, 33, ...]]
    2024-09-04 19:03:50.913 12221-13137 [Bluetooth...vity L:119 app.theranica.neriviomigra D FINISHED CharacteristicReadOperation(204334072) in 1938 ms

  • Further delays in characteristic read/write operations
    2024-09-04 19:03:51.901 12221-12461 [Bluetooth...vity L:118 app.theranica.neriviomigra I MAC='00:A0:50:0D:17:3F' onCharacteristicRead(), status=0, value=[uuid='71387662-eb78-11e6-b006-92361f002671', hexValue=[31, 20, 30, 20, 65, 62, 39, 33, ...]]
    2024-09-04 19:03:51.903 12221-13137 [Bluetooth...vity L:119 app.theranica.neriviomigra D FINISHED CharacteristicReadOperation(114573011) in 974 ms

Additional context

  • We have attempted multiple potential workarounds, such as refreshing the GATT cache using reflection via BluetoothGatt, setting connection priorities, enhancing disconnection handling, and re-bonding the device on each connection attempt. None of these have resolved the issue.
  • The problem does not occur on Android 14 or below, indicating a possible change in the Bluetooth stack behavior on Android 15.
  • Restarting the Bluetooth adapter or the entire device temporarily resolves the issue but does not provide a long-term fix.
  • We are also in communication with Google regarding this issue in their issue tracker: Google Issue Tracker.

We are looking for any insights or suggestions from your side that might help us further investigate or work around this issue. If there's any additional information or specific scenarios you need, please let us know.

@yd-threra-and yd-threra-and added the bug Bug that is caused by the library label Sep 4, 2024
@dariuszseweryn
Copy link
Owner

Thank you for the report. Have you seen any library logs that would have onConnectionUpdated part? I wonder if these have been changed on Android 15

@yd-threra-and
Copy link
Author

@dariuszseweryn Thank you for your reply. I enabled debug logging for RxAndroidBle and tested both the first-time connection (with pairing/bonding) and subsequent connections to the BLE device. Here is what I observed:

First-Time Connection (Pairing/Bonding):

  • The connection request prompts for pairing and bonding as expected, and all operations, including MTU requests and characteristic reads/writes, complete swiftly without noticeable delays.
  • The onConnectionUpdated log does not appear immediately after this initial connection.

Subsequent Connections (After Initial Pairing/Bonding):

  • After the first successful pairing connection, subsequent connections (which do not require bonding again) exhibit significant delays.
  • The following log lines are observed from both the BluetoothGatt and the RxAndroidBle library during the subsequent connection:
    2024-09-07 12:45:53.716 22572-22732 BluetoothGatt app.theranica.neriviomigra D onConnectionUpdated() - Device=00:A0:50:0D:17:3F interval=396 latency=0 timeout=200 status=0
    2024-09-07 12:45:53.719 22572-22732 [Bluetooth...vity L:118 app.theranica.neriviomigra I MAC='00:A0:50:0D:17:3F' onConnectionUpdated(), status=0, interval=396 (495.00 ms), latency=0, timeout=200 (2000 ms)
  • The delay occurs particularly during the MTU request phase (taking about 4 seconds) and characteristic read operations.

Behavior Across Multiple Devices:

  • This pattern is consistent across different BLE devices. Switching to a new device results in a quick initial connection with pairing, but subsequent connections become slow again unless we reset the Bluetooth stack (e.g., turning Bluetooth off/on or restarting the phone). Turning Bluetooth off/on typically resolves the slowness temporarily, though not always. Restarting the phone generally restores stability for a longer period, but the issue has been observed to reoccur after some time.
  • Once the slowness occurs in the connection, all subsequent operations involving characteristic reads and writes are also delayed. For example, in our app, starting or pausing a treatment for a medical device involves writing commands to the BLE device and reading responses using readCharacteristic from the RxAndroidBle library.

Our Implementation:
In our implementation, the MTU request is made immediately after establishing a connection and before discovering services, as shown in our code snippet:

bleDevice.establishConnection(false)
    .flatMapSingle { rxBleConnection ->
        logD(LogCategory.Bluetooth, "Connection established")
        bleConnection = rxBleConnection
        Single.timer(1, TimeUnit.SECONDS)
    }
    .flatMapSingle {
        logD(LogCategory.Bluetooth, "Requesting MTU")
        bleConnection?.requestMtu(512)?.timeout(6, TimeUnit.SECONDS)
    }
    .flatMapSingle {
        logD(LogCategory.Bluetooth, "MTU request success")
        logD(LogCategory.Bluetooth, "Discovering services")
        bleConnection?.discoverServices()
    }

Request for Your Insights:
Based on these observations, it seems that something may change in the BLE stack after the initial connection and bonding. Could changes in how the onConnectionUpdated event is handled on Android 15, or another factor, be contributing to this behavior?

We would greatly appreciate any insights or recommendations you might have to further investigate or work around this issue.

Thank you again for your assistance!

@dariuszseweryn
Copy link
Owner

My suspicion: It may be that Android 15 negotiates lower connection priority after initial setup.

You could check if the connection parameters are updated on Android 14 — I guess not.

As a workaround, setting connection priority after it was changed by Android 15 could help.

@yd-threra-and
Copy link
Author

Thank you for your suggestion regarding setting the BLE connection priority after it was changed by Android 15. I implemented this workaround as follows:

After establishing the connection, I set the BLE connection priority to CONNECTION_PRIORITY_HIGH to ensure stable communication. Here is a brief code snippet showing the implementation:

bleDevice.establishConnection(false)
    .flatMapSingle { rxBleConnection ->
        logD(LogCategory.Bluetooth, "Connection established")

        val localBleConnection = rxBleConnection
        bleConnection = localBleConnection

        // Apply workaround for Android 15 and above
        if (isAndroid15andAbove()) {
            localBleConnection.requestConnectionPriority(
                BluetoothGatt.CONNECTION_PRIORITY_HIGH,
                2, TimeUnit.SECONDS
            )
                .doOnComplete { logD(LogCategory.Bluetooth, "Connection priority set to high") }
                .andThen(Single.timer(1, TimeUnit.SECONDS)) // Delay for 1 second
        } else {
            Single.timer(1, TimeUnit.SECONDS)
        }
    }
    .flatMapSingle {
        logD(LogCategory.Bluetooth, "Requesting MTU")
        if (isAndroid15andAbove()) {
            bleConnection?.requestMtu(512)?.timeout(6, TimeUnit.SECONDS)
        } else {
            bleConnection?.requestMtu(512)?.timeout(3, TimeUnit.SECONDS)
        }
    }

Observations:

  • On Android 14, the onConnectionUpdated log is not triggered at all after establishing any connection (both first-time and subsequent connections), suggesting that this behavior of triggering onConnectionUpdated might be new or specific to Android 15.

  • Initial testing shows promising results, with improved connection stability and reduced delays on Android 15.

Thank you again for your support!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
awaiting feedback bug Bug that is caused by the library
Projects
None yet
Development

No branches or pull requests

2 participants