Android-BLE-Library: Disable notifications ACK not received, trying to enable notifications throws Status -3

One of the operations I perform often is an atomic enable/disable notifications and write characteristic

        Timber.d("$rawDataOn pre")
beginAtomicRequestQueue()
            .add(klEnableNotificationsRequest(sensorsRawDataCharacteristic, rawDataOn)) //enables/disables notifications
            .add(writeCharacteristic(sensorsStreamingControlCharacteristic, payload))
            .before {
                Timber.d("$rawDataOn before")
            }
            .done {
                Timber.d("$rawDataOn Completed")
            }
            .enqueue()

A standard execution when passing “false” logs something like this

12:13:20.565 false pre
12:13:20.565 false before
12:13:20.566 gatt.setCharacteristicNotification(01000001-55d0-4989-b640-cfb64e5c34e0, false)
12:13:20.566 setCharacteristicNotification() - uuid: 01000001-55d0-4989-b640-cfb64e5c34e0 enable: false
12:13:20.567 Disabling notifications and indications for 01000001-55d0-4989-b640-cfb64e5c34e0
12:13:20.568 gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x00-00)
12:13:20.575 Data written to descr. 00002902-0000-1000-8000-00805f9b34fb, value: (0x) 00-00
12:13:20.575 Notifications and indications disabled
12:13:20.576 Writing characteristic 04000001-55d0-4989-b640-cfb64e5c34e0 (WRITE REQUEST)
12:13:20.576 gatt.writeCharacteristic(04000001-55d0-4989-b640-cfb64e5c34e0)
12:13:20.577 false Completed

Some times, if there are consecutive calls with enable set to false and then true, it tries to enable notifications before the disable is complete. Apparently, the “disable notifications” request never confirms that the notifications are disabled but still completes

12:13:19.467 false pre
12:13:19.495 true pre
12:13:20.485 false before
12:13:20.486 gatt.setCharacteristicNotification(01000001-55d0-4989-b640-cfb64e5c34e0, false)
12:13:20.486 setCharacteristicNotification() - uuid: 01000001-55d0-4989-b640-cfb64e5c34e0 enable: false
12:13:20.489 Disabling notifications and indications for 01000001-55d0-4989-b640-cfb64e5c34e0
12:13:20.490 gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x00-00)
12:13:20.504 Writing characteristic 04000001-55d0-4989-b640-cfb64e5c34e0 (WRITE REQUEST)
12:13:20.505 gatt.writeCharacteristic(04000001-55d0-4989-b640-cfb64e5c34e0)
12:13:20.507 false Completed
12:13:20.508 true before
12:13:20.510 klEnableNotificationsRequest setNotificationCallback
12:13:20.511 gatt.setCharacteristicNotification(01000001-55d0-4989-b640-cfb64e5c34e0, true)
12:13:20.511 setCharacteristicNotification() - uuid: 01000001-55d0-4989-b640-cfb64e5c34e0 enable: true
12:13:20.514 Enabling notifications for 01000001-55d0-4989-b640-cfb64e5c34e0
12:13:20.514 gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x01-00)
-> error -3 12:13:20.516 Failed to enabled notifications for 01000001-55d0-4989-b640-cfb64e5c34e0 (status = -3)
12:13:20.517 Writing characteristic 04000001-55d0-4989-b640-cfb64e5c34e0 (WRITE REQUEST)
12:13:20.518 gatt.writeCharacteristic(04000001-55d0-4989-b640-cfb64e5c34e0)
12:13:20.519 true Completed

If you compare it with the previous log, it’s missing the “disable notifications” ACK

12:13:20.575 Data written to descr. 00002902-0000-1000-8000-00805f9b34fb, value: (0x) 00-00
12:13:20.575 Notifications and indications disabled

Does it sound like a bug in the library?

We develop our own firmware so there might as well be a bug there, but I don’t have a sniffer to check the packets.

About this issue

Original URL
State: closed
Created 6 years ago
Comments: 40 (20 by maintainers)

Commits related to this issue

#48 fixed — committed to NordicSemiconductor/Android-BLE-Library by philips77 6 years ago
#48 fixed again — committed to NordicSemiconductor/Android-BLE-Library by philips77 6 years ago

Most upvoted comments

Hi @philips77, thanks for your quick reply.

Here is the issue: #60

vicobz on Dec 12, 2018

That seems to fix the issues, thank you so much!!

ghost on Nov 30, 2018

The notification flood was on a different characteristic. Does it still affect the WaitForValueChangedRequest?

It can happen that the characteristic emits a notification change that’s not a direct answer to our command. For example, if the user presses a button and the device starts vibrating, the “is vibrating” sensor will emit a notification changed on the same characteristic we are trying to write on. Will that cause issues?

In our case, the response’s first byte matches the command we sent. I don’t know if it’d be possible to pass some kind of filter to WaitForValueChangedRequest, but I guess that belongs in a separate feature request.

Failure log, where we can see that the notification received was indeed a response to the command we sent

07:37:45.703 15611-15803/ D/KLNordicBleManager: writeAndNotifyOperation command id 0x44
07:37:45.733 15611-15611/ I/: Notification received from 02000004-..., value: (0x) 44-...
07:37:45.736 15611-15611/ I/: Data written to 02000004-..., value: (0x) 44-...

ghost on Nov 30, 2018

I think I’ve identified WaitForValueChangedRequest as the source of issues

This works perfectly fine and never returns status = -3

writeCharacteristic(deviceParametersCharacteristic, payload)
                .fail { _, status ->
                    Timber.e("writeCharacteristic sensors failed with status %s",status)
                }
                .enqueue()

This returns status = -3 quite often, both using enqueue() and awaitValid(response)

waitForNotification(deviceParametersCharacteristic!!)
                .trigger(writeCharacteristic(deviceParametersCharacteristic, payload)
                    .fail { _, status ->
                      Timber.e("writeCharacteristic sensors failed with status %s",status)
                    }
                )
                .timeout(OPERATION_TIMEOUT_MS)
                .enqueue()

Sorry to spam the thread, but this is biting us and we need to fix it 😢

ghost on Nov 29, 2018