BleGattCallbackTimeoutException when writing a characteristic with different data payload many times in a short period of time.

[dquand91]

Describe the bug

I have a BLE device with several characteristics and all of them are working.

But when I try to write 1 characteristic many times with different data payload in a short period of time (for 10 request in 5 seconds) by using com.polidea.rxandroidble2:rxandroidble:1.18.1 library on Android, it leads to BleGattCallbackTimeoutException and then automatically disconnect bluetooth with device. But I have an IOS application connects to the same BLE device, it still works as expected in the same scenario.

To Reproduce
Steps to reproduce the behavior:

1. Application on Android connects to BLE device.
2. Write 1 characteristic many times by method "rxBleConnection.createNewLongWriteBuilder()". Please refer to source code below:

Disposable writeDisposable = connectionObservable.flatMap(rxBleConnection ->
  rxBleConnection.createNewLongWriteBuilder()
    .setCharacteristicUuid(UUID.fromString(characteristic))
    .setBytes(data)
    .setMaxBatchSize(MAX_PACKET_LENGTH)
    .build())
  .doOnError(throwable ->
  {
      throwable.printStackTrace();
  })
  .subscribe(bytes -> onWriteSuccess(characteristic, bytes), this::onWriteFailure);

Expected behavior

• It should not disconnect the bluetooth
• Do we have any workaround solution or tips in case of writing 1 characteristic many times in a short period of time?

Smartphone (please complete the following information):

• Device: Samsung S23, S23 Ultra
• OS: Android 13
• Library version: 1.18.1

Logs from the application when bug occurs (this will greatly help in quick understanding the problem)
To turn on logs use:

57:53.574 26010-26010 RxBle#ConnectionOperationQueue  D  QUEUED   CharacteristicLongWriteOperation(91963927)
57:53.577 26010-32587 RxBle#ConnectionOperationQueue  D  STARTED  CharacteristicLongWriteOperation(91963927)

57:53.577 26010-26010 RxBle#ConnectionOperationQueue  D  QUEUED   CharacteristicLongWriteOperation(163186669)
57:53.580 26010-26010 RxBle#ConnectionOperationQueue  D  QUEUED   CharacteristicLongWriteOperation(132638899)
57:53.582 26010-26010 RxBle#ConnectionOperationQueue  D  QUEUED   CharacteristicLongWriteOperation(205922926)
57:53.590 26010-26010 RxBle#ConnectionOperationQueue  D  QUEUED   CharacteristicLongWriteOperation(49439132)
57:55.708 26010-26010 RxBle#ConnectionOperationQueue  D  QUEUED   CharacteristicLongWriteOperation(154431849)
57:58.596 26010-26010 RxBle#ConnectionOperationQueue  D  QUEUED   CharacteristicLongWriteOperation(35002628)
57:58.598 26010-26010 RxBle#ConnectionOperationQueue  D  QUEUED   CharacteristicLongWriteOperation(109101346)
57:58.600 26010-26010 RxBle#ConnectionOperationQueue  D  QUEUED   CharacteristicLongWriteOperation(241025392)
57:58.604 26010-26010 RxBle#ConnectionOperationQueue  D  QUEUED   CharacteristicLongWriteOperation(126733678)

// After about 30007 mili-seconds, it leads to timeout exception.
58:23.583 26010-26763 BLEManager                      E  write long error: GATT exception from MAC address XX:XX:XX:XX:XX:XX, with type BleGattOperation{description='CHARACTERISTIC_LONG_WRITE'}
58:23.585 26010-32587 RxBle#ConnectionOperationQueue  D  FINISHED CharacteristicLongWriteOperation(91963927) in 30007 ms
58:23.586 26010-26763 System.err                      W  com.polidea.rxandroidble2.exceptions.BleGattCallbackTimeoutException: GATT exception from MAC address XX:XX:XX:XX:XX:XX, with type BleGattOperation{description='CHARACTERISTIC_LONG_WRITE'}
58:23.586 26010-26763 System.err                      W  	at com.polidea.rxandroidble2.internal.operations.CharacteristicLongWriteOperation.protectedRun(CharacteristicLongWriteOperation.java:87)
58:23.587 26010-26763 System.err                      W  	at com.polidea.rxandroidble2.internal.QueueOperation$1.subscribe(QueueOperation.java:41)
58:23.587 26010-26763 System.err                      W  	at io.reactivex.internal.operators.observable.ObservableCreate.subscribeActual(ObservableCreate.java:40)
58:23.587 26010-26763 System.err                      W  	at io.reactivex.Observable.subscribe(Observable.java:12284)
58:23.587 26010-26763 System.err                      W  	at io.reactivex.internal.operators.observable.ObservableUnsubscribeOn.subscribeActual(ObservableUnsubscribeOn.java:32)
58:23.587 26010-26763 System.err                      W  	at io.reactivex.Observable.subscribe(Observable.java:12284)
58:23.587 26010-26763 System.err                      W  	at com.polidea.rxandroidble2.internal.serialization.FIFORunnableEntry$1.run(FIFORunnableEntry.java:56)
58:23.587 26010-26763 System.err                      W  	at io.reactivex.internal.schedulers.ScheduledDirectTask.call(ScheduledDirectTask.java:38)
58:23.587 26010-26763 System.err                      W  	at io.reactivex.internal.schedulers.ScheduledDirectTask.call(ScheduledDirectTask.java:26)
58:23.587 26010-26763 System.err                      W  	at java.util.concurrent.FutureTask.run(FutureTask.java:264)
58:23.587 26010-26763 System.err                      W  	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
58:23.588 26010-26763 System.err                      W  	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
58:23.588 26010-32587 RxBle#ConnectionOperationQueue  D  STARTED  CharacteristicLongWriteOperation(163186669)
58:23.588 26010-26763 System.err                      W  	at java.lang.Thread.run(Thread.java:1012)
58:23.588 26010-26763 BLEManager                      E  BLECharacteristic write failed: GATT exception from MAC address XX:XX:XX:XX:XX:XX, with type BleGattOperation{description='CHARACTERISTIC_LONG_WRITE'}
58:23.588 26010-32587 RxBle#ConnectionOperationQueue  I  RUNNING  CharacteristicLongWriteOperation{MAC='XX:XX:XX:XX:XX:XX', characteristic=[uuid='...'], maxBatchSize=20}
58:23.589 26010-26763 System.err                      W  com.polidea.rxandroidble2.exceptions.BleGattCallbackTimeoutException: GATT exception from MAC address XX:XX:XX:XX:XX:XX, with type BleGattOperation{description='CHARACTERISTIC_LONG_WRITE'}
58:23.589 26010-26763 System.err                      W  	at com.polidea.rxandroidble2.internal.operations.CharacteristicLongWriteOperation.protectedRun(CharacteristicLongWriteOperation.java:87)
58:23.589 26010-26763 System.err                      W  	at com.polidea.rxandroidble2.internal.QueueOperation$1.subscribe(QueueOperation.java:41)
58:23.589 26010-26763 System.err                      W  	at io.reactivex.internal.operators.observable.ObservableCreate.subscribeActual(ObservableCreate.java:40)
58:23.590 26010-26763 System.err                      W  	at io.reactivex.Observable.subscribe(Observable.java:12284)
58:23.590 26010-26763 System.err                      W  	at io.reactivex.internal.operators.observable.ObservableUnsubscribeOn.subscribeActual(ObservableUnsubscribeOn.java:32)
58:23.590 26010-26763 System.err                      W  	at io.reactivex.Observable.subscribe(Observable.java:12284)
58:23.590 26010-26763 System.err                      W  	at com.polidea.rxandroidble2.internal.serialization.FIFORunnableEntry$1.run(FIFORunnableEntry.java:56)
58:23.590 26010-26763 System.err                      W  	at io.reactivex.internal.schedulers.ScheduledDirectTask.call(ScheduledDirectTask.java:38)
58:23.590 26010-26517 RxBle#Characte...riteOperation  D  Writing batch #0000: [...]
58:23.590 26010-26763 System.err                      W  	at io.reactivex.internal.schedulers.ScheduledDirectTask.call(ScheduledDirectTask.java:26)
58:23.590 26010-26763 System.err                      W  	at java.util.concurrent.FutureTask.run(FutureTask.java:264)
58:23.590 26010-26763 System.err                      W  	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
58:23.590 26010-26763 System.err                      W  	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
58:23.590 26010-26763 System.err                      W  	at java.lang.Thread.run(Thread.java:1012)
58:23.592 26010-26517 BLEManager                      E  write long error: GATT exception from MAC address XX:XX:XX:XX:XX:XX, with type BleGattOperation{description='CHARACTERISTIC_LONG_WRITE'}
58:23.592 26010-32587 RxBle#ConnectionOperationQueue  D  FINISHED CharacteristicLongWriteOperation(163186669) in 6 ms
58:23.594 26010-32587 RxBle#ConnectionOperationQueue  D  STARTED  CharacteristicLongWriteOperation(132638899)
58:23.594 26010-26517 System.err                      W  com.polidea.rxandroidble2.exceptions.BleGattCannotStartException: GATT exception from MAC address XX:XX:XX:XX:XX:XX, with type BleGattOperation{description='CHARACTERISTIC_LONG_WRITE'}
58:23.594 26010-26517 System.err                      W  	at com.polidea.rxandroidble2.internal.operations.CharacteristicLongWriteOperation.writeData(CharacteristicLongWriteOperation.java:190)
58:23.594 26010-26517 System.err                      W  	at com.polidea.rxandroidble2.internal.operations.CharacteristicLongWriteOperation$3.subscribe(CharacteristicLongWriteOperation.java:165)
58:23.594 26010-26517 System.err                      W  	at io.reactivex.internal.operators.observable.ObservableCreate.subscribeActual(ObservableCreate.java:40)
58:23.594 26010-26517 System.err                      W  	at io.reactivex.Observable.subscribe(Observable.java:12284)
58:23.594 26010-26517 System.err                      W  	at io.reactivex.internal.operators.observable.ObservableSubscribeOn$SubscribeTask.run(ObservableSubscribeOn.java:96)
58:23.594 26010-26517 System.err                      W  	at io.reactivex.internal.schedulers.ScheduledDirectTask.call(ScheduledDirectTask.java:38)
58:23.594 26010-26517 System.err                      W  	at io.reactivex.internal.schedulers.ScheduledDirectTask.call(ScheduledDirectTask.java:26)
58:23.595 26010-26517 System.err                      W  	at java.util.concurrent.FutureTask.run(FutureTask.java:264)
58:23.595 26010-26517 System.err                      W  	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
58:23.595 26010-32587 RxBle#ConnectionOperationQueue  I  RUNNING  CharacteristicLongWriteOperation{MAC='XX:XX:XX:XX:XX:XX', characteristic=[uuid='...'], maxBatchSize=20}
58:23.595 26010-26517 System.err                      W  	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
58:23.595 26010-26517 System.err                      W  	at java.lang.Thread.run(Thread.java:1012)
58:23.595 26010-26517 BLEManager                      E  BLECharacteristic write failed: GATT exception from MAC address XX:XX:XX:XX:XX:XX, with type BleGattOperation{description='CHARACTERISTIC_LONG_WRITE'}
58:23.596 26010-26517 System.err                      W  com.polidea.rxandroidble2.exceptions.BleGattCannotStartException: GATT exception from MAC address XX:XX:XX:XX:XX:XX, with type BleGattOperation{description='CHARACTERISTIC_LONG_WRITE'}
58:23.596 26010-26517 System.err                      W  	at com.polidea.rxandroidble2.internal.operations.CharacteristicLongWriteOperation.writeData(CharacteristicLongWriteOperation.java:190)
58:23.596 26010-26517 System.err                      W  	at com.polidea.rxandroidble2.internal.operations.CharacteristicLongWriteOperation$3.subscribe(CharacteristicLongWriteOperation.java:165)
58:23.596 26010-26517 System.err                      W  	at io.reactivex.internal.operators.observable.ObservableCreate.subscribeActual(ObservableCreate.java:40)
58:23.596 26010-26517 System.err                      W  	at io.reactivex.Observable.subscribe(Observable.java:12284)
58:23.596 26010-26517 System.err                      W  	at io.reactivex.internal.operators.observable.ObservableSubscribeOn$SubscribeTask.run(ObservableSubscribeOn.java:96)
58:23.596 26010-26517 System.err                      W  	at io.reactivex.internal.schedulers.ScheduledDirectTask.call(ScheduledDirectTask.java:38)
58:23.596 26010-26517 System.err                      W  	at io.reactivex.internal.schedulers.ScheduledDirectTask.call(ScheduledDirectTask.java:26)
58:23.596 26010-26517 System.err                      W  	at java.util.concurrent.FutureTask.run(FutureTask.java:264)
58:23.596 26010-26517 System.err                      W  	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
58:23.596 26010-26517 System.err                      W  	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
58:23.596 26010-26517 System.err                      W  	at java.lang.Thread.run(Thread.java:1012)
58:23.597 26010-26517 RxBle#Characte...riteOperation  D  Writing batch #0000: [...]
58:23.598 26010-26517 BLEManager                      E  write long error: GATT exception from MAC address XX:XX:XX:XX:XX:XX, with type BleGattOperation{description='CHARACTERISTIC_LONG_WRITE'}
58:23.598 26010-32587 RxBle#ConnectionOperationQueue  D  FINISHED CharacteristicLongWriteOperation(132638899) in 6 ms



// After a lot of exceptions, the Bluetooth is disconnected.
58:23.662 26010-26789 RxBle#GattCallback              I  MAC='XX:XX:XX:XX:XX:XX'    onCharacteristicWrite(), status=133, value=[uuid='...']
58:23.662 26010-26789 BluetoothGatt                   D  onClientConnectionState() - status=22 clientIf=6 device=XX:XX:XX:XX:XX:XX
58:23.669 26010-26789 RxBle#GattCallback              I  MAC='XX:XX:XX:XX:XX:XX'  onConnectionStateChange(), status=22, value=0
58:23.671 26010-26789 RxBle#ConnectionOperationQueue  D  Connection operations queue to be terminated (MAC='XX:XX:XX:XX:XX:XX')
                                                                       com.polidea.rxandroidble2.exceptions.BleDisconnectedException: Disconnected from MAC='XX:XX:XX:XX:XX:XX' with status 22 (GATT_CONN_TERMINATE_LOCAL_HOST)
                                                                       	at com.polidea.rxandroidble2.internal.connection.RxBleGattCallback$2.onConnectionStateChange(RxBleGattCallback.java:85)
                                                                       	at android.bluetooth.BluetoothGatt$1$4.run(BluetoothGatt.java:381)
                                                                       	at android.bluetooth.BluetoothGatt.runOrQueueCallback(BluetoothGatt.java:1068)
                                                                       	at android.bluetooth.BluetoothGatt.-$$Nest$mrunOrQueueCallback(Unknown Source:0)
                                                                       	at android.bluetooth.BluetoothGatt$1.onClientConnectionState(BluetoothGatt.java:376)
                                                                       	at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:226)
                                                                       	at android.os.Binder.execTransactInternal(Binder.java:1380)
                                                                       	at android.os.Binder.execTransact(Binder.java:1311)
58:23.672 26010-32587 RxBle#ConnectionOperationQueue  V  Terminated (MAC='XX:XX:XX:XX:XX:XX')
58:23.672 26010-26789 RxBle#ClientOperationQueue      D  QUEUED   DisconnectOperation(23872671)
58:23.673 26010-26762 BLEManager                      E  notification error: Disconnected from MAC='XX:XX:XX:XX:XX:XX' with status 22 (GATT_CONN_TERMINATE_LOCAL_HOST)
58:23.673 26010-26147 RxBle#ClientOperationQueue      D  STARTED  DisconnectOperation(23872671)
58:23.673 26010-26789 BluetoothGatt                   D  setCharacteristicNotification() - uuid: 2738cac5-a508-82b7-8c48-4356f52c4720 enable: false
58:23.673 26010-26147 RxBle#ClientOperationQueue      I  RUNNING  DisconnectOperation{MAC='XX:XX:XX:XX:XX:XX'}
58:23.674 26010-26762 System.err                      W  com.polidea.rxandroidble2.exceptions.BleDisconnectedException: Disconnected from MAC='XX:XX:XX:XX:XX:XX' with status 22 (GATT_CONN_TERMINATE_LOCAL_HOST)
58:23.674 26010-26762 System.err                      W  	at com.polidea.rxandroidble2.internal.connection.RxBleGattCallback$2.onConnectionStateChange(RxBleGattCallback.java:85)
58:23.674 26010-26762 System.err                      W  	at android.bluetooth.BluetoothGatt$1$4.run(BluetoothGatt.java:381)
58:23.674 26010-26762 System.err                      W  	at android.bluetooth.BluetoothGatt.runOrQueueCallback(BluetoothGatt.java:1068)
58:23.674 26010-26762 System.err                      W  	at android.bluetooth.BluetoothGatt.-$$Nest$mrunOrQueueCallback(Unknown Source:0)
58:23.674 26010-26762 System.err                      W  	at android.bluetooth.BluetoothGatt$1.onClientConnectionState(BluetoothGatt.java:376)
58:23.674 26010-26762 System.err                      W  	at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:226)
58:23.674 26010-26762 System.err                      W  	at android.os.Binder.execTransactInternal(Binder.java:1380)
58:23.674 26010-26762 System.err                      W  	at android.os.Binder.execTransact(Binder.java:1311)

Additional context
Add any other context about the problem here.

[dariuszseweryn]

Hey, thanks for using the library!

This looks like an Android BLE stack error/unhandled situation. Most probably a HCI log would have hints on what is going on.

Are those long writes you make related somehow to configuring your peripheral's BLE configuration?

[dquand91]

Are those long writes you make related somehow to configuring your peripheral's BLE configuration?

Thanks for your replying.

Yes, I use long writes the characteristic with different data payload to configuring my peripheral's BLE.
The BLE connection is automatically disconnect after the BleGattCallbackTimeoutException.

Could you guide me some tips to workaround this issue?
Can we refresh the Gatt cache or do something in case of exception instead of disconnect the BLE?

[dariuszseweryn]

First of all – what configuration are you setting specifically? Maybe it's not needed or timed wrong?

As for the refresh, there is a topic about it already — it's possible

[dquand91]

Thanks for your tips.
I think I should optimize the way to configuring peripheral device. Instead of writing many time in a short period of time, I will try to write sequentially.

[dariuszseweryn]

I don't think queuing these writes sequentially will help as they are executed sequentially FIFO anyway.

If you could share what these individual writes are configuring it could help understand what is going on.

Additional questions:

1. How many bytes have the individual commands?
2. Are these writes scheduled right after the connection is established or later?
3. Is the peripheral paired/bonded?

[dquand91]

If you could share what these individual writes are configuring it could help understand what is going on.

It is a feature called feature A of the peripheral device, when the application start or resume (move from background to foreground), I try to write/read configurations of this feature A, for example: get/set volume, get/set status (on or off),...

1.How many bytes have the individual commands?

There are 5 different commands with data payload from 2 to 9 bytes.

2. Are these writes scheduled right after the connection is established or later?

No, I just try to write/read when the connection already is established. I also checked the BLE connection is connected or not before write/read.

3. Is the peripheral paired/bonded?

It is already paired/bonded

---

I am trying to write/read 5 different BLE commands when the application moves from background to foreground. The app and peripheral are always paired/bonded while app is in background.
If I try to repeat the steps to move the app from background to foreground 10 times. There is at least 1 time that I observe the issue BLE disconnect.

[dariuszseweryn]

It is a feature called feature A of the peripheral device, when the application start or resume (move from background to foreground), I try to write/read configurations of this feature A, for example: get/set volume, get/set status (on or off),...

What does it change from the Bluetooth perspective? Are there changes in the bluetooth services available? Connection timings change?

There are 5 different commands with data payload from 2 to 9 bytes.

If so, I see no need in using rxBleConnection.createNewLongWriteBuilder(), standard rxBleConnection.writeCharacteristic() should work since no command exceeds the default 20 byte payload size (unless you concatenate multiple commands in one write). Or rather not work as I suspect the problem you face to be either a BLE stack related or a Peripheral implementation issue.

[dquand91]

Thanks for your support.
I have changed from the .createNewLongWriteBuilder() to .writeCharacteristic() for any commands less than 20 bytes payload size. It works as expected in my environment. But I am waiting for testers to confirm in their environment.

[dquand91]

Thanks @dariuszseweryn.
The change to use .writeCharacteristic() does not work in the testers environment. They still receive the same error about BleGattCallbackTimeoutException.
But the error is not always observed. They tried 10 times, there are 2 times observe the error.

Their phone are: Samsung S23, S23 Ultra. Both are running Android 13.

After the timeout exception, the bluetooth is disconnected automatically with either:

• Disconnected from MAC='XX:XX:XX:XX:XX:XX' with status 0 (GATT_SUCCESS)
• Or Disconnected from MAC='XX:XX:XX:XX:XX:XX' with status 22 (GATT_CONN_TERMINATE_LOCAL_HOST)

I wonder why the library automatically disconnect bluetooth in this case? Why don't we keep the connection and the application can handle the connection by itself?

[dariuszseweryn]

The change to use .writeCharacteristic() does not work in the testers environment. They still receive the same error about BleGattCallbackTimeoutException.
But the error is not always observed. They tried 10 times, there are 2 times observe the error.

That was expected.

I wonder why the library automatically disconnect bluetooth in this case? Why don't we keep the connection and the application can handle the connection by itself?

The library does not disconnect by itself but only reports what the Android BLE Stack is doing.

You still did not share what Bluetooth connection configuration can change with those 5 commands you write so I cannot give you more suggestions apart of looking into the BLE Stack. To get more insight on what the Android BLE Stack is doing (or rather what it is not handling correctly) you would need to check the Bluetooth HCI Log.

[dquand91]

Sorry for making you confuse about the changing of BLE connection configuration by those 5 commands I write to the BLE device. The 5 commands just change settings for a function in the device that doesn't relate to Bluetooth configuration.

What does it change from the Bluetooth perspective? Are there changes in the bluetooth services available? Connection timings change?

The commands don't change anything relate to Bluetooth.

[dquand91]

Now, the tester report that we are facing the BleGattCallbackTimeoutException on all BLE write commands that we send to device randomly. That means if we write a BLE command to device 10 times, each command 1 second apart, we can observe the timeout exception at least 1 time (1/10 tries).

But it is odd that the bug is only observed in testers's environment with their Samsung S23 and S23 Ultra.
I tried to reproduce with my Samsung S22 Ultra and Google Pixel 7A, but I don't observe the issue.

I think I should check bluetooth HCI log on their phone.