establishConnection fails sometimes with status 133 GATT_ERROR

[aptly-io]

Summary

I get the following exception when calling establishConnection(false): status 133 GATT_ERROR about 1/4 times on my Android 8.0. (strange that it is a DisconnectedException while trying to connect ...)

I tried to get around with a retry after such connection failure. But this doesn't work: the next exception tells me that the device is already connected. It seems that rxandroidble got into an inconsistent state?

If I try again the code block always succeeds (the code is triggered by a button click)

Library version

1.8.0

Preconditions

Sometimes it happens when the application is just restarted (from the debugger).

Steps to reproduce actual result

Minimum code snippet reproducing the issue

return device.establishConnection(false)
    .retry(2, { throwable ->
        Thread.sleep(500). # retry with some patience
        warn { "establishConnection() failed: " + throwable.message}
        # retry if the connection fails
        throwable is BleDisconnectedException &&
                throwable.message?.contains("status 133 (GATT_ERROR)") ?: false
    }).flatMap { rxBleConnection ->
 ...

Logs from the application running with setting RxBleLog.setLogLevel(RxBleLog.VERBOSE)

D/RxBle#ClientOperationQueue: QUEUED   ConnectOperation(266688704)
D/RxBle#ClientOperationQueue: STARTED  ConnectOperation(266688704)
V/RxBle#BleConnectionCompat: Connecting without reflection
D/BluetoothGatt: connect() - device: F5:14:59:CB:18:99, auto: false
    registerApp()
D/BluetoothGatt: registerApp() - UUID=df67839d-5d9d-43fc-b086-3f62899251d6
D/BluetoothGatt: onClientRegistered() - status=0 clientIf=7
D/BluetoothGatt: onClientConnectionState() - status=133 clientIf=7 device=F5:14:59:CB:18:99
D/RxBle#BluetoothGatt$1: onConnectionStateChange newState=0 status=133
I/RxBle#ConnectionOperationQueue: Connection operations queue to be terminated (F5:14:59:CB:18:99)
D/RxBle#Executors$RunnableAdapter: Terminated.
W/Ble: establishConnection() failed: Disconnected from F5:14:59:CB:18:99 with status 133 (GATT_ERROR)
W/Ble: establishConnection() failed: Already connected to device with MAC address F5:14:59:CB:18:99
W/MainActivity: ### FM SetupNotification failed: Already connected to device with MAC address F5:14:59:CB:18:99, cause: null
D/RxBle#ClientOperationQueue: QUEUED   DisconnectOperation(83660552)
D/RxBle#ClientOperationQueue: FINISHED ConnectOperation(266688704) in 5694 ms
D/RxBle#ClientOperationQueue: STARTED  DisconnectOperation(83660552)
D/BluetoothManager: getConnectionState()
    getConnectedDevices
D/BluetoothGatt: close()
    unregisterApp() - mClientIf=7
D/RxBle#ClientOperationQueue: FINISHED DisconnectOperation(83660552) in 20 ms

Actual result

Expected result

Would it be possible for the 'device' instance to not think it is connected when retrying the connection? I have a feeling that the retry might then succeed ...

[aptly-io]

After changes to my code, the error occurred less.
Therefore I closed this myself ...

[dariuszseweryn]

Hmmm... that is an interesting idea you used to simply put Thread.sleep(). I would recommend using .retryWhen() instead where you can return an Observable that could be .delay()-ed in a non-blocking manner. I suppose this is the problem with 'already connected' exception.

Some other issues with status 133 are described in the wiki

[dariuszseweryn]

Btw. @aptly-io — could you post your updated code? In case someone will come here and ask

[aptly-io]

@DariuszAniszewski Thank you for your attention and that suggestion, I'm a rx and ble freshman, flabbergasted by all these observable operations. I need to give some context to my use case.

I open a connection, write configuration values to a BLE accelerometer's characteristic, then wait for the accelerometer notifications to stream in. At one point the observer no longer needs the accelerometer data and disposes his subscription. This triggers a doFinally which tries to write again to the BLE accelerometer characteristic to power its hardware down (conserve the IoT's battery).
From the log traces I concluded that the new connection within this doFinally causes a race condition with the ongoing closing (in the background?) of the connection used before to receive the notification stream? I added a listen to connection state changes. Only once 'DISCONNECTED', I re-open to write the power-off values to the BLE's characteristic.

Since adding this extra code (see below), the status 133 issue occurred less frequent.

        .doFinally {
            debug { "### doFinally"}
            device.observeConnectionStateChanges()
                .skipWhile { state ->
                    debug { "### state: " + state }
                    state != RxBleConnection.RxBleConnectionState.DISCONNECTED
                }.take(1)
                .delay(1000, TimeUnit.MICROSECONDS)
                .flatMap { state ->
                    debug { "### state: " + state }
                    device.establishConnection(false)
                }.flatMap { connection ->
                    MetaWear.disableAcceleroSensor(connection)
                }
                // todo how to dispose this subscription (a kind of mem. leak?) after onComplete?
                .subscribe({
                    debug { "### all done but how to cleanup this subscription?"}
                }, { throwable ->
                    warn { "### createMetaWearSensorObserver not properly stopped: " + throwable.message + throwable.toString()}}, {

                })

I realise I still have work on this (like my todo for handling the leak; any suggestion is welcomed :-). I don't completely understand why most status 133 issues gone. I need a bit more debugging/testing to confirm this additional code caused the improvement (I didn't have for this to today).

Another assumption for the status 133 issue during development is that the running Android Activity is forcefully killed by Android Studio(?). The Underlying layers on the Android platform might have the connection still opened? Next restarting the simple Activity, trying to connect to the BLE device, cause a similar race condition as described above (or at least confuse the RxAndroidBle FW about the state of the underlying layers)(?)

I hope this gives others some fresh inspiration :-)

[aptly-io]

@dariuszseweryn Based on your suggestion I tried .retryWhen with a delay mechanism. The log traces indicate that the timer is executed but the actual retry never happens. When commenting out the delays, the retry happens! Strange but Luckily, after much trying, the delay seems unnecessary.

I tried these:

                    .retryWhen({
                        val counter = AtomicInteger()
                        warn { "### retrying ${counter}" }
                        it.takeWhile { error ->
                                warn { "### takeWhile error: ${error}" }
                                counter.getAndIncrement() != 3
                            }
                        .flatMap { error ->
                            warn {"### delay retry by " + counter.get() + " second(s) for error: ${error}" }
                            Observable.timer(counter.get().toLong(), TimeUnit.SECONDS)
                        }
                    })

and this variant

                    .retryWhen({
                        val counter = AtomicInteger()
                        warn { "### retrying ${counter}" }
                        it
                            .takeWhile { error ->
                                warn { "### takeWhile error: ${error}" }
                                counter.getAndIncrement() != 3
                            }
                        .doOnNext { debug { "### before delay on thread ${Thread.currentThread().getName()}" } }
                        .delay(1, TimeUnit.SECONDS)
                        .doOnNext { debug { "### after delay on thread ${Thread.currentThread().getName()}" } }
                    })

I see status 133 occurs frequently but I've never seen in fail again after a first retry. I finally stick with this simple:

                    .retry(4, { throwable ->
                        warn { "### within doFinally establishConnection() failed: " + throwable.message}
                        true    // force a retry
                    })

Hope it will help others.

[TyFancaoHuynh]

@aptly-io Hi aptly-io, I have same issues. I try to connect ble device and it have error 133 GATT code. Have you fix it done? Lets show me code to connect ble with RxAndroidBle. Thank you so much :D .