Failed to read newly loaded characteristics after services changed #692

Dachmian · 2020-05-26T11:02:11Z

Describe the bug
I am having issues reading encrypted characteristics for a bonded bluetooth device.
When connecting to the device it is only advertising 2 services but by writing to one of the exposed characteristics, it sends a Services Changed Indication and loads the remaining Characteristics.

The phone recognises the services changed indication and the remaining services and characteristics are discoverable using the discoverServices() method.
However, when reading the newly loaded characteristics after successful discovery I either get:

I/RxBle#GattCallback: MAC=MAC     onCharacteristicRead(), status=1, value=[uuid=UUID hexValue=null]

or:

OnErrorNotification[com.polidea.rxandroidble2.exceptions.BleGattCharacteristicException: GATT exception from MAC=MAC, status 1 (GATT_INVALID_HANDLE), type BleGattOperation{description='CHARACTERISTIC_READ'}. (Look up status 0x01 here https://android.googlesource.com/platform/external/bluetooth/bluedroid/+/android-5.1.0_r1/stack/include/gatt_api.h)]

errors.

I thought this was due to something wrong going on with the discovery and I used the suggestion here: #453 (comment)
to refresh cache. However I am still unable to read the characteristics that are loaded during connection. But this time I get another error:

W/BluetoothGatt: onCharacteristicRead() failed to find characteristic!

even though discoverServices() shows that it has discovered the characteristics I am trying to read.

If I connect to the device via my app and then go into LightBlue BLE app, I can browse all services and characteristics and read them successfully.

Please let me know what kind of logs would be helpful or suggestions for steps I should try to overcome this issue.

To Reproduce

Connect
Write command to load remaining services
Discover services using discoverServices() method
Read newly loaded characteristic

Expected behavior
Able to read newly loaded characteristics

Smartphone (please complete the following information):

Device: [e.g. Huawei P20]
OS: [e.g. Android 8.1.0]
Library version: [e.g. 1.11.1]

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

RxBleClient.updateLogOptions(new LogOptions.Builder()
        .setLogLevel(LogConstants.DEBUG)
        .setMacAddressLogSetting(LogConstants.MAC_ADDRESS_FULL)
        .setUuidsLogSetting(LogConstants.UUIDS_FULL)
        .setShouldLogAttributeValues(true)
        .build()
);

Additional context
Add any other context about the problem here.

The text was updated successfully, but these errors were encountered:

Dachmian · 2020-05-26T13:15:44Z

When loading custom firmware to my bluetooth device which has all the services and characteristics exposed solves the issue. I am able to interact with all the services and characteristics so it excludes the bonding / encryption of the characteristics to be the issue.

dariuszseweryn · 2020-05-26T14:32:19Z

I do not have access to any peripheral that behaves like you described. You could also share how you have modelled your interaction with the peripheral. I do not expect invalid handle exception if you used BluetoothGattCharacteristic API directly. UUID API could use cached BluetoothGattCharacteristic under the hood.
A log of the connection could also help me understand what have happened.

Dachmian · 2020-05-26T15:17:38Z

Hello @dariuszseweryn

I have a RxBleManager class which holds the RxBleClient, a BehaviorRelay which exposes the ble connection and ble device, and contains all the api calls the app uses.
I also have a connection module which contains the connection logic which scans for devices, establishes connection, sends necessary commands and then exposes the ble connection and ble device to the RxBleManager Relay.

Pseudo code for connection procedure in the connection module:

val scannedDevice = rxBleManager.scanForDevices(services)

val connectViaScan = scannedDevice
    .flatMap { scannedDevice ->
        scannedDevice.scannedPeripheral.bleDevice.establishConnection(true)
            .doOnError { error -> error.localizedMessage?.let { logE(it) } }
            .delay(1, TimeUnit.SECONDS)
            .map{Pair(scannedDevice.scannedPeripheral.bleDevice, it)}
    }
    .flatMap{ /* Interact with open characteristics which loads the new services*/}

connectViaScan.subscribe{scannedDevice ->
    rxBleManager.bleRelay.accept(scannedDevice)
}

RxBleManager Code Snippets

fun scanForDevices(withServices: List<AdvertisedServices>): Observable<ScannedDevice>{
    return rxBleClient.observeStateChanges().startWith(rxBleClient.state)
        .filter { it == RxBleClient.State.READY }
        .flatMap {
            retrievePeripherals(
                withServices.map{it.serviceUuid}
            )
        }
}

fun retrievePeripherals(uuids: List<String>): Observable<ScanResult> {
    val scanSettings =
        ScanSettings.Builder().setScanMode(ScanSettings.SCAN_MODE_BALANCED).build()
    val listOfScanFilter = mutableListOf<ScanFilter>()
    uuids.forEach {
        listOfScanFilter.add(ScanFilter.Builder().setServiceUuid(ParcelUuid.fromString(it)).build())
    }
    return rxBleClient.scanBleDevices(scanSettings, *listOfScanFilter.toTypedArray())
}



fun readCharacteristic(characteristicIdentifier: BluetoothGattCharacteristic): Observable<ByteArray> {
    return bleRelay.map { it.second }.take(1).flatMap { rxBleConnection ->
        rxBleConnection.readCharacteristic(characteristicIdentifier).toObservable()
    }
}

fun readCharacteristicUuid(uuid: UUID): Observable<ByteArray> {
    return bleRelay.map { it.second }.take(1).flatMap { rxBleConnection ->
        rxBleConnection.readCharacteristic(uuid).toObservable()
    }
}

Then later inside the app I try to read certain characteristics using either of the convenience methods I defined but all of them returns the errors mentioned.

rxBleManager.readCharacteristic(uuid).subscribe()
rxBleManager.readCharacteristic(characteristic).subscribe()

I will run the tests again and produce the logs shortly. Thank you for the quick answer!

Dachmian · 2020-05-26T15:25:36Z

To read using the BluetoothGattCharacteristic API directly I took your example from this comment: #635 (comment)

Dachmian · 2020-06-03T11:26:40Z

@dariuszseweryn I compiled a small test project to show the issue I am facing.

The code I am running is:

    private fun runTestApp(){
        val rxBleClient = RxBleClient.create(this.applicationContext)

        RxBleClient.updateLogOptions(
            LogOptions.Builder()
                .setLogLevel(LogConstants.DEBUG)
                .setMacAddressLogSetting(LogConstants.MAC_ADDRESS_FULL)
                .setUuidsLogSetting(LogConstants.UUIDS_FULL)
                .setShouldLogAttributeValues(true)
                .build()
        )

        val disposable = rxBleClient.observeStateChanges()
            .startWith(rxBleClient.state)
            .filter { it == RxBleClient.State.READY }
            .flatMap {
                rxBleClient.scanBleDevices(
                    ScanSettings.Builder().setScanMode(ScanSettings.SCAN_MODE_LOW_LATENCY).build(),
                    *mutableListOf<ScanFilter>(ScanFilter.Builder().setServiceUuid(ParcelUuid.fromString("0000fFf0-0000-1000-8000-00805f9b34fb")).build()).toTypedArray()
                )
            }
            .filter{it.bleDevice.macAddress == deviceMacAddress}
            .distinctUntilChanged{t1, t2 ->  t1.bleDevice.macAddress == t2.bleDevice.macAddress}
            .delay(3, TimeUnit.SECONDS)
            .flatMap{scanResult ->
                scanResult.bleDevice.establishConnection(false).map{Pair(scanResult.bleDevice, it)}
            }
            .delay(3, TimeUnit.SECONDS)
            .flatMap{data ->
                data.second.queue(bluetoothGattRefreshCustomOp).ignoreElements()
                    .andThen(data.second.queue(discoverServicesCustomOp))
                    .doAfterNext { Log.d("First Services from custom refresh","services: ${it.map{it.characteristics.map{it.uuid.toString()}}}")}
                    .toFlowable(BackpressureStrategy.BUFFER).toObservable().map{data}
            }
            .delay(3, TimeUnit.SECONDS)
            .flatMap{data ->
                data.second.discoverServices().doAfterSuccess { Log.d("First Services from RxAndroidBle","services: ${it.bluetoothGattServices.map{it.characteristics.map{it.uuid.toString()}}}")}.toObservable().map{data}
            }
            .delay(3, TimeUnit.SECONDS)
            .flatMap{data ->
                data.second.readCharacteristic(
                    UUID.fromString("0000fef2-0000-1000-8000-00805f9b34fb")
                ).toObservable().map{data}
            }
            .delay(3, TimeUnit.SECONDS)
            .flatMap{data ->
                data.second.writeCharacteristic(
                    UUID.fromString("0000fef2-0000-1000-8000-00805f9b34fb"),
                    byteArrayOf(0x39,0x33,0x31,0x61,0x64,0x61,0x34,0x37,0x45,0x30,0x32,0x41,0x33,0x42,0x39,0x44)
                ).toObservable().map{data}
            }
            .delay(3, TimeUnit.SECONDS)
            .flatMap{data ->
                data.second.writeCharacteristic(
                    UUID.fromString("0000fef1-0000-1000-8000-00805f9b34fb"),
                    byteArrayOf(0x01)
                ).toObservable().map{data}
            }
            .delay(3, TimeUnit.SECONDS)
            .flatMap{data ->
                data.second.queue(bluetoothGattRefreshCustomOp).ignoreElements()
                    .andThen(data.second.queue(discoverServicesCustomOp))
                    .delay(3, TimeUnit.SECONDS)
                    .flatMapSingle{services ->
                        Log.d("Second Services from custom refresh","services: ${services.map{it.characteristics.map{it.uuid.toString()}}}")
                        return@flatMapSingle data.second.readCharacteristic(services[0].characteristics[0].uuid)
                    }
                    .toFlowable(BackpressureStrategy.BUFFER).toObservable().map{data}
            }
            .delay(3, TimeUnit.SECONDS)
            .flatMap{data ->
                data.second.discoverServices().doAfterSuccess { Log.d("Second Services from RxAndroidBle","services: ${it.bluetoothGattServices.map{it.characteristics.map{it.uuid.toString()}}}")}.toObservable().map{data}
            }
            .delay(3, TimeUnit.SECONDS)
            .flatMap{data ->
                data.second.readCharacteristic(
                    UUID.fromString("0000fee3-0000-1000-8000-00805f9b34fb")
                ).toObservable()
            }
            .delay(3, TimeUnit.SECONDS)
            .subscribe{
                print(it)
            }
    }

And the logs from the session are:

I/Utils: Utils_isSuperResolutionSupport [load libai_client.success]
D/HwGalleryCacheManagerImpl: mIsEffect:false
D/HwRTBlurUtils: check blur style for HwPhoneWindow, themeResId : 0x7f0d0005, context : com.example.testapplication.MainActivity@ad17bb6, Nhwext : 0, get Blur : disable with , null
D/HwRTBlurUtils: check blur style for HwPhoneWindow, themeResId : 0x7f0d0005, context : com.example.testapplication.MainActivity@ad17bb6, Nhwext : 0, get Blur : disable with , null
D/RxBle#ClientOperationQueue: QUEUED   ScanOperationApi21(216939951)
D/RxBle#ClientOperationQueue: STARTED  ScanOperationApi21(216939951)
I/RxBle#ClientOperationQueue: RUNNING  ScanOperationApi21{ANY_MUST_MATCH -> nativeFilters=[BluetoothLeScanFilter [mDeviceName=null, MAC=null, mUuid=0000fff0-0000-1000-8000-00805f9b34fb, mUuidMask=null, mServiceDataUuid=null, mServiceData=null, mServiceDataMask=null, mManufacturerId=-1, mManufacturerData=null, mManufacturerDataMask=null]]}
I/RxBle#QueueOperation: Scan operation is requested to start.
D/RxBle#ScanOperationApi21: No library side filtering —> debug logs of scanned devices disabled
I/BluetoothAdapter: getBluetoothLeScanner
D/BluetoothAdapter: isLeEnabled(): ON
D/ActivityThread: add activity client record, r= ActivityRecord{80a7229 token=android.os.BinderProxy@70f5b3 {com.example.testapplication/com.example.testapplication.MainActivity}} token= android.os.BinderProxy@70f5b3
D/BluetoothLeScanner: onScannerRegistered() - status=0 scannerId=8 mScannerId=0
I/HwSecImmHelper: mSecurityInputMethodService is null
D/RxBle#ClientOperationQueue: FINISHED ScanOperationApi21(216939951) in 18 ms
I/hwaps: HwAps: JNI_OnLoad
D/OpenGLRenderer:   HWUI Binary is  enabled
D/OpenGLRenderer: HWUI GL Pipeline
I/zygote64: android::hardware::configstore::V1_0::ISurfaceFlingerConfigs::hasWideColorDisplay retrieved: 0
I/OpenGLRenderer: Initialized EGL, version 1.4
D/OpenGLRenderer: Swap behavior 2
D/mali_winsys: EGLint new_window_surface(egl_winsys_display *, void *, EGLSurface, EGLConfig, egl_winsys_surface **, egl_color_buffer_format *, EGLBoolean) returns 0x3000
W/InputMethodManager: startInputReason = 1
W/InputMethodManager: startInputReason = 5
I/RxBle#Client: ScanResult{bleDevice=RxBleDeviceImpl{MAC='54:6C:0E:A0:44:45', name=SimpleBLEPeripheral}, rssi=-67, timestampNanos=1209847210634060, callbackType=CALLBACK_TYPE_ALL_MATCHES, scanRecord=[02, 01, 06, 03, 02, F0, FF, 14, 09, 53, 69, 6D, 70, 6C, 65, 42, 4C, 45, 50, 65, 72, 69, 70, 68, 65, 72, 61, 6C, 05, 12, 50, 00, 20, 03, 02, 0A, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00]}
I/RxBle#Client: ScanResult{bleDevice=RxBleDeviceImpl{MAC='54:6C:0E:A0:44:45', name=SimpleBLEPeripheral}, rssi=-52, timestampNanos=1209847631324164, callbackType=CALLBACK_TYPE_ALL_MATCHES, scanRecord=[02, 01, 06, 03, 02, F0, FF, 14, 09, 53, 69, 6D, 70, 6C, 65, 42, 4C, 45, 50, 65, 72, 69, 70, 68, 65, 72, 61, 6C, 05, 12, 50, 00, 20, 03, 02, 0A, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00]}
I/RxBle#Client: ScanResult{bleDevice=RxBleDeviceImpl{MAC='54:6C:0E:A0:44:45', name=SimpleBLEPeripheral}, rssi=-52, timestampNanos=1209847738473122, callbackType=CALLBACK_TYPE_ALL_MATCHES, scanRecord=[02, 01, 06, 03, 02, F0, FF, 14, 09, 53, 69, 6D, 70, 6C, 65, 42, 4C, 45, 50, 65, 72, 69, 70, 68, 65, 72, 61, 6C, 05, 12, 50, 00, 20, 03, 02, 0A, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00]}
I/RxBle#Client: ScanResult{bleDevice=RxBleDeviceImpl{MAC='54:6C:0E:A0:44:45', name=SimpleBLEPeripheral}, rssi=-52, timestampNanos=1209847846016351, callbackType=CALLBACK_TYPE_ALL_MATCHES, scanRecord=[02, 01, 06, 03, 02, F0, FF, 14, 09, 53, 69, 6D, 70, 6C, 65, 42, 4C, 45, 50, 65, 72, 69, 70, 68, 65, 72, 61, 6C, 05, 12, 50, 00, 20, 03, 02, 0A, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00]}
I/RxBle#Client: ScanResult{bleDevice=RxBleDeviceImpl{MAC='54:6C:0E:A0:44:45', name=SimpleBLEPeripheral}, rssi=-50, timestampNanos=1209848059355414, callbackType=CALLBACK_TYPE_ALL_MATCHES, scanRecord=[02, 01, 06, 03, 02, F0, FF, 14, 09, 53, 69, 6D, 70, 6C, 65, 42, 4C, 45, 50, 65, 72, 69, 70, 68, 65, 72, 61, 6C, 05, 12, 50, 00, 20, 03, 02, 0A, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00]}
I/RxBle#Client: ScanResult{bleDevice=RxBleDeviceImpl{MAC='54:6C:0E:A0:44:45', name=SimpleBLEPeripheral}, rssi=-51, timestampNanos=1209848272387705, callbackType=CALLBACK_TYPE_ALL_MATCHES, scanRecord=[02, 01, 06, 03, 02, F0, FF, 14, 09, 53, 69, 6D, 70, 6C, 65, 42, 4C, 45, 50, 65, 72, 69, 70, 68, 65, 72, 61, 6C, 05, 12, 50, 00, 20, 03, 02, 0A, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00]}
I/RxBle#Client: ScanResult{bleDevice=RxBleDeviceImpl{MAC='54:6C:0E:A0:44:45', name=SimpleBLEPeripheral}, rssi=-56, timestampNanos=1209848483157497, callbackType=CALLBACK_TYPE_ALL_MATCHES, scanRecord=[02, 01, 06, 03, 02, F0, FF, 14, 09, 53, 69, 6D, 70, 6C, 65, 42, 4C, 45, 50, 65, 72, 69, 70, 68, 65, 72, 61, 6C, 05, 12, 50, 00, 20, 03, 02, 0A, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00]}
I/RxBle#Client: ScanResult{bleDevice=RxBleDeviceImpl{MAC='54:6C:0E:A0:44:45', name=SimpleBLEPeripheral}, rssi=-51, timestampNanos=1209848697650205, callbackType=CALLBACK_TYPE_ALL_MATCHES, scanRecord=[02, 01, 06, 03, 02, F0, FF, 14, 09, 53, 69, 6D, 70, 6C, 65, 42, 4C, 45, 50, 65, 72, 69, 70, 68, 65, 72, 61, 6C, 05, 12, 50, 00, 20, 03, 02, 0A, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00]}
I/RxBle#Client: ScanResult{bleDevice=RxBleDeviceImpl{MAC='54:6C:0E:A0:44:45', name=SimpleBLEPeripheral}, rssi=-58, timestampNanos=1209848804551768, callbackType=CALLBACK_TYPE_ALL_MATCHES, scanRecord=[02, 01, 06, 03, 02, F0, FF, 14, 09, 53, 69, 6D, 70, 6C, 65, 42, 4C, 45, 50, 65, 72, 69, 70, 68, 65, 72, 61, 6C, 05, 12, 50, 00, 20, 03, 02, 0A, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00]}
I/RxBle#Client: ScanResult{bleDevice=RxBleDeviceImpl{MAC='54:6C:0E:A0:44:45', name=SimpleBLEPeripheral}, rssi=-58, timestampNanos=1209848912585101, callbackType=CALLBACK_TYPE_ALL_MATCHES, scanRecord=[02, 01, 06, 03, 02, F0, FF, 14, 09, 53, 69, 6D, 70, 6C, 65, 42, 4C, 45, 50, 65, 72, 69, 70, 68, 65, 72, 61, 6C, 05, 12, 50, 00, 20, 03, 02, 0A, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00]}
I/RxBle#Client: ScanResult{bleDevice=RxBleDeviceImpl{MAC='54:6C:0E:A0:44:45', name=SimpleBLEPeripheral}, rssi=-54, timestampNanos=1209849013387184, callbackType=CALLBACK_TYPE_ALL_MATCHES, scanRecord=[02, 01, 06, 03, 02, F0, FF, 14, 09, 53, 69, 6D, 70, 6C, 65, 42, 4C, 45, 50, 65, 72, 69, 70, 68, 65, 72, 61, 6C, 05, 12, 50, 00, 20, 03, 02, 0A, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00]}
I/RxBle#Client: ScanResult{bleDevice=RxBleDeviceImpl{MAC='54:6C:0E:A0:44:45', name=SimpleBLEPeripheral}, rssi=-51, timestampNanos=1209849223618434, callbackType=CALLBACK_TYPE_ALL_MATCHES, scanRecord=[02, 01, 06, 03, 02, F0, FF, 14, 09, 53, 69, 6D, 70, 6C, 65, 42, 4C, 45, 50, 65, 72, 69, 70, 68, 65, 72, 61, 6C, 05, 12, 50, 00, 20, 03, 02, 0A, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00]}
I/RxBle#Client: ScanResult{bleDevice=RxBleDeviceImpl{MAC='54:6C:0E:A0:44:45', name=SimpleBLEPeripheral}, rssi=-53, timestampNanos=1209849332012184, callbackType=CALLBACK_TYPE_ALL_MATCHES, scanRecord=[02, 01, 06, 03, 02, F0, FF, 14, 09, 53, 69, 6D, 70, 6C, 65, 42, 4C, 45, 50, 65, 72, 69, 70, 68, 65, 72, 61, 6C, 05, 12, 50, 00, 20, 03, 02, 0A, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00]}
I/RxBle#Client: ScanResult{bleDevice=RxBleDeviceImpl{MAC='54:6C:0E:A0:44:45', name=SimpleBLEPeripheral}, rssi=-48, timestampNanos=1209849440640830, callbackType=CALLBACK_TYPE_ALL_MATCHES, scanRecord=[02, 01, 06, 03, 02, F0, FF, 14, 09, 53, 69, 6D, 70, 6C, 65, 42, 4C, 45, 50, 65, 72, 69, 70, 68, 65, 72, 61, 6C, 05, 12, 50, 00, 20, 03, 02, 0A, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00]}
I/RxBle#Client: ScanResult{bleDevice=RxBleDeviceImpl{MAC='54:6C:0E:A0:44:45', name=SimpleBLEPeripheral}, rssi=-48, timestampNanos=1209849548863747, callbackType=CALLBACK_TYPE_ALL_MATCHES, scanRecord=[02, 01, 06, 03, 02, F0, FF, 14, 09, 53, 69, 6D, 70, 6C, 65, 42, 4C, 45, 50, 65, 72, 69, 70, 68, 65, 72, 61, 6C, 05, 12, 50, 00, 20, 03, 02, 0A, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00]}
I/RxBle#Client: ScanResult{bleDevice=RxBleDeviceImpl{MAC='54:6C:0E:A0:44:45', name=SimpleBLEPeripheral}, rssi=-48, timestampNanos=1209849654530934, callbackType=CALLBACK_TYPE_ALL_MATCHES, scanRecord=[02, 01, 06, 03, 02, F0, FF, 14, 09, 53, 69, 6D, 70, 6C, 65, 42, 4C, 45, 50, 65, 72, 69, 70, 68, 65, 72, 61, 6C, 05, 12, 50, 00, 20, 03, 02, 0A, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00]}
I/RxBle#Client: ScanResult{bleDevice=RxBleDeviceImpl{MAC='54:6C:0E:A0:44:45', name=SimpleBLEPeripheral}, rssi=-48, timestampNanos=1209849756822080, callbackType=CALLBACK_TYPE_ALL_MATCHES, scanRecord=[02, 01, 06, 03, 02, F0, FF, 14, 09, 53, 69, 6D, 70, 6C, 65, 42, 4C, 45, 50, 65, 72, 69, 70, 68, 65, 72, 61, 6C, 05, 12, 50, 00, 20, 03, 02, 0A, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00]}
I/zygote64: Do partial code cache collection, code=30KB, data=25KB
I/zygote64: After code cache collection, code=30KB, data=25KB
    Increasing code cache capacity to 128KB
I/RxBle#Client: ScanResult{bleDevice=RxBleDeviceImpl{MAC='54:6C:0E:A0:44:45', name=SimpleBLEPeripheral}, rssi=-49, timestampNanos=1209849963564267, callbackType=CALLBACK_TYPE_ALL_MATCHES, scanRecord=[02, 01, 06, 03, 02, F0, FF, 14, 09, 53, 69, 6D, 70, 6C, 65, 42, 4C, 45, 50, 65, 72, 69, 70, 68, 65, 72, 61, 6C, 05, 12, 50, 00, 20, 03, 02, 0A, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00]}
I/RxBle#Client: ScanResult{bleDevice=RxBleDeviceImpl{MAC='54:6C:0E:A0:44:45', name=SimpleBLEPeripheral}, rssi=-47, timestampNanos=1209850171582497, callbackType=CALLBACK_TYPE_ALL_MATCHES, scanRecord=[02, 01, 06, 03, 02, F0, FF, 14, 09, 53, 69, 6D, 70, 6C, 65, 42, 4C, 45, 50, 65, 72, 69, 70, 68, 65, 72, 61, 6C, 05, 12, 50, 00, 20, 03, 02, 0A, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00]}
D/RxBle#ClientOperationQueue: QUEUED   ConnectOperation(202167403)
D/RxBle#ClientOperationQueue: STARTED  ConnectOperation(202167403)
I/RxBle#ClientOperationQueue: RUNNING  ConnectOperation{MAC='54:6C:0E:A0:44:45', autoConnect=false}
D/BluetoothGatt: connect() - device: 54:6C:0E:A0:44:45, auto: false
    registerApp()
D/BluetoothGatt: registerApp() - UUID=120c39ac-30f6-4326-94ff-8e9075047214
D/BluetoothGatt: onClientRegistered() - status=0 clientIf=9
D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=9 device=54:6C:0E:A0:44:45
I/RxBle#GattCallback: MAC='54:6C:0E:A0:44:45'  onConnectionStateChange(), status=0, value=2
D/RxBle#ClientOperationQueue: FINISHED ConnectOperation(202167403) in 2323 ms
D/BluetoothGatt: onConnectionUpdated() - Device=54:6C:0E:A0:44:45 interval=6 latency=0 timeout=500 status=0
I/RxBle#GattCallback: MAC='54:6C:0E:A0:44:45'      onConnectionUpdated(), status=0, interval=6 (7.50 ms), latency=0, timeout=500 (5000 ms)
D/BluetoothGatt: onConnectionUpdated() - Device=54:6C:0E:A0:44:45 interval=39 latency=0 timeout=500 status=0
I/RxBle#GattCallback: MAC='54:6C:0E:A0:44:45'      onConnectionUpdated(), status=0, interval=39 (48.75 ms), latency=0, timeout=500 (5000 ms)
D/RxBle#ConnectionOperationQueue: QUEUED   (64106197)
D/RxBle#ConnectionOperationQueue: STARTED  (64106197)
I/RxBle#ConnectionOperationQueue: RUNNING  com.polidea.rxandroidble2.internal.connection.RxBleConnectionImpl$11@3d22ed5
D/BluetoothGatt: refresh() - device: 54:6C:0E:A0:44:45
D/BluetoothGatt: onConnectionUpdated() - Device=54:6C:0E:A0:44:45 interval=6 latency=0 timeout=500 status=0
I/RxBle#GattCallback: MAC='54:6C:0E:A0:44:45'      onConnectionUpdated(), status=0, interval=6 (7.50 ms), latency=0, timeout=500 (5000 ms)
D/RxBle#ConnectionOperationQueue: QUEUED   (182608781)
D/RxBle#ConnectionOperationQueue: FINISHED (64106197) in 514 ms
D/RxBle#ConnectionOperationQueue: STARTED  (182608781)
I/RxBle#ConnectionOperationQueue: RUNNING  com.polidea.rxandroidble2.internal.connection.RxBleConnectionImpl$11@ae2638d
D/BluetoothGatt: discoverServices() - device: 54:6C:0E:A0:44:45
D/BluetoothGatt: onSearchComplete() = Device=54:6C:0E:A0:44:45 Status=0
I/RxBle#GattCallback: MAC='54:6C:0E:A0:44:45'     onServicesDiscovered(), status=0
D/First Services from custom refresh: services: [[00002a00-0000-1000-8000-00805f9b34fb, 00002a01-0000-1000-8000-00805f9b34fb, 00002a04-0000-1000-8000-00805f9b34fb], [00002a05-0000-1000-8000-00805f9b34fb], [00002a23-0000-1000-8000-00805f9b34fb, 00002a24-0000-1000-8000-00805f9b34fb, 00002a25-0000-1000-8000-00805f9b34fb, 00002a26-0000-1000-8000-00805f9b34fb, 00002a27-0000-1000-8000-00805f9b34fb, 00002a28-0000-1000-8000-00805f9b34fb, 00002a29-0000-1000-8000-00805f9b34fb, 00002a2a-0000-1000-8000-00805f9b34fb, 00002a50-0000-1000-8000-00805f9b34fb], [0000fef1-0000-1000-8000-00805f9b34fb, 0000fef2-0000-1000-8000-00805f9b34fb]]
D/RxBle#ConnectionOperationQueue: FINISHED (182608781) in 123 ms
D/BluetoothGatt: onConnectionUpdated() - Device=54:6C:0E:A0:44:45 interval=39 latency=0 timeout=500 status=0
I/RxBle#GattCallback: MAC='54:6C:0E:A0:44:45'      onConnectionUpdated(), status=0, interval=39 (48.75 ms), latency=0, timeout=500 (5000 ms)
D/First Services from RxAndroidBle: services: [[00002a00-0000-1000-8000-00805f9b34fb, 00002a01-0000-1000-8000-00805f9b34fb, 00002a04-0000-1000-8000-00805f9b34fb], [00002a05-0000-1000-8000-00805f9b34fb], [00002a23-0000-1000-8000-00805f9b34fb, 00002a24-0000-1000-8000-00805f9b34fb, 00002a25-0000-1000-8000-00805f9b34fb, 00002a26-0000-1000-8000-00805f9b34fb, 00002a27-0000-1000-8000-00805f9b34fb, 00002a28-0000-1000-8000-00805f9b34fb, 00002a29-0000-1000-8000-00805f9b34fb, 00002a2a-0000-1000-8000-00805f9b34fb, 00002a50-0000-1000-8000-00805f9b34fb], [0000fef1-0000-1000-8000-00805f9b34fb, 0000fef2-0000-1000-8000-00805f9b34fb]]
D/RxBle#ConnectionOperationQueue: QUEUED   CharacteristicReadOperation(252964743)
D/RxBle#ConnectionOperationQueue: STARTED  CharacteristicReadOperation(252964743)
I/RxBle#ConnectionOperationQueue: RUNNING  CharacteristicReadOperation{MAC='54:6C:0E:A0:44:45', characteristic=[uuid='0000fef2-0000-1000-8000-00805f9b34fb']}
D/BluetoothGatt: onConnectionUpdated() - Device=54:6C:0E:A0:44:45 interval=6 latency=0 timeout=500 status=0
I/RxBle#GattCallback: MAC='54:6C:0E:A0:44:45'      onConnectionUpdated(), status=0, interval=6 (7.50 ms), latency=0, timeout=500 (5000 ms)
I/RxBle#GattCallback: MAC='54:6C:0E:A0:44:45'     onCharacteristicRead(), status=0, value=[uuid='0000fef2-0000-1000-8000-00805f9b34fb', hexValue=[00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00]]
D/RxBle#ConnectionOperationQueue: FINISHED CharacteristicReadOperation(252964743) in 1420 ms
D/BluetoothGatt: onConnectionUpdated() - Device=54:6C:0E:A0:44:45 interval=39 latency=0 timeout=500 status=0
I/RxBle#GattCallback: MAC='54:6C:0E:A0:44:45'      onConnectionUpdated(), status=0, interval=39 (48.75 ms), latency=0, timeout=500 (5000 ms)
D/RxBle#ConnectionOperationQueue: QUEUED   CharacteristicWriteOperation(88688642)
D/RxBle#ConnectionOperationQueue: STARTED  CharacteristicWriteOperation(88688642)
I/RxBle#ConnectionOperationQueue: RUNNING  CharacteristicWriteOperation{MAC='54:6C:0E:A0:44:45', characteristic=[uuid='0000fef2-0000-1000-8000-00805f9b34fb', hexValue=[39, 33, 31, 61, 64, 61, 34, 37, 45, 30, 32, 41, 33, 42, 39, 44]]}
I/RxBle#GattCallback: MAC='54:6C:0E:A0:44:45'    onCharacteristicWrite(), status=0, value=[uuid='0000fef2-0000-1000-8000-00805f9b34fb']
D/RxBle#ConnectionOperationQueue: FINISHED CharacteristicWriteOperation(88688642) in 122 ms
D/RxBle#ConnectionOperationQueue: QUEUED   CharacteristicWriteOperation(195252079)
D/RxBle#ConnectionOperationQueue: STARTED  CharacteristicWriteOperation(195252079)
I/RxBle#ConnectionOperationQueue: RUNNING  CharacteristicWriteOperation{MAC='54:6C:0E:A0:44:45', characteristic=[uuid='0000fef1-0000-1000-8000-00805f9b34fb', hexValue=[01]]}
I/RxBle#GattCallback: MAC='54:6C:0E:A0:44:45'    onCharacteristicWrite(), status=0, value=[uuid='0000fef1-0000-1000-8000-00805f9b34fb']
D/RxBle#ConnectionOperationQueue: FINISHED CharacteristicWriteOperation(195252079) in 108 ms
D/RxBle#ConnectionOperationQueue: QUEUED   (43642150)
D/RxBle#ConnectionOperationQueue: STARTED  (43642150)
I/RxBle#ConnectionOperationQueue: RUNNING  com.polidea.rxandroidble2.internal.connection.RxBleConnectionImpl$11@299ed26
D/BluetoothGatt: refresh() - device: 54:6C:0E:A0:44:45
D/BluetoothGatt: onConnectionUpdated() - Device=54:6C:0E:A0:44:45 interval=6 latency=0 timeout=500 status=0
I/RxBle#GattCallback: MAC='54:6C:0E:A0:44:45'      onConnectionUpdated(), status=0, interval=6 (7.50 ms), latency=0, timeout=500 (5000 ms)
D/RxBle#ConnectionOperationQueue: QUEUED   (196294420)
D/RxBle#ConnectionOperationQueue: FINISHED (43642150) in 514 ms
D/RxBle#ConnectionOperationQueue: STARTED  (196294420)
I/RxBle#ConnectionOperationQueue: RUNNING  com.polidea.rxandroidble2.internal.connection.RxBleConnectionImpl$11@bb33714
D/BluetoothGatt: discoverServices() - device: 54:6C:0E:A0:44:45
D/BluetoothGatt: onSearchComplete() = Device=54:6C:0E:A0:44:45 Status=0
I/RxBle#GattCallback: MAC='54:6C:0E:A0:44:45'     onServicesDiscovered(), status=0
D/RxBle#ConnectionOperationQueue: FINISHED (196294420) in 346 ms
D/BluetoothGatt: onConnectionUpdated() - Device=54:6C:0E:A0:44:45 interval=39 latency=0 timeout=500 status=0
I/RxBle#GattCallback: MAC='54:6C:0E:A0:44:45'      onConnectionUpdated(), status=0, interval=39 (48.75 ms), latency=0, timeout=500 (5000 ms)
D/Second Services from custom refresh: services: [[00002a00-0000-1000-8000-00805f9b34fb, 00002a01-0000-1000-8000-00805f9b34fb, 00002a04-0000-1000-8000-00805f9b34fb], [00002a05-0000-1000-8000-00805f9b34fb], [00002a23-0000-1000-8000-00805f9b34fb, 00002a24-0000-1000-8000-00805f9b34fb, 00002a25-0000-1000-8000-00805f9b34fb, 00002a26-0000-1000-8000-00805f9b34fb, 00002a27-0000-1000-8000-00805f9b34fb, 00002a28-0000-1000-8000-00805f9b34fb, 00002a29-0000-1000-8000-00805f9b34fb, 00002a2a-0000-1000-8000-00805f9b34fb, 00002a50-0000-1000-8000-00805f9b34fb], [0000fef1-0000-1000-8000-00805f9b34fb, 0000fef2-0000-1000-8000-00805f9b34fb], [0000fee1-0000-1000-8000-00805f9b34fb, 0000fee2-0000-1000-8000-00805f9b34fb, 0000fee3-0000-1000-8000-00805f9b34fb, 0000fee4-0000-1000-8000-00805f9b34fb, 0000fee5-0000-1000-8000-00805f9b34fb, 0000fee6-0000-1000-8000-00805f9b34fb, 0000fee7-0000-1000-8000-00805f9b34fb, 0000fee8-0000-1000-8000-00805f9b34fb, 0000fee9-0000-1000-8000-00805f9b34fb]]
W/RxBle#IllegalOperationChecker: Characteristic 00002a00-0000-1000-8000-00805f9b34fb supports properties: [ WRITE_NO_RESPONSE WRITE ] (12) does not have any property matching [ READ ] (2)
D/RxBle#ConnectionOperationQueue: QUEUED   CharacteristicReadOperation(207059710)
D/RxBle#ConnectionOperationQueue: STARTED  CharacteristicReadOperation(207059710)
I/RxBle#ConnectionOperationQueue: RUNNING  CharacteristicReadOperation{MAC='54:6C:0E:A0:44:45', characteristic=[uuid='00002a00-0000-1000-8000-00805f9b34fb']}
D/RxBle#ConnectionOperationQueue: FINISHED CharacteristicReadOperation(207059710) in 17 ms
D/RxBle#ClientOperationQueue: QUEUED   DisconnectOperation(74863788)
I/RxBle#CancellableDisposable: Scan operation is requested to stop.
D/RxBle#ClientOperationQueue: STARTED  DisconnectOperation(74863788)
I/BluetoothAdapter: getBluetoothLeScanner
W/System.err: io.reactivex.exceptions.OnErrorNotImplementedException: The exception was not handled due to missing onError handler in the subscribe() method call. Further reading: https://github.com/ReactiveX/RxJava/wiki/Error-Handling | com.polidea.rxandroidble2.exceptions.BleGattCannotStartException: GATT exception from MAC address 54:6C:0E:A0:44:45, with type BleGattOperation{description='CHARACTERISTIC_READ'}
W/System.err:     at io.reactivex.internal.functions.Functions$OnErrorMissingConsumer.accept(Functions.java:704)
        at io.reactivex.internal.functions.Functions$OnErrorMissingConsumer.accept(Functions.java:701)
I/RxBle#ClientOperationQueue: RUNNING  DisconnectOperation{MAC='54:6C:0E:A0:44:45'}
W/System.err:     at io.reactivex.internal.observers.LambdaObserver.onError(LambdaObserver.java:77)
W/System.err:     at io.reactivex.observers.SerializedObserver.onError(SerializedObserver.java:153)
        at io.reactivex.internal.operators.observable.ObservableDelay$DelayObserver$OnError.run(ObservableDelay.java:128)
D/BluetoothAdapter: isLeEnabled(): ON
W/System.err:     at io.reactivex.internal.schedulers.ScheduledRunnable.run(ScheduledRunnable.java:66)
        at io.reactivex.internal.schedulers.ScheduledRunnable.call(ScheduledRunnable.java:57)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:301)
W/System.err:     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636)
        at java.lang.Thread.run(Thread.java:784)
    Caused by: com.polidea.rxandroidble2.exceptions.BleGattCannotStartException: GATT exception from MAC address 54:6C:0E:A0:44:45, with type BleGattOperation{description='CHARACTERISTIC_READ'}
W/System.err:     at com.polidea.rxandroidble2.internal.SingleResponseOperation.protectedRun(SingleResponseOperation.java:61)
        at com.polidea.rxandroidble2.internal.QueueOperation$1.subscribe(QueueOperation.java:41)
        at io.reactivex.internal.operators.observable.ObservableCreate.subscribeActual(ObservableCreate.java:40)
        at io.reactivex.Observable.subscribe(Observable.java:12284)
        at io.reactivex.internal.operators.observable.ObservableUnsubscribeOn.subscribeActual(ObservableUnsubscribeOn.java:32)
W/System.err:     at io.reactivex.Observable.subscribe(Observable.java:12284)
W/System.err:     at com.polidea.rxandroidble2.internal.serialization.FIFORunnableEntry$1.run(FIFORunnableEntry.java:56)
W/System.err:     at io.reactivex.internal.schedulers.ScheduledDirectTask.call(ScheduledDirectTask.java:38)
        at io.reactivex.internal.schedulers.ScheduledDirectTask.call(ScheduledDirectTask.java:26)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    	... 3 more
D/RxBle#ConnectionOperationQueue: Connection operations queue to be terminated (MAC='54:6C:0E:A0:44:45')
    com.polidea.rxandroidble2.exceptions.BleDisconnectedException: Disconnected from MAC='54:6C:0E:A0:44:45' with status -1 (UNKNOWN)
        at com.polidea.rxandroidble2.internal.serialization.ConnectionOperationQueueImpl.onConnectionUnsubscribed(ConnectionOperationQueueImpl.java:162)
        at com.polidea.rxandroidble2.internal.connection.ConnectorImpl$1$1.run(ConnectorImpl.java:65)
        at io.reactivex.internal.operators.observable.ObservableDoFinally$DoFinallyObserver.runFinally(ObservableDoFinally.java:142)
        at io.reactivex.internal.operators.observable.ObservableDoFinally$DoFinallyObserver.dispose(ObservableDoFinally.java:98)
        at io.reactivex.internal.disposables.DisposableHelper.dispose(DisposableHelper.java:124)
        at io.reactivex.internal.operators.observable.ObservableSubscribeOn$SubscribeOnObserver.dispose(ObservableSubscribeOn.java:73)
        at io.reactivex.internal.operators.observable.ObservableUnsubscribeOn$UnsubscribeObserver$DisposeTask.run(ObservableUnsubscribeOn.java:95)
        at io.reactivex.internal.schedulers.ScheduledDirectTask.call(ScheduledDirectTask.java:38)
        at io.reactivex.internal.schedulers.ScheduledDirectTask.call(ScheduledDirectTask.java:26)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:301)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636)
        at java.lang.Thread.run(Thread.java:784)
D/BluetoothManager: getConnectionState()
D/BluetoothManager: getConnectedDevices
D/BluetoothGatt: cancelOpen() - device: 54:6C:0E:A0:44:45
D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=9 device=54:6C:0E:A0:44:45
I/RxBle#GattCallback: MAC='54:6C:0E:A0:44:45'  onConnectionStateChange(), status=0, value=0
I/Process: Sending signal. PID: 12413 SIG: 9
Disconnected from the target VM, address: 'localhost:8620', transport: 'socket'

You can clearly see the new service "fee0" after it has been unlocked. However when trying to read using the connection I get an error. It happens at this line:

return@flatMapSingle data.second.readCharacteristic(services[0].characteristics[0].uuid)

Do you happen to have a CC2640 or CC2642 launchpad from Texas Instruments? If so I have an example application with this behaviour I can send over.

Dachmian · 2020-06-17T11:56:24Z

I managed to solve the issue by storing the characteristics discovered by the custom gatt refresh operation and use this for BLE interactions. Will use this as a workaround now.

Dachmian added the bug Bug that is caused by the library label May 26, 2020

Dachmian changed the title ~~Failed to read encrypted characteristic bonded device~~ Failed to read newly loaded characteristics after services changed Jun 3, 2020

Dachmian closed this as completed Jun 17, 2020

qq1023308356 mentioned this issue Aug 17, 2023

GenericFailure<CharacteristicValueUpdateError> #832

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Failed to read newly loaded characteristics after services changed #692

Failed to read newly loaded characteristics after services changed #692

Dachmian commented May 26, 2020 •

edited by dariuszseweryn

Loading

Dachmian commented May 26, 2020

dariuszseweryn commented May 26, 2020

Dachmian commented May 26, 2020 •

edited

Loading

Dachmian commented May 26, 2020

Dachmian commented Jun 3, 2020 •

edited

Loading

Dachmian commented Jun 17, 2020

Failed to read newly loaded characteristics after services changed #692

Failed to read newly loaded characteristics after services changed #692

Comments

Dachmian commented May 26, 2020 • edited by dariuszseweryn Loading

Dachmian commented May 26, 2020

dariuszseweryn commented May 26, 2020

Dachmian commented May 26, 2020 • edited Loading

Dachmian commented May 26, 2020

Dachmian commented Jun 3, 2020 • edited Loading

Dachmian commented Jun 17, 2020

Dachmian commented May 26, 2020 •

edited by dariuszseweryn

Loading

Dachmian commented May 26, 2020 •

edited

Loading

Dachmian commented Jun 3, 2020 •

edited

Loading