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

BleGattException CHARACTERISTIC_READ: Device disconnects but BluetoothGatt is not closed properly #63

Closed
WIStudent opened this issue Aug 27, 2016 · 16 comments
Assignees
Labels
bug Bug that is caused by the library

Comments

@WIStudent
Copy link

WIStudent commented Aug 27, 2016

I am currently using Bluez 4.51 and its D-Bus API to turn a Raspberry Pi 3 into a BLE peripheral. It provides a single service with a few characteristics to read from and write to.

The app uses the following code to connect to the periheral and to read some characteristics:

connectionObservable = bleDevice.establishConnection(this, false)
    .compose(bindUntilEvent(ActivityEvent.PAUSE))
    .doOnUnsubscribe(this::clearConnectionObservable)
    .unsubscribeOn(AndroidSchedulers.mainThread())
    .compose(new ConnectionSharingAdapter());

connectionObservable
    .observeOn(AndroidSchedulers.mainThread())
    .subscribe(this::onDeviceConnected, this::onConnectionFailure);

// In onDeviceConnected
connection
    .readCharacteristic(UUID.fromString(row_uuid))
    .observeOn(AndroidSchedulers.mainThread())
    .subscribe(bytes -> setButtonColors(temp_row, bytes), this::onConnectionFailure);

As long as nothing unexpected happens, this works as intended. The app searches for the peripheral, connects to it, reads some characteristics and disconnects from it on the pause event.

08-27 20:27:28.389 9464-9464/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationScan(208722037)
08-27 20:27:28.390 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationScan(208722037)
08-27 20:27:28.396 9464-9512/de.tobiastrumm.bluetoothledmatrix D/OpenGLRenderer: Use EGL_SWAP_BEHAVIOR_PRESERVED: true
08-27 20:27:28.402 9464-9464/de.tobiastrumm.bluetoothledmatrix D/BluetoothAdapter: startLeScan(): null
08-27 20:27:28.404 9464-9464/de.tobiastrumm.bluetoothledmatrix D/BluetoothAdapter: STATE_ON
08-27 20:27:28.409 9464-9482/de.tobiastrumm.bluetoothledmatrix D/BluetoothLeScanner: onClientRegistered() - status=0 clientIf=5
08-27 20:27:28.412 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationScan(208722037)
08-27 20:27:28.483 9464-9512/de.tobiastrumm.bluetoothledmatrix I/Adreno: QUALCOMM build                   : 63c06b2, I8366cd0437
                                                                         Build Date                       : 12/06/15
                                                                         OpenGL ES Shader Compiler Version: XE031.05.13.02
                                                                         Local Branch                     : mybranch17112971
                                                                         Remote Branch                    : quic/LA.BF64.1.2.9_v2
                                                                         Remote Branch                    : NONE
                                                                         Reconstruct Branch               : NOTHING
08-27 20:27:28.489 9464-9512/de.tobiastrumm.bluetoothledmatrix I/OpenGLRenderer: Initialized EGL, version 1.4
08-27 20:27:32.754 9464-9464/de.tobiastrumm.bluetoothledmatrix D/BluetoothAdapter: stopLeScan()
08-27 20:27:32.757 9464-9464/de.tobiastrumm.bluetoothledmatrix D/BluetoothAdapter: STATE_ON
08-27 20:27:32.837 9464-9464/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationConnect(33739039)
08-27 20:27:32.838 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationConnect(33739039)
08-27 20:27:32.861 9464-9464/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: connect() - device: B8:27:EB:A7:1B:9D, auto: false
08-27 20:27:32.862 9464-9464/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: registerApp()
08-27 20:27:32.862 9464-9464/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: registerApp() - UUID=48690a14-deaa-4d00-9907-bb50ddeef349
08-27 20:27:32.866 9464-9482/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: onClientRegistered() - status=0 clientIf=5
08-27 20:27:34.204 9464-9482/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=5 device=B8:27:EB:A7:1B:9D
08-27 20:27:34.225 9464-9482/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onConnectionStateChange newState=2 status=0
08-27 20:27:34.254 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationConnect(33739039)
08-27 20:27:34.280 9464-9464/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationServicesDiscover(105210533)
08-27 20:27:34.282 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationServicesDiscover(105210533)
08-27 20:27:34.295 9464-9464/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: discoverServices() - device: B8:27:EB:A7:1B:9D
08-27 20:27:34.301 9464-9482/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: onSearchComplete() = Device=B8:27:EB:A7:1B:9D Status=0
08-27 20:27:34.302 9464-9482/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onServicesDiscovered status=0
08-27 20:27:34.329 9464-9664/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(7225693)
08-27 20:27:34.332 9464-9664/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(123841184)
08-27 20:27:34.334 9464-9664/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(142559999)
08-27 20:27:34.336 9464-9664/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(43676202)
08-27 20:27:34.338 9464-9664/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(143636369)
08-27 20:27:34.341 9464-9664/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(20737380)
08-27 20:27:34.343 9464-9664/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(15134611)
08-27 20:27:34.345 9464-9664/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(218267342)
08-27 20:27:34.347 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationServicesDiscover(105210533)
08-27 20:27:34.348 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(7225693)
08-27 20:27:34.420 9464-9482/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0000 status=0
08-27 20:27:34.426 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(7225693)
08-27 20:27:34.427 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(123841184)
08-27 20:27:34.512 9464-9482/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0001 status=0
08-27 20:27:34.523 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(123841184)
08-27 20:27:34.525 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(142559999)
08-27 20:27:34.602 9464-9482/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0002 status=0
08-27 20:27:34.610 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(142559999)
08-27 20:27:34.612 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(43676202)
08-27 20:27:34.694 9464-9482/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0003 status=0
08-27 20:27:34.704 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(43676202)
08-27 20:27:34.706 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(143636369)
08-27 20:27:34.902 9464-9482/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0004 status=0
08-27 20:27:34.911 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(143636369)
08-27 20:27:34.913 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(20737380)
08-27 20:27:35.024 9464-9482/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0005 status=0
08-27 20:27:35.032 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(20737380)
08-27 20:27:35.034 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(15134611)
08-27 20:27:35.141 9464-9482/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0006 status=0
08-27 20:27:35.149 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(15134611)
08-27 20:27:35.152 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(218267342)
08-27 20:27:35.324 9464-9482/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0007 status=0
08-27 20:27:35.333 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(218267342)
08-27 20:27:39.071 9464-9464/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationDisconnect(69216652)
08-27 20:27:39.072 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationDisconnect(69216652)
08-27 20:27:39.099 9464-9464/de.tobiastrumm.bluetoothledmatrix D/BluetoothManager: getConnectionState()
08-27 20:27:39.099 9464-9464/de.tobiastrumm.bluetoothledmatrix D/BluetoothManager: getConnectedDevices
08-27 20:27:39.124 9464-9464/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: cancelOpen() - device: B8:27:EB:A7:1B:9D
08-27 20:27:39.138 9464-9482/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=5 device=B8:27:EB:A7:1B:9D
08-27 20:27:39.139 9464-9482/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onConnectionStateChange newState=0 status=0
08-27 20:27:39.145 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationDisconnect(69216652)
08-27 20:27:39.187 9464-9464/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: close()
08-27 20:27:39.188 9464-9464/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: unregisterApp() - mClientIf=5

The issue occurs when the program that provides the service over the D-Bus api on the Pi is terminated. Bluez then removes the service with its characteristics, but does not disconnect any connected central device. As expected, a BleGattException occurs if the app tries to read a characteristic that is no longer there.

08-27 20:28:19.809 9464-9464/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationScan(182191558)
08-27 20:28:19.810 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationScan(182191558)
08-27 20:28:19.814 9464-9464/de.tobiastrumm.bluetoothledmatrix D/BluetoothAdapter: startLeScan(): null
08-27 20:28:19.816 9464-9464/de.tobiastrumm.bluetoothledmatrix D/BluetoothAdapter: STATE_ON
08-27 20:28:19.819 9464-9482/de.tobiastrumm.bluetoothledmatrix D/BluetoothLeScanner: onClientRegistered() - status=0 clientIf=5
08-27 20:28:19.825 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationScan(182191558)
08-27 20:28:19.860 9464-9512/de.tobiastrumm.bluetoothledmatrix I/Adreno: QUALCOMM build                   : 63c06b2, I8366cd0437
                                                                         Build Date                       : 12/06/15
                                                                         OpenGL ES Shader Compiler Version: XE031.05.13.02
                                                                         Local Branch                     : mybranch17112971
                                                                         Remote Branch                    : quic/LA.BF64.1.2.9_v2
                                                                         Remote Branch                    : NONE
                                                                         Reconstruct Branch               : NOTHING
08-27 20:28:19.869 9464-9512/de.tobiastrumm.bluetoothledmatrix I/OpenGLRenderer: Initialized EGL, version 1.4
08-27 20:28:33.762 9464-9464/de.tobiastrumm.bluetoothledmatrix D/BluetoothAdapter: stopLeScan()
08-27 20:28:33.766 9464-9464/de.tobiastrumm.bluetoothledmatrix D/BluetoothAdapter: STATE_ON
08-27 20:28:33.785 9464-9464/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationConnect(185320209)
08-27 20:28:33.787 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationConnect(185320209)
08-27 20:28:33.808 9464-9464/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: connect() - device: B8:27:EB:A7:1B:9D, auto: false
08-27 20:28:33.809 9464-9464/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: registerApp()
08-27 20:28:33.810 9464-9464/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: registerApp() - UUID=1cf80b9c-c6e3-458d-88e6-c646acc724db
08-27 20:28:33.816 9464-9483/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: onClientRegistered() - status=0 clientIf=5
08-27 20:28:35.228 9464-10674/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=5 device=B8:27:EB:A7:1B:9D
08-27 20:28:35.247 9464-10674/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onConnectionStateChange newState=2 status=0
08-27 20:28:35.255 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationConnect(185320209)
08-27 20:28:35.255 9464-9464/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationServicesDiscover(152166182)
08-27 20:28:35.257 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationServicesDiscover(152166182)
08-27 20:28:35.269 9464-9464/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: discoverServices() - device: B8:27:EB:A7:1B:9D
08-27 20:28:35.275 9464-9482/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: onSearchComplete() = Device=B8:27:EB:A7:1B:9D Status=0
08-27 20:28:35.276 9464-9482/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onServicesDiscovered status=0
08-27 20:28:35.289 9464-11057/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(108149855)
08-27 20:28:35.291 9464-11057/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(75602698)
08-27 20:28:35.294 9464-11057/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(140778993)
08-27 20:28:35.297 9464-11057/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(175591236)
08-27 20:28:35.299 9464-11057/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(264839923)
08-27 20:28:35.301 9464-11057/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(109793710)
08-27 20:28:35.303 9464-11057/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(158773221)
08-27 20:28:35.306 9464-11057/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(65777864)
08-27 20:28:35.307 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationServicesDiscover(152166182)
08-27 20:28:35.308 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(108149855)
08-27 20:28:35.445 9464-9483/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0000 status=0
08-27 20:28:35.457 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(108149855)
08-27 20:28:35.459 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(75602698)
08-27 20:28:35.533 9464-10674/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0001 status=0
08-27 20:28:35.540 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(75602698)
08-27 20:28:35.541 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(140778993)
08-27 20:28:35.621 9464-9482/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0002 status=0
08-27 20:28:35.626 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(140778993)
08-27 20:28:35.628 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(175591236)
08-27 20:28:35.715 9464-9483/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0003 status=0
08-27 20:28:35.723 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(175591236)
08-27 20:28:35.725 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(264839923)
08-27 20:28:35.863 9464-10674/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0004 status=0
08-27 20:28:35.869 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(264839923)
08-27 20:28:35.871 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(109793710)
08-27 20:28:35.983 9464-9482/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0005 status=0
08-27 20:28:35.990 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(109793710)
08-27 20:28:35.992 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(158773221)
08-27 20:28:36.104 9464-9483/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0006 status=0
08-27 20:28:36.114 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(158773221)
08-27 20:28:36.115 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(65777864)
08-27 20:28:36.223 9464-10674/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0007 status=0
08-27 20:28:36.230 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(65777864)
08-27 20:29:15.162 9464-9464/de.tobiastrumm.bluetoothledmatrix D/LedControlActivity: Pressed button [0][0]
08-27 20:29:15.185 9464-9464/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(173308595)
08-27 20:29:15.187 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(173308595)
08-27 20:29:15.287 9464-10674/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0000 status=1
08-27 20:29:15.293 9464-9464/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationDisconnect(138501230)
08-27 20:29:15.293 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(173308595)
08-27 20:29:15.294 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationDisconnect(138501230)
08-27 20:29:15.367 9464-9464/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                         at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:245)
                                                                                         at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:26)
                                                                                         at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:94)
                                                                                         at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:356)
                                                                                         at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:249)
                                                                                         at android.os.Binder.execTransact(Binder.java:453)
08-27 20:29:15.370 9464-9464/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                         at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:245)
                                                                                         at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:26)
                                                                                         at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:94)
                                                                                         at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:356)
                                                                                         at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:249)
                                                                                         at android.os.Binder.execTransact(Binder.java:453)
08-27 20:29:15.371 9464-9464/de.tobiastrumm.bluetoothledmatrix D/BluetoothManager: getConnectionState()
08-27 20:29:15.371 9464-9464/de.tobiastrumm.bluetoothledmatrix D/BluetoothManager: getConnectedDevices
08-27 20:29:15.374 9464-9464/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: cancelOpen() - device: B8:27:EB:A7:1B:9D
08-27 20:29:15.377 9464-9507/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationDisconnect(138501230)
08-27 20:29:15.381 9464-10674/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=5 device=B8:27:EB:A7:1B:9D
08-27 20:29:15.382 9464-10674/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onConnectionStateChange newState=0 status=0
08-27 20:29:15.505 9464-9512/de.tobiastrumm.bluetoothledmatrix V/RenderScript: 0x7f8a6b2000 Launching thread(s), CPUs 6

As you can see, RxBleRadioOperationDisconnect is started and finishes. Using bluetoothctl on the Pi i can see, that the Android device is being disconnected, but Logcat never shows that BluetoothGatt was closed.

The BleGattExceptions still occur even after the service and its characteristics are added to the peripheral again.

08-27 20:30:27.835 12770-12770/de.tobiastrumm.bluetoothledmatrix D/BluetoothAdapter: stopLeScan()
08-27 20:30:27.840 12770-12770/de.tobiastrumm.bluetoothledmatrix D/BluetoothAdapter: STATE_ON
08-27 20:30:27.932 12770-12770/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationConnect(33739039)
08-27 20:30:27.940 12770-12785/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationConnect(33739039)
08-27 20:30:27.949 12770-12770/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: connect() - device: B8:27:EB:A7:1B:9D, auto: false
08-27 20:30:27.949 12770-12770/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: registerApp()
08-27 20:30:27.950 12770-12770/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: registerApp() - UUID=0036871f-09be-4403-94cf-7d459063e7d4
08-27 20:30:27.952 12770-12781/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: onClientRegistered() - status=0 clientIf=5
08-27 20:30:30.516 12770-12781/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=5 device=B8:27:EB:A7:1B:9D
08-27 20:30:30.518 12770-12781/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onConnectionStateChange newState=2 status=0
08-27 20:30:30.543 12770-12785/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationConnect(33739039)
08-27 20:30:30.553 12770-12770/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationServicesDiscover(105210533)
08-27 20:30:30.555 12770-12785/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationServicesDiscover(105210533)
08-27 20:30:30.564 12770-12770/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: discoverServices() - device: B8:27:EB:A7:1B:9D
08-27 20:30:30.573 12770-12781/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: onSearchComplete() = Device=B8:27:EB:A7:1B:9D Status=0
08-27 20:30:30.575 12770-12781/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onServicesDiscovered status=0
08-27 20:30:30.611 12770-12838/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(7225693)
08-27 20:30:30.614 12770-12838/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(123841184)
08-27 20:30:30.617 12770-12838/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(142559999)
08-27 20:30:30.621 12770-12838/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(43676202)
08-27 20:30:30.624 12770-12838/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(143636369)
08-27 20:30:30.627 12770-12838/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(20737380)
08-27 20:30:30.630 12770-12838/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(15134611)
08-27 20:30:30.632 12770-12838/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(218267342)
08-27 20:30:30.634 12770-12785/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationServicesDiscover(105210533)
08-27 20:30:30.635 12770-12785/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(7225693)
08-27 20:30:30.735 12770-12781/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0000 status=1
08-27 20:30:30.744 12770-12781/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationDisconnect(223066586)
08-27 20:30:30.745 12770-12785/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(7225693)
08-27 20:30:30.747 12770-12785/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(123841184)
08-27 20:30:30.748 12770-12770/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:245)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:26)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:94)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:356)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:249)
                                                                                           at android.os.Binder.execTransact(Binder.java:453)
08-27 20:30:30.761 12770-12770/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:245)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:26)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:94)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:356)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:249)
                                                                                           at android.os.Binder.execTransact(Binder.java:453)
08-27 20:30:30.778 12770-12785/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(123841184)
08-27 20:30:30.779 12770-12785/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(142559999)
08-27 20:30:30.820 12770-12770/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:245)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:26)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:94)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:356)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:249)
                                                                                           at android.os.Binder.execTransact(Binder.java:453)
08-27 20:30:30.822 12770-12785/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(142559999)
08-27 20:30:30.823 12770-12785/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(43676202)
08-27 20:30:30.845 12770-12790/de.tobiastrumm.bluetoothledmatrix V/RenderScript: 0x7f8d3e8000 Launching thread(s), CPUs 6
08-27 20:30:30.873 12770-12770/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:245)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:26)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:94)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:356)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:249)
                                                                                           at android.os.Binder.execTransact(Binder.java:453)
08-27 20:30:30.876 12770-12785/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(43676202)
08-27 20:30:30.880 12770-12785/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(143636369)
08-27 20:30:30.889 12770-12770/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:245)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:26)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:94)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:356)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:249)
                                                                                           at android.os.Binder.execTransact(Binder.java:453)
08-27 20:30:30.891 12770-12785/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(143636369)
08-27 20:30:30.893 12770-12785/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(20737380)
08-27 20:30:30.903 12770-12770/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:245)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:26)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:94)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:356)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:249)
                                                                                           at android.os.Binder.execTransact(Binder.java:453)
08-27 20:30:30.905 12770-12785/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(20737380)
08-27 20:30:30.906 12770-12785/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(15134611)
08-27 20:30:30.919 12770-12770/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:245)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:26)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:94)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:356)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:249)
                                                                                           at android.os.Binder.execTransact(Binder.java:453)
08-27 20:30:30.921 12770-12785/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(15134611)
08-27 20:30:30.922 12770-12785/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(218267342)
08-27 20:30:30.950 12770-12770/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:245)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:26)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:94)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:356)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:249)
                                                                                           at android.os.Binder.execTransact(Binder.java:453)
08-27 20:30:30.952 12770-12785/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(218267342)
08-27 20:30:30.953 12770-12785/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationDisconnect(223066586)
08-27 20:30:30.956 12770-12781/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0001 status=1
08-27 20:30:30.994 12770-12770/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:245)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:26)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:94)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:356)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:249)
                                                                                           at android.os.Binder.execTransact(Binder.java:453)
08-27 20:30:30.996 12770-12770/de.tobiastrumm.bluetoothledmatrix D/BluetoothManager: getConnectionState()
08-27 20:30:30.996 12770-12770/de.tobiastrumm.bluetoothledmatrix D/BluetoothManager: getConnectedDevices
08-27 20:30:30.999 12770-12770/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: cancelOpen() - device: B8:27:EB:A7:1B:9D
08-27 20:30:31.002 12770-12785/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationDisconnect(223066586)
08-27 20:30:31.004 12770-12781/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=5 device=B8:27:EB:A7:1B:9D
08-27 20:30:31.005 12770-12781/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onConnectionStateChange newState=0 status=0

The reason for that could be that Bluez does not assign the same handles to services and characteristics if they are removed and added again. But because BluetoothGatt was not closed, Android still expects the characteristics to be reachable under the old handles, I guess.

The only way I could get the app running again was to disable and then re-enable bluetooth on the Android device.

@WIStudent
Copy link
Author

Some additional infos: I am using a Nexus 5X with Android 6.0.1

@dariuszseweryn dariuszseweryn added the bug Bug that is caused by the library label Aug 29, 2016
@dariuszseweryn dariuszseweryn self-assigned this Aug 30, 2016
@dariuszseweryn
Copy link
Owner

dariuszseweryn commented Sep 8, 2016

Hello there,
I have been thinking how to address this issue. I currently have no possibility of test this scenario.
I can give you the change I think would fix the problem - would you be so kind to test it?

The thing is to change the isDisconnected() function implementation in RxBleRadioOperationDisconnect class. It would go like this:

private boolean isDisconnected(BluetoothGatt bluetoothGatt) {
    return bluetoothManager.getConnectionState(bluetoothGatt.getDevice(), BluetoothProfile.GATT) == BluetoothProfile.STATE_DISCONNECTED
            && rxBleGattCallback.getConnectionState() == RxBleConnection.RxBleConnectionState.DISCONNECTED;
}

and the whole implementation of RxBleGattCallback would be:

package com.polidea.rxandroidble.internal.connection;

import android.bluetooth.BluetoothGatt;
import android.bluetooth.BluetoothGattCallback;
import android.bluetooth.BluetoothGattCharacteristic;
import android.bluetooth.BluetoothGattDescriptor;
import android.support.annotation.NonNull;

import com.polidea.rxandroidble.RxBleConnection.RxBleConnectionState;
import com.polidea.rxandroidble.RxBleDeviceServices;
import com.polidea.rxandroidble.exceptions.BleDisconnectedException;
import com.polidea.rxandroidble.exceptions.BleGattException;
import com.polidea.rxandroidble.exceptions.BleGattOperationType;
import com.polidea.rxandroidble.internal.RxBleLog;

import com.polidea.rxandroidble.internal.util.ByteAssociation;
import java.util.UUID;

import java.util.concurrent.atomic.AtomicReference;
import rx.Observable;
import rx.Scheduler;
import rx.functions.Func1;
import rx.schedulers.Schedulers;
import rx.subjects.BehaviorSubject;
import rx.subjects.PublishSubject;

public class RxBleGattCallback {

    public interface Provider {

        RxBleGattCallback provide();
    }

    private final Scheduler callbackScheduler = Schedulers.computation();
    private final BehaviorSubject<Void> statusErrorSubject = BehaviorSubject.create();
    private final BehaviorSubject<BluetoothGatt> bluetoothGattBehaviorSubject = BehaviorSubject.create();
    private final PublishSubject<RxBleConnectionState> connectionStatePublishSubject = PublishSubject.create();
    private final PublishSubject<RxBleDeviceServices> servicesDiscoveredPublishSubject = PublishSubject.create();
    private final PublishSubject<ByteAssociation<UUID>> readCharacteristicPublishSubject = PublishSubject.create();
    private final PublishSubject<ByteAssociation<UUID>> writeCharacteristicPublishSubject = PublishSubject.create();
    private final PublishSubject<ByteAssociation<UUID>> changedCharacteristicPublishSubject = PublishSubject.create();
    private final PublishSubject<ByteAssociation<BluetoothGattDescriptor>> readDescriptorPublishSubject = PublishSubject.create();
    private final PublishSubject<ByteAssociation<BluetoothGattDescriptor>> writeDescriptorPublishSubject = PublishSubject.create();
    private final PublishSubject<Integer> readRssiPublishSubject = PublishSubject.create();
    private final PublishSubject<Integer> changedMtuPublishSubject = PublishSubject.create();
    private final Observable disconnectedErrorObservable = getOnConnectionStateChange()
            .filter(this::isDisconnectedOrDisconnecting)
            .doOnNext(rxBleConnectionState -> bluetoothGattBehaviorSubject.onCompleted())
            .flatMap(rxBleConnectionState -> Observable.error(new BleDisconnectedException()));
    private final AtomicReference<RxBleConnectionState> connectionStateAtomicReference = new AtomicReference<>();

    private boolean isDisconnectedOrDisconnecting(RxBleConnectionState rxBleConnectionState) {
        return rxBleConnectionState == RxBleConnectionState.DISCONNECTED || rxBleConnectionState == RxBleConnectionState.DISCONNECTING;
    }

    private BluetoothGattCallback bluetoothGattCallback = new BluetoothGattCallback() {

        @Override
        public void onConnectionStateChange(BluetoothGatt gatt, int status, int newState) {
            RxBleLog.d("onConnectionStateChange newState=%d status=%d", newState, status);
            super.onConnectionStateChange(gatt, status, newState);
            bluetoothGattBehaviorSubject.onNext(gatt);

            if (propagateStatusErrorIfGattErrorOccurred(status, BleGattOperationType.CONNECTION_STATE)) {
                return;
            }

            Observable.just(mapConnectionStateToRxBleConnectionStatus(newState))
                    .compose(getSubscribeAndObserveOnTransformer())
                    .doOnNext(connectionStateAtomicReference::set)
                    .subscribe(connectionStatePublishSubject::onNext);
        }

        @Override
        public void onServicesDiscovered(BluetoothGatt gatt, int status) {
            RxBleLog.d("onServicesDiscovered status=%d", status);
            super.onServicesDiscovered(gatt, status);
            bluetoothGattBehaviorSubject.onNext(gatt);

            if (propagateStatusErrorIfGattErrorOccurred(status, BleGattOperationType.SERVICE_DISCOVERY)) {
                return;
            }

            Observable.just(gatt)
                    .map(BluetoothGatt::getServices)
                    .map(RxBleDeviceServices::new)
                    .compose(getSubscribeAndObserveOnTransformer())
                    .subscribe(servicesDiscoveredPublishSubject::onNext);
        }

        @Override
        public void onCharacteristicRead(BluetoothGatt gatt, BluetoothGattCharacteristic characteristic, int status) {
            RxBleLog.d("onCharacteristicRead characteristic=%s status=%d", characteristic.getUuid(), status);
            super.onCharacteristicRead(gatt, characteristic, status);
            bluetoothGattBehaviorSubject.onNext(gatt);

            if (propagateStatusErrorIfGattErrorOccurred(status, BleGattOperationType.CHARACTERISTIC_READ)) {
                return;
            }

            just(characteristic)
                    .map(associateCharacteristicWithBytes())
                    .compose(getSubscribeAndObserveOnTransformer())
                    .subscribe(readCharacteristicPublishSubject::onNext);
        }

        @Override
        public void onCharacteristicWrite(BluetoothGatt gatt, BluetoothGattCharacteristic characteristic, int status) {
            RxBleLog.d("onCharacteristicWrite characteristic=%s status=%d", characteristic.getUuid(), status);
            super.onCharacteristicWrite(gatt, characteristic, status);
            bluetoothGattBehaviorSubject.onNext(gatt);

            if (propagateStatusErrorIfGattErrorOccurred(status, BleGattOperationType.CHARACTERISTIC_WRITE)) {
                return;
            }

            just(characteristic)
                    .map(associateCharacteristicWithBytes())
                    .compose(getSubscribeAndObserveOnTransformer())
                    .subscribe(writeCharacteristicPublishSubject::onNext);
        }

        @Override
        public void onCharacteristicChanged(BluetoothGatt gatt, BluetoothGattCharacteristic characteristic) {
            RxBleLog.d("onCharacteristicChanged characteristic=%s", characteristic.getUuid());
            super.onCharacteristicChanged(gatt, characteristic);
            bluetoothGattBehaviorSubject.onNext(gatt);

            just(characteristic)
                    .map(associateCharacteristicWithBytes())
                    .compose(getSubscribeAndObserveOnTransformer())
                    .subscribe(changedCharacteristicPublishSubject::onNext);
        }

        @Override
        public void onDescriptorRead(BluetoothGatt gatt, BluetoothGattDescriptor descriptor, int status) {
            RxBleLog.d("onCharacteristicRead descriptor=%s status=%d", descriptor.getUuid(), status);
            super.onDescriptorRead(gatt, descriptor, status);
            bluetoothGattBehaviorSubject.onNext(gatt);

            if (propagateStatusErrorIfGattErrorOccurred(status, BleGattOperationType.DESCRIPTOR_READ)) {
                return;
            }

            just(descriptor)
                    .compose(getSubscribeAndObserveOnTransformer())
                    .subscribe(readDescriptorPublishSubject::onNext);
        }

        @Override
        public void onDescriptorWrite(BluetoothGatt gatt, BluetoothGattDescriptor descriptor, int status) {
            RxBleLog.d("onDescriptorWrite descriptor=%s status=%d", descriptor.getUuid(), status);
            super.onDescriptorWrite(gatt, descriptor, status);
            bluetoothGattBehaviorSubject.onNext(gatt);

            if (propagateStatusErrorIfGattErrorOccurred(status, BleGattOperationType.DESCRIPTOR_WRITE)) {
                return;
            }

            just(descriptor)
                    .compose(getSubscribeAndObserveOnTransformer())
                    .subscribe(writeDescriptorPublishSubject::onNext);
        }

        @Override
        public void onReliableWriteCompleted(BluetoothGatt gatt, int status) {
            RxBleLog.d("onReliableWriteCompleted status=%d", status);
            super.onReliableWriteCompleted(gatt, status);
            bluetoothGattBehaviorSubject.onNext(gatt);

            if (propagateStatusErrorIfGattErrorOccurred(status, BleGattOperationType.RELIABLE_WRITE_COMPLETED)) {
                return;
            }

            // TODO Implement reliable write
        }

        @Override
        public void onReadRemoteRssi(BluetoothGatt gatt, int rssi, int status) {
            RxBleLog.d("onReadRemoteRssi rssi=%d status=%d", rssi, status);
            super.onReadRemoteRssi(gatt, rssi, status);
            bluetoothGattBehaviorSubject.onNext(gatt);

            if (propagateStatusErrorIfGattErrorOccurred(status, BleGattOperationType.READ_RSSI)) {
                return;
            }

            Observable.just(rssi)
                    .compose(getSubscribeAndObserveOnTransformer())
                    .subscribe(readRssiPublishSubject::onNext);
        }

        @Override
        public void onMtuChanged(BluetoothGatt gatt, int mtu, int status) {
            RxBleLog.d("onMtuChanged mtu=%d status=%d", mtu, status);
            super.onMtuChanged(gatt, mtu, status);
            bluetoothGattBehaviorSubject.onNext(gatt);

            if (propagateStatusErrorIfGattErrorOccurred(status, BleGattOperationType.ON_MTU_CHANGED)) {
                return;
            }

            Observable.just(mtu)
                    .compose(getSubscribeAndObserveOnTransformer())
                    .subscribe(changedMtuPublishSubject::onNext);
        }
    };

    @NonNull
    private Observable<ByteAssociation<BluetoothGattCharacteristic>> just(BluetoothGattCharacteristic bluetoothGattCharacteristic) {
        final byte[] value = bluetoothGattCharacteristic.getValue();
        return Observable.defer(() -> Observable.just(ByteAssociation.create(bluetoothGattCharacteristic, value)));
    }

    @NonNull
    private Func1<ByteAssociation<BluetoothGattCharacteristic>, ByteAssociation<UUID>> associateCharacteristicWithBytes() {
        return pair -> new ByteAssociation<>(pair.first.getUuid(), pair.second);
    }

    @NonNull
    private Observable<ByteAssociation<BluetoothGattDescriptor>> just(BluetoothGattDescriptor bluetoothGattDescriptor) {
        final byte[] value = bluetoothGattDescriptor.getValue();
        return Observable.defer(() -> Observable.just(ByteAssociation.create(bluetoothGattDescriptor, value)));
    }

    private RxBleConnectionState mapConnectionStateToRxBleConnectionStatus(int newState) {

        switch (newState) {
            case BluetoothGatt.STATE_CONNECTING:
                return RxBleConnectionState.CONNECTING;
            case BluetoothGatt.STATE_CONNECTED:
                return RxBleConnectionState.CONNECTED;
            case BluetoothGatt.STATE_DISCONNECTING:
                return RxBleConnectionState.DISCONNECTING;
            default:
                return RxBleConnectionState.DISCONNECTED;
        }
    }

    private <T> Observable.Transformer<T, T> getSubscribeAndObserveOnTransformer() {
        return observable -> observable.subscribeOn(callbackScheduler).observeOn(callbackScheduler);
    }

    private boolean propagateStatusErrorIfGattErrorOccurred(int status, BleGattOperationType operationType) {
        final boolean isError = status != BluetoothGatt.GATT_SUCCESS;

        if (isError) {
            statusErrorSubject.onError(new BleGattException(status, operationType));
            bluetoothGattBehaviorSubject.onCompleted();
        }

        return isError;
    }

    private <T> Observable<T> withHandlingStatusError(Observable<T> observable) {
        //noinspection unchecked
        return Observable.merge(
                (Observable<? extends T>) statusErrorSubject.asObservable(), // statusErrorSubject emits only errors
                observable
        );
    }

    public BluetoothGattCallback getBluetoothGattCallback() {
        return bluetoothGattCallback;
    }

    public Observable<BluetoothGatt> getBluetoothGatt() {
        return bluetoothGattBehaviorSubject;
    }

    /**
     * @return Observable that never emits onNexts.
     * @throws BleDisconnectedException emitted in case of a disconnect that is a part of the normal flow
     * @throws BleGattException         emitted in case of connection was interrupted unexpectedly.
     */
    public <T> Observable<T> observeDisconnect() {
        //noinspection unchecked
        return disconnectedErrorObservable;
    }

    public Observable<RxBleConnectionState> getOnConnectionStateChange() {
        return withHandlingStatusError(connectionStatePublishSubject);
    }

    public Observable<RxBleDeviceServices> getOnServicesDiscovered() {
        return withHandlingStatusError(servicesDiscoveredPublishSubject);
    }

    public Observable<ByteAssociation<UUID>> getOnCharacteristicRead() {
        return withHandlingStatusError(readCharacteristicPublishSubject);
    }

    public Observable<ByteAssociation<UUID>> getOnCharacteristicWrite() {
        return withHandlingStatusError(writeCharacteristicPublishSubject);
    }

    public Observable<ByteAssociation<UUID>> getOnCharacteristicChanged() {
        return withHandlingStatusError(changedCharacteristicPublishSubject);
    }

    public Observable<ByteAssociation<BluetoothGattDescriptor>> getOnDescriptorRead() {
        return withHandlingStatusError(readDescriptorPublishSubject);
    }

    public Observable<ByteAssociation<BluetoothGattDescriptor>> getOnDescriptorWrite() {
        return withHandlingStatusError(writeDescriptorPublishSubject);
    }

    public Observable<Integer> getOnRssiRead() {
        return withHandlingStatusError(readRssiPublishSubject);
    }

    public RxBleConnectionState getConnectionState() {
        return connectionStateAtomicReference.get();
    }
}

@WIStudent
Copy link
Author

I am not sure if I applied your changes correctly, but it seams that BluetoothGatt is still not closed

09-08 19:48:18.962 26825-27052/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(25496177)
09-08 19:48:18.966 26825-27052/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(116164036)
09-08 19:48:18.970 26825-27052/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(254716787)
09-08 19:48:18.972 26825-27052/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(1233966)
09-08 19:48:18.974 26825-27052/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(43775077)
09-08 19:48:18.976 26825-27052/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(202579784)
09-08 19:48:18.978 26825-27052/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(27928007)
09-08 19:48:18.981 26825-27052/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(171573650)
09-08 19:48:18.982 26825-27049/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationServicesDiscover(266080148)
09-08 19:48:18.984 26825-27049/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(25496177)
09-08 19:48:19.039 26825-26869/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0000 status=1
09-08 19:48:19.049 26825-26869/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationDisconnect(176898444)
09-08 19:48:19.051 26825-27049/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(25496177)
09-08 19:48:19.053 26825-27049/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(116164036)
09-08 19:48:19.068 26825-26825/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:248)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:27)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:97)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:356)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:249)
                                                                                           at android.os.Binder.execTransact(Binder.java:453)
09-08 19:48:19.082 26825-26825/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:248)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:27)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:97)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:356)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:249)
                                                                                           at android.os.Binder.execTransact(Binder.java:453)
09-08 19:48:19.085 26825-27049/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(116164036)
09-08 19:48:19.086 26825-27049/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(254716787)
09-08 19:48:19.163 26825-26825/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:248)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:27)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:97)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:356)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:249)
                                                                                           at android.os.Binder.execTransact(Binder.java:453)
09-08 19:48:19.165 26825-27049/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(254716787)
09-08 19:48:19.166 26825-27049/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(1233966)
09-08 19:48:19.220 26825-26869/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0001 status=1
09-08 19:48:19.259 26825-27055/de.tobiastrumm.bluetoothledmatrix V/RenderScript: 0x7f9611b000 Launching thread(s), CPUs 6
09-08 19:48:19.294 26825-26825/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:248)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:27)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:97)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:356)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:249)
                                                                                           at android.os.Binder.execTransact(Binder.java:453)
09-08 19:48:19.296 26825-27049/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(1233966)
09-08 19:48:19.297 26825-27049/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(43775077)
09-08 19:48:19.315 26825-26825/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:248)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:27)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:97)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:356)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:249)
                                                                                           at android.os.Binder.execTransact(Binder.java:453)
09-08 19:48:19.317 26825-27049/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(43775077)
09-08 19:48:19.318 26825-27049/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(202579784)
09-08 19:48:19.326 26825-26825/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:248)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:27)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:97)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:356)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:249)
                                                                                           at android.os.Binder.execTransact(Binder.java:453)
09-08 19:48:19.327 26825-27049/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(202579784)
09-08 19:48:19.328 26825-27049/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(27928007)
09-08 19:48:19.342 26825-26825/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:248)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:27)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:97)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:356)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:249)
                                                                                           at android.os.Binder.execTransact(Binder.java:453)
09-08 19:48:19.344 26825-27049/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(27928007)
09-08 19:48:19.345 26825-27049/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(171573650)
09-08 19:48:19.353 26825-26851/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0003 status=1
09-08 19:48:19.358 26825-26825/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:248)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:27)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:97)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:356)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:249)
                                                                                           at android.os.Binder.execTransact(Binder.java:453)
09-08 19:48:19.360 26825-27049/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(171573650)
09-08 19:48:19.361 26825-27049/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationDisconnect(176898444)
09-08 19:48:19.375 26825-26825/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:248)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:27)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:97)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:356)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:249)
                                                                                           at android.os.Binder.execTransact(Binder.java:453)
09-08 19:48:19.376 26825-26825/de.tobiastrumm.bluetoothledmatrix D/BluetoothManager: getConnectionState()
09-08 19:48:19.377 26825-26825/de.tobiastrumm.bluetoothledmatrix D/BluetoothManager: getConnectedDevices
09-08 19:48:19.379 26825-26825/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: cancelOpen() - device: B8:27:EB:A7:1B:9D
09-08 19:48:19.382 26825-27049/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationDisconnect(176898444)
09-08 19:48:19.385 26825-26837/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=5 device=B8:27:EB:A7:1B:9D
09-08 19:48:19.386 26825-26837/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onConnectionStateChange newState=0 status=0

Actually I am starting to belive that this isn't an issue with RxAndroidBle but with Android itself. I originally assumed that closing BluetoothGatt would clear the cache that holds the mapping between characteristic UUIDs and handles. I did some more tests and noticed that the following scenario still causes CHARACTERISTIC_READ errors despite closing BluetoothGatt:

  1. GATT service is created on the peripheral
  2. App connects to the peripheral
  3. App reads from/writes to characteristics
  4. App unsubscribes from connectionObervable -> Device disconnects, BluetoothGatt is closed
  5. On the peripheral the service is removed and added again. This causes the characteristics' handles to change
  6. The app connects to the peripheral again
  7. The app tries to read from a characteristic -> BleGattException(status=1, CHARACTERISTIC_READ), the device is disconnected, BluetoothGatt is not closed

I did some research and found this issue: Android does not discover services if device supports Service Changed. It seams that Android assumes that handles won't change, even if the peripheral includes the "service changed" characteristic. This also explains why the issue is solved by disabling and re-enabling bluetooth on the Android device.

For me personally this isn't a big issue because all I wanted to do was to experiment with BLE and to control some LEDs with it. I just have to make sure that the handles don't change while I am using it, or I have to restart bluetooth on my Android device.

But if you want to look further into the issue of changing handles, I put the code that uses BlueZ to create the peripheral and the code for the app on Github a few days ago.
https://github.com/WIStudent/Bluetooth-Low-Energy-LED-Matrix
https://github.com/WIStudent/Bluetooth-LED-Matrix-App

@dariuszseweryn
Copy link
Owner

Thanks for sharing the code - I will try to recreate the issue locally.
There are two issues I want to address:

  1. Connection is not being properly closed because somehow the final callback comes after the RxBleOperationDisconnect finishes like you can see here:
09-08 19:48:19.361 26825-27049/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationDisconnect(176898444)
09-08 19:48:19.375 26825-26825/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:248)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:27)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:97)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:356)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:249)
                                                                                           at android.os.Binder.execTransact(Binder.java:453)
09-08 19:48:19.376 26825-26825/de.tobiastrumm.bluetoothledmatrix D/BluetoothManager: getConnectionState()
09-08 19:48:19.377 26825-26825/de.tobiastrumm.bluetoothledmatrix D/BluetoothManager: getConnectedDevices
09-08 19:48:19.379 26825-26825/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: cancelOpen() - device: B8:27:EB:A7:1B:9D
09-08 19:48:19.382 26825-27049/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationDisconnect(176898444)
09-08 19:48:19.385 26825-26837/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=5 device=B8:27:EB:A7:1B:9D
09-08 19:48:19.386 26825-26837/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onConnectionStateChange newState=0 status=0

This situation prevent's closing the BluetoothGatt even when calling BluetoothGatt.close().

The second thing is to allow using BluetoothGatt.refresh() method via reflection. Calling this method should allow proper functioning of BLE devices that change their services / characteristics without putting the BluetoothAdapter through on/off cycle.

@lavenj
Copy link

lavenj commented Sep 26, 2016

Hi @DariuszAniszewski -- I'm seeing the same output in my project. It seems like the disconnect callbacks are being fired before the connection actually closes. Is this a correct assessment? Any possibility for a bugfix?

@dariuszseweryn
Copy link
Owner

@lavenj @WIStudent Sorry for such a long wait. I have a possible bugfix for the situation where the BluetoothGatt.close() method is being called before the Android actually disconnects the BluetoothGatt.
I could either push the possible fix to a branch for you to test or I will try to setup the test procedure myself.
Best Regards

@WIStudent
Copy link
Author

I moved on to a different project so I can't test it at the moment.

@lavenj
Copy link

lavenj commented Nov 2, 2016

@dariuszseweryn thanks for looking at this! We have a reasonable workaround implemented so are OK for now. This library continues to be a huge help.

Off-topic but discovered RxBleAdapterStateObservable while digging through the source. So clean and easy! You should throw it in the docs if it's not already in there 😄

@dariuszseweryn
Copy link
Owner

@lavenj can you share more info about the workaround?
About the RxBleAdapterStateObservable I will think about mentioning it the docs. ;)

@WIStudent I am trying to use your Raspberry Pi 3 script to recreate the issue. I have installed a fresh Raspbian on the RPi3 and commented out all interactions with the display from the source code. I have enabled the bluetooth by calling sudo systemctl enable bluetooth but still the script returns:

GattManager1 interface not found
LEAdvertisingManager1 interface not found
Traceback (most recent call last):
  File "led_matrix.py", line 216, in <module>
    main()
  File "led_matrix.py", line 194, in main
    service_manager.RegisterApplication(app.get_path(), {},
AttributeError: 'NoneType' object has no attribute 'RegisterApplication'

I am not very experienced with linux and Raspberry Pi configuration so maybe you could point me in the right direction. Possible causes I can think off:

  • I should enable something in the system prior to running the script
  • I must update the BlueZ 5.23 -> 5.41 (rather a cumbersome process from what I have googled so far)
  • I lack of some dependencies with the DBus but the imports didn't failed so I don't think so
    Any hints you could give me?

@WIStudent
Copy link
Author

I highly recommend updating Bluez to the latest version (which is currently 5.43) . Some of its BLE features are quite new and might not be impemented in an older version. I used this tutorial to compile and install Bluez from source on a Raspberry Pi. It should only take a few minutes.

If you don't want to update, you need to set at least the --experimental flag in the bluez service configuration in order to access the missing dbus interfaces. The process is described at the end of the tutorial.

If you have still issues accessing the dbus interfaces after that, make sure that you have the packages python-gi, python3-gi and python-dbus installed.

sudo apt-get install python-gi python3-gi python-dbus

The first two will install the python 2 and 3 bindings for GObject, the third one will install the python-dbus library.

If you downloaded the bluez source directory, you can also try to run the example-gatt-server and the example-advertisement python script from the bluez-5.xx/test folder. The first one creates a heart rate GATT service and the second one creates the corresponding advertisement. They use the same libraries I used in my script.

@dariuszseweryn
Copy link
Owner

@WIStudent
Thank you for the instructions. I have updated the BlueZ according to the tutorial flawlessly. I have checked your code against current master branch using code:

rxBleClient.getBleDevice(macAddress)
                .establishConnection(this, false)
                .flatMap(rxBleConnection -> Observable
                        .interval(1, TimeUnit.SECONDS)
                        .flatMap(i -> rxBleConnection.readCharacteristic(UUID.fromString("00002a38-0000-1000-8000-00805f9b34fb")))
                )
                .subscribe(
                        read -> Log.d("read", "read"),
                        error -> Log.e("XXX", "Error", error)
                );

which connects to the RPi3 and every second it tries to read a characteristic. Then at some point I closed the gatt server script and got a proper closing of the BluetoothGatt.

11-04 14:42:31.026 25628-26420/com.polidea.rxandroidble.sample D/read: read
11-04 14:42:31.028 25628-25641/com.polidea.rxandroidble.sample D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(203958134)
11-04 14:42:31.924 25628-30697/com.polidea.rxandroidble.sample D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(21262938)
11-04 14:42:31.924 25628-25641/com.polidea.rxandroidble.sample D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(21262938)
11-04 14:42:32.035 25628-25639/com.polidea.rxandroidble.sample D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=00002a38-0000-1000-8000-00805f9b34fb status=0
11-04 14:42:32.036 25628-26420/com.polidea.rxandroidble.sample D/read: read
11-04 14:42:32.036 25628-25641/com.polidea.rxandroidble.sample D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(21262938)
11-04 14:42:32.924 25628-30697/com.polidea.rxandroidble.sample D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(86345726)
11-04 14:42:32.925 25628-25641/com.polidea.rxandroidble.sample D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(86345726)
11-04 14:42:32.995 25628-25658/com.polidea.rxandroidble.sample D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=00002a38-0000-1000-8000-00805f9b34fb status=0
11-04 14:42:32.996 25628-26420/com.polidea.rxandroidble.sample D/read: read
11-04 14:42:32.996 25628-25641/com.polidea.rxandroidble.sample D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(86345726)
11-04 14:42:33.929 25628-30697/com.polidea.rxandroidble.sample D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(116747362)
11-04 14:42:33.943 25628-25641/com.polidea.rxandroidble.sample D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(116747362)
11-04 14:42:34.076 25628-25640/com.polidea.rxandroidble.sample D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=00002a38-0000-1000-8000-00805f9b34fb status=1
11-04 14:42:34.076 25628-25640/com.polidea.rxandroidble.sample I/RxBle#RadioOperation: onError
                                                                                       BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:248)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:25)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:97)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:356)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:249)
                                                                                           at android.os.Binder.execTransact(Binder.java:453)
11-04 14:42:34.077 25628-25640/com.polidea.rxandroidble.sample E/XXX: Error
                                                                      BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                          at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:248)
                                                                          at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:25)
                                                                          at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:97)
                                                                          at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:356)
                                                                          at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:249)
                                                                          at android.os.Binder.execTransact(Binder.java:453)
11-04 14:42:34.077 25628-25640/com.polidea.rxandroidble.sample D/RxBle#Radio:   QUEUED RxBleRadioOperationDisconnect(149083612)
11-04 14:42:34.078 25628-25641/com.polidea.rxandroidble.sample D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(116747362)
11-04 14:42:34.078 25628-25641/com.polidea.rxandroidble.sample D/RxBle#Radio:  STARTED RxBleRadioOperationDisconnect(149083612)
11-04 14:42:34.078 25628-25628/com.polidea.rxandroidble.sample D/BluetoothManager: getConnectionState()
11-04 14:42:34.078 25628-25628/com.polidea.rxandroidble.sample D/BluetoothManager: getConnectedDevices
11-04 14:42:34.080 25628-25628/com.polidea.rxandroidble.sample D/BluetoothGatt: cancelOpen() - device: B8:27:EB:B3:78:18
11-04 14:42:34.085 25628-25639/com.polidea.rxandroidble.sample D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=5 device=B8:27:EB:B3:78:18
11-04 14:42:34.085 25628-25639/com.polidea.rxandroidble.sample D/RxBle#BluetoothGatt: onConnectionStateChange newState=0 status=0
11-04 14:42:34.086 25628-25641/com.polidea.rxandroidble.sample D/RxBle#Radio: FINISHED RxBleRadioOperationDisconnect(149083612)
11-04 14:42:34.086 25628-25628/com.polidea.rxandroidble.sample D/BluetoothGatt: close()
11-04 14:42:34.086 25628-25628/com.polidea.rxandroidble.sample D/BluetoothGatt: unregisterApp() - mClientIf=5

So perhaps some recent fix has unintentionally fixed this issue as well. I was checking with Nexus 5 and Nexus 5X both with Android 6.0.1. Fun fact: I couldn't get any device with Android < 6.0 to connect to the Raspberry Pi 3 - always getting status=133 (GATT_ERROR) when connecting.

It would be awesome if you could re-check this issue using the SNAPSHOT release or the newest version if it will be available before.

Yet - I still need to add a refresh() function for clearing the BluetoothGatt state.

@WIStudent
Copy link
Author

I tested it again with the 1.1.0-SNAPSHOT. I used bluez-5.41 again on the Pi to rule out any changes on that side. But Unfortunately I have upgraded my Nexus 5x to Android 7.0 in the meantime so I can't tell if the problem is solved in Android 6.

Interestingly the behavior changed in Android 7 again. Reading from and writing to an existing characteristic works as expected.

11-06 22:01:59.785 28082-28082/de.tobiastrumm.bluetoothledmatrix D/LedControlActivity: Pressed button [0][0]
11-06 22:01:59.794 28082-28082/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(90263684)
11-06 22:01:59.795 28082-28082/de.tobiastrumm.bluetoothledmatrix D/LedMatrix: Old: Col 0 Color 1: 00000000 00000000
11-06 22:01:59.796 28082-28105/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(90263684)
11-06 22:01:59.796 28082-28082/de.tobiastrumm.bluetoothledmatrix D/LedMatrix: New: Col 0 Color 1: 01000000 00000000
11-06 22:01:59.805 28082-28082/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicWrite(58975849)
11-06 22:01:59.960 28082-28098/de.tobiastrumm.bluetoothledmatrix W/BluetoothGatt: onCharacteristicRead() - Device=B8:27:EB:A7:1B:9D handle=48 Status=0
11-06 22:01:59.962 28082-28098/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0000 status=0
11-06 22:01:59.965 28082-28214/de.tobiastrumm.bluetoothledmatrix D/LedControlActivity: read
11-06 22:01:59.968 28082-28105/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(90263684)
11-06 22:01:59.968 28082-28105/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicWrite(58975849)
11-06 22:02:00.079 28082-28094/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicWrite characteristic=12345678-1234-5678-1234-56789abc0000 status=0
11-06 22:02:00.081 28082-28214/de.tobiastrumm.bluetoothledmatrix D/LedControlActivity: write
11-06 22:02:00.081 28082-28105/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicWrite(58975849)

Bluez on the Pi received and sent the following packets (Use sudo btmon see the packets in real time)

> ACL Data RX: Handle 64 flags 0x02 dlen 7                   [hci0] 1357.182785
      ATT: Read Request (0x0a) len 2
        Handle: 0x0030
< ACL Data TX: Handle 64 flags 0x00 dlen 7                   [hci0] 1357.185679
      ATT: Read Response (0x0b) len 2
        Value: 0000
> ACL Data RX: Handle 64 flags 0x02 dlen 9                   [hci0] 1357.302857
      ATT: Write Request (0x12) len 4
        Handle: 0x0030
          Data: 4000
< ACL Data TX: Handle 64 flags 0x00 dlen 5                   [hci0] 1357.312835
      ATT: Write Response (0x13) len 0

The next log shows the attempt to read and write the same characteristic after it was removed:

11-06 22:04:49.168 28082-28082/de.tobiastrumm.bluetoothledmatrix D/LedControlActivity: Pressed button [0][0]
11-06 22:04:49.171 28082-28082/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(229704388)
11-06 22:04:49.172 28082-28082/de.tobiastrumm.bluetoothledmatrix D/LedMatrix: Old: Col 0 Color 2: 01010000 00000000
11-06 22:04:49.172 28082-28105/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(229704388)
11-06 22:04:49.172 28082-28082/de.tobiastrumm.bluetoothledmatrix D/LedMatrix: New: Col 0 Color 2: 10010000 00000000
11-06 22:04:49.175 28082-28082/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicWrite(48455593)
11-06 22:04:49.281 28082-28094/de.tobiastrumm.bluetoothledmatrix W/BluetoothGatt: onCharacteristicRead() - Device=B8:27:EB:A7:1B:9D handle=48 Status=1
11-06 22:04:49.283 28082-28094/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0000 status=1
11-06 22:04:49.286 28082-28105/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(229704388)
11-06 22:04:49.286 28082-28094/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: Read: Error
                                                                                       BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:248)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:25)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:97)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:287)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:117)
                                                                                           at android.os.Binder.execTransact(Binder.java:565)
11-06 22:04:49.287 28082-28105/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicWrite(48455593)
11-06 22:04:49.288 28082-28082/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: Write: Error
                                                                                       BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:248)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:25)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:97)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:287)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:117)
                                                                                           at android.os.Binder.execTransact(Binder.java:565)
11-06 22:04:49.289 28082-28105/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicWrite(48455593)
11-06 22:04:49.402 28082-28095/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicWrite characteristic=12345678-1234-5678-1234-56789abc0000 status=1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                   [hci0] 1526.505062
      ATT: Read Request (0x0a) len 2
        Handle: 0x0030
< ACL Data TX: Handle 64 flags 0x00 dlen 9                   [hci0] 1526.505427
      ATT: Error Response (0x01) len 4
        Read Request (0x0a)
        Handle: 0x0030
        Error: Invalid Handle (0x01)
> ACL Data RX: Handle 64 flags 0x02 dlen 9                   [hci0] 1526.625134
      ATT: Write Request (0x12) len 4
        Handle: 0x0030
          Data: 9000
< ACL Data TX: Handle 64 flags 0x00 dlen 9                   [hci0] 1526.625376
      ATT: Error Response (0x01) len 4
        Write Request (0x12)
        Handle: 0x0030
        Error: Invalid Handle (0x01)

The BleGattExceptions are still thrown but instead of closing the connection automatically it is now kept alive.

@dariuszseweryn
Copy link
Owner

I wish I had written tests for RxBleGattCallback earlier. No disconnection when receiving status error is a behaviour planned for release 2.0.0 but it is a bug in 1.x.x.

@dariuszseweryn
Copy link
Owner

@WIStudent Excuse me for asking again but I have fixed the behaviour to be inline with 1.x.x and it should be working fine now. (I hope... - it at least works as intended for me)
Thanks! Cheers!

@WIStudent
Copy link
Author

WIStudent commented Nov 18, 2016

I switched to the 1.2.0-SNAPSHOT and tested it again. Now I see the same behavior as you do.

11-18 21:01:59.212 23273-23273/de.tobiastrumm.bluetoothledmatrix D/LedControlActivity: Pressed button [2][3]
11-18 21:01:59.217 23273-23273/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicRead(75725609)
11-18 21:01:59.219 23273-23273/de.tobiastrumm.bluetoothledmatrix D/LedMatrix: Old: Col 3 Color 2: 00000001 00000000
11-18 21:01:59.220 23273-23273/de.tobiastrumm.bluetoothledmatrix D/LedMatrix: New: Col 3 Color 2: 00000010 00000000
11-18 21:01:59.220 23273-23627/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationCharacteristicRead(75725609)
11-18 21:01:59.226 23273-23273/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationCharacteristicWrite(57374650)
11-18 21:01:59.355 23273-23285/de.tobiastrumm.bluetoothledmatrix W/BluetoothGatt: onCharacteristicRead() - Device=B8:27:EB:A7:1B:9D handle=35 Status=1
11-18 21:01:59.357 23273-23285/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onCharacteristicRead characteristic=12345678-1234-5678-1234-56789abc0002 status=1
11-18 21:01:59.363 23273-23285/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: Read: Error
                                                                                       BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:248)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:25)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:97)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:287)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:117)
                                                                                           at android.os.Binder.execTransact(Binder.java:565)
11-18 21:01:59.363 23273-23285/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: Write: Error
                                                                                       BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:248)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:25)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:97)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:287)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:117)
                                                                                           at android.os.Binder.execTransact(Binder.java:565)
11-18 21:01:59.364 23273-23285/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: Read: Error
                                                                                       BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:248)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:25)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:97)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:287)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:117)
                                                                                           at android.os.Binder.execTransact(Binder.java:565)
11-18 21:01:59.364 23273-23285/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: Write: Error
                                                                                       BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:248)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:25)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:97)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:287)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:117)
                                                                                           at android.os.Binder.execTransact(Binder.java:565)
11-18 21:01:59.366 23273-23285/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  REMOVED RxBleRadioOperationCharacteristicWrite(57374650)
11-18 21:01:59.367 23273-23273/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:   QUEUED RxBleRadioOperationDisconnect(221169268)
11-18 21:01:59.367 23273-23627/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationCharacteristicRead(75725609)
11-18 21:01:59.368 23273-23627/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio:  STARTED RxBleRadioOperationDisconnect(221169268)
11-18 21:01:59.392 23273-23273/de.tobiastrumm.bluetoothledmatrix E/LedControlActivity: BleGattException{status=1, bleGattOperation=BleGattOperation{description='CHARACTERISTIC_READ'}}
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.propagateStatusErrorIfGattErrorOccurred(RxBleGattCallback.java:248)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback.access$100(RxBleGattCallback.java:25)
                                                                                           at com.polidea.rxandroidble.internal.connection.RxBleGattCallback$1.onCharacteristicRead(RxBleGattCallback.java:97)
                                                                                           at android.bluetooth.BluetoothGatt$1.onCharacteristicRead(BluetoothGatt.java:287)
                                                                                           at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:117)
                                                                                           at android.os.Binder.execTransact(Binder.java:565)
11-18 21:01:59.398 23273-23273/de.tobiastrumm.bluetoothledmatrix D/BluetoothManager: getConnectionState()
11-18 21:01:59.398 23273-23273/de.tobiastrumm.bluetoothledmatrix D/BluetoothManager: getConnectedDevices
11-18 21:01:59.492 23273-23273/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: cancelOpen() - device: B8:27:EB:A7:1B:9D
11-18 21:01:59.495 23273-23286/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=5 device=B8:27:EB:A7:1B:9D
11-18 21:01:59.496 23273-23286/de.tobiastrumm.bluetoothledmatrix D/RxBle#BluetoothGatt: onConnectionStateChange newState=0 status=0
11-18 21:01:59.497 23273-23627/de.tobiastrumm.bluetoothledmatrix D/RxBle#Radio: FINISHED RxBleRadioOperationDisconnect(221169268)
11-18 21:01:59.539 23273-23273/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: close()
11-18 21:01:59.539 23273-23273/de.tobiastrumm.bluetoothledmatrix D/BluetoothGatt: unregisterApp() - mClientIf=5

@dariuszseweryn
Copy link
Owner

So it seems that cause of this issue (that is in the topic) is resolved.
The error occurs because the handles had changed but the connection is disconnected and closed properly. Thank you for reporting and feedback. Cheers!

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

No branches or pull requests

3 participants