NordicSemiconductor / Android-BLE-Library

A library that makes working with Bluetooth LE on Android a pleasure. Seriously.
BSD 3-Clause "New" or "Revised" License
1.99k stars 414 forks source link

Sometimes, App does not receive callback of setIndicationCallback #485

Closed doanpt closed 10 months ago

doanpt commented 1 year ago

Hi, My app use your lib to setIndicationCallback, but sometime, after wrote command. my app does not receive callback from setIndicationCallback

I look into log and see there are difference below:

In passed case. the log as below:

03-22 16:19:48.210 27720 27720 D BleInterface: UL0E99: runConnectedOperation 'requestChallenge'... disconnect: false... isOpenSecureOperation: false
03-22 16:19:48.212 27720 27720 D BleInterface: BLE Lock UL0E99 is not busy and connected and isRequireSecureChannel:null gattValidationResult=LockServices 
03-22 16:19:48.213 27720 27720 D BleInterface: gatt.setCharacteristicNotification(xxxxxxxx-766c-42c4-8944-42bc98fc2d09, true)
03-22 16:19:48.215 27720 27720 D BleInterface: Enabling indications for xxxxxxxx-766c-42c4-8944-42bc98fc2d09
03-22 16:19:48.215 27720 27720 D BleInterface: gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x02-00)
03-22 16:19:48.300 27720 27720 D BleInterface: **Data written to descr. 00002902-0000-1000-8000-00805f9b34fb, value: (0x) 02-00** 
03-22 16:19:48.301 27720 27720 D BleInterface: **Indications enabled** 
03-22 16:19:48.423 27720 27720 D BleInterface: Writing characteristic xxxxxxxx-766c-42c4-8944-42bc98fc2d09 (WRITE REQUEST) 
03-22 16:19:48.423 27720 27720 D BleInterface: gatt.writeCharacteristic(xxxxxxxx-766c-42c4-8944-42bc98fc2d09) 
03-22 16:19:48.495 27720 27720 D BleInterface: Data written to xxxxxxxx-766c-42c4-8944-42bc98fc2d09, value: (0x) 61-00 
03-22 16:19:48.499 27720 27720 D BleInterface: **Indication received** from xxxxxxxx-766c-42c4-8944-42bc98fc2d09, value: (0x) 01-20-5E-C5-E0-BF-B4-09-09-DF-E5-02-AE-D7-A1-E7-47-6F-1C-D6-FF-C4-36-C5-CC-23-54-7A-41-19-EA-72-C4-A4
03-22 16:19:48.500 27720 27720 D BleInterface: **setIndicationCallback receive callback data**
03-22 16:19:48.504 27720 27720 D BleInterface: UL0E99 requestChallenge succeeded

In failed case, log look like:

03-24 14:21:26.629 5569 5569 D BleInterface: UL9096: runConnectedOperation 'requestChallenge'... disconnect: false... isOpenSecureOperation: false
03-24 14:21:29.481 5569 5569 D BleInterface: gatt.setCharacteristicNotification(4d050051-766c-42c4-8944-42bc98fc2d09, true) 
03-24 14:21:29.483 5569 5569 D BleInterface: Enabling indications for 4d050051-766c-42c4-8944-42bc98fc2d09
03-24 14:21:29.483 5569 5569 D BleInterface: gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x02-00) 
03-24 14:21:29.510 5569 5569 D BleInterface: **Data written to descr. 00002902-0000-1000-8000-00805f9b34fb**
03-24 14:21:29.630 5569 5569 D BleInterface: Writing characteristic 4d050027-766c-42c4-8944-42bc98fc2d09 (WRITE REQUEST) 
03-24 14:21:29.630 5569 5569 D BleInterface: gatt.writeCharacteristic(4d050027-766c-42c4-8944-42bc98fc2d09, value=0x6100, WRITE REQUEST) 
03-24 14:21:29.660 5569 5569 D BleInterface: Data written to 4d050027-766c-42c4-8944-42bc98fxd09
03-24 14:21:29.660 5569 5569 D BleInterface: **Notification received** from xxxxxxxx-766c-42c4-8944-42bc98fc2d09, value: (0x) 01-20-DD-86-5F-5A-C1-6F-CD-35-78-32-FF-58-EC-07-F4-11-CD-4D-56-3A-79-56-2B-23-49-65-28-90-50-34-19-2E

After see "Notification received" log that print from your lib. my app does not receive callback then app stuck in loading screen. could you please help me check and let me know why same code but different log.

doanpt commented 1 year ago

Update: As I check, with passed log, my app using ble-ktx:2.5.1 and failed log, my app using ver: ble-ktx:2.6.0. My app still passed almost times with 2.6.0, but some time, app does not receive callback after see below log:

03-24 14:21:29.660 5569 5569 D BleInterface: Notification received from xxxxxxxx-766c-42c4-8944-42bc98fc2d09, value: (0x) 01-20-DD-86-5F-5A-C1-6F-CD-35-78-32-FF-58-EC-07-F4-11-CD-4D-56-3A-79-56-2B-23-49-65-28-90-50-34-19-2E
philips77 commented 1 year ago

Hello, Sorry for very long delay. Could your relevant paste your code here? For example the initialize() method where you enable indications and set indication callback and trigger the indication.

Btw, for one-time indications, like in case of a Control Point characteristic with indications, you may consider using;

waitForIndication(characteristic)
   .trigger(writeCharacteristic(characteristic, requestData, type))
   .with { device, data ->
      // handle indication
   }
   .timeout(10_000)
   .enqueue()

It will:

  1. assign a one-time listener for the indication,
  2. send the requestData with type type
  3. await the indication for at most 10 seconds
doanpt commented 1 year ago

hello, thanks so much for your reply, I think your solution waitForIndication very helpful, I will try your solution.

for analysis this issue: Here is my exam code for setIndicationCallback and enableIndication

 suspend fun requestAction(): Result<ActionResult, BleError> =
        runConnectedOperation(false, "requestAction") { services ->
            runSuspendContinuation(scope) { continuation ->
                setIndicationCallback(services.authCharacteristic.gattCharacteristic).with { _, data ->
                    continuation.resume(Ok(ActionResult.parse(data.value)))
                }
                enableIndications(
                    services.authCharacteristic.gattCharacteristic,
                    CommandAction.bytes,
                )
            }
        }

suspend fun enableIndications(
        characteristic: BluetoothGattCharacteristic,
        bytes: ByteArray
    ) {
        var enableState = ENABLE_INDICATION_IDLE
        enableIndications(characteristic)
            .done {
               Timber.d("enableIndications done: $it")
               enableState = ENABLE_INDICATION_DONE
            }
            .fail { e, status ->
               Timber.e("enableIndications fail: $status - $e")
               enableState = ENABLE_INDICATION_FAIL
            }
            .enqueue()
        while (enableState == ENABLE_INDICATION_IDLE) {
            Timber.d("enableIndications waiting")
            delay(ENABLE_INDICATION_WAITING_TIME)
        }
        if (enableState == ENABLE_INDICATION_DONE) {
            Timber.d("enableIndications writing")
            delay(100L)
            writeBleCharacteristic(characteristic, bytes)
        }
    }

As you said and I read the comment of waitForIndication method, It's one-time callback and helpful in waiting setIndicationCallback done before the trigger command wrote. But in my app, I have some scenarios where the Indication callback will be called multiple times. I think the issue in my case is the trigger command written before the set indication callback is done. so I can't receive the data callback., so do you have any suggestion for my situation, I need a method that waits for setIndicationCallback (that receives multi-callback) success before writing a trigger command,

philips77 commented 1 year ago

I need a method that waits for setIndicationCallback (that receives multi-callback) success before writing a trigger command,

If the data you get is split into multiple indications but all are sent one after each other, you may use .merge(DataMerger). The DataMerger object can combine received data into a single packet and return whether to continue collecting or return. waitForIndication will wait until the merger decides that all data are ready.

philips77 commented 1 year ago

Also, you may look into ble-ktx module, which has Kotlin extensions for suspended functions. E.g. you may call:

enableIndications(characteristic).suspend()

which either returns, or throws an exception. There are also variations of suspend() method for handling incoming data.

doanpt commented 1 year ago

hi @philips77 thanks your suggestion, the suspend worked for me for wait to enable notification. but .merge(dataMerger) not work for me. Bellow is old code with setIndicationCallback, it received multi indication callback, and it will parse the data of each indication callback one by one until all the conditions are true.

    override suspend fun readCert(allowNoSigner: Boolean): Result<ParserCertificate, Error> =
        runConnectedOperation(false, "requestCert") { services ->
            runSuspendContinuation(scope) { continuation ->
                val cert = ParserCertificate()
                setIndicationCallback(services.authenCharacteristic).with { _, data ->
                    data.value?.toList()?.let { cert.parse(it) }
                    if (cert.certDone && ((allowNoSigner && !cert.signerStarted) || cert.signerDone)) {
                        removeIndicationCallback(services.authenCharacteristic)
                        continuation.resume(Ok(cert))
                    }
                }
                delay(200L)
                write(
                    services,
                    services.writeCharacteristic,
                    Commands.bytes
                )
            }
        }

I tried to apply Data merger by your suggestion as below:

    class CertMerger(private val cert: ParserCertificate, private val allowNoSigner: Boolean) : DataMerger {
        override fun merge(output: DataStream, lastPacket: ByteArray?, index: Int): Boolean {
            lastPacket?.toList()?.let { cert.parse(it) }
            return if (cert.certDone && ((allowNoSigner && !cert.signerStarted) || cert.signerDone)) {
                true
            } else {
                false
            }
        }
    }

    override suspend fun readCert(allowNoSigner: Boolean): Result<ParserCertificate, Error> =
        runConnectedOperation(false, "requestCert") { services ->
            runSuspendContinuation(scope) { continuation ->
                val cert = ParserCertificate()
                waitForIndication(services.authenCharacteristic)
                    .trigger(
                        buildWriteRequest(
                            services,
                            services.writeCharacteristic,
                            Commands.bytes
                        )
                    )
                    .merge(CertMerger(cert, allowNoSigner))
                    .with { _, _ ->
                        Timber.d("readCert final data")
                        continuation.resume(Ok(cert))
                    }
                    .fail { device, status ->
                        Timber.d("readCert fail ${device.name} - ${device.address}: $status")
                        continuation.resume(Err(err))
                    }
                    .timeout(20000L)
                    .enqueue()
            }
        }

With data merger, I only receive the first data package then the device is disconnected as below log:

04-16 10:51:37.081 19660 19660 D BleInterface: WingDevice: runConnectedOperation 'requestCert'... disconnect: false... isOpenSecureOperation: false
04-16 10:51:37.092 19660 19660 D NordicBLE: Waiting for value change...
04-16 10:51:37.093 19660 19660 D NordicBLE: Writing characteristic xxxxxxxx-766c-42c4-8944-42bc98fc2d09 (WRITE REQUEST)
04-16 10:51:37.093 19660 19660 D NordicBLE: gatt.writeCharacteristic(xxxxxxxx-766c-42c4-8944-42bc98fc2d09, value=0x6000, WRITE REQUEST)
04-16 10:51:37.164 19660 19660 D NordicBLE: Notification received from yyyyyyyy-766c-42c4-8944-42bc98fc2d09, value: (0x) 03-01-FC
04-16 10:51:37.170 19660 19660 D NordicBLE: Data written to xxxxxxxx-766c-42c4-8944-42bc98fc2d09
04-16 10:51:37.244 19660 19660 D NordicBLE: [Callback] Connection state changed with status: 0 and new state: 0 (DISCONNECTED)
04-16 10:51:37.245 19660 19660 D NordicBLE: Connection lost
04-16 10:51:37.258 19660 19660 D BleInterface$getGattCallback: onServicesInvalidated() 'WingDevice'
04-16 10:51:37.263 19660 19660 D BleInterface$getGattCallback: onDeviceDisconnected() 'WingDevice'
04-16 10:51:37.281 19660 19660 D NordicBLE: gatt.close()

Could you please look at my code and point out any wrong that led me only receive one indication callback instead of multiple callback?

philips77 commented 11 months ago

Hello, Sorry for very late response. Did you manage to solve your issue?

doanpt commented 10 months ago

hi @philips77 waitForIndications and DataMerger are now working fine, missing indication was fixed by our firmware team