Receiving ERR UNLIKELY when doing a Write With Response

Question

I have written an application in C using Bluez that implements a peripheral (a GATT server). I managed to advertise and make my peripheral work. Reading a characteristic works fine, notifying works fine and even a Write Without Reponse works. However, what doesn't work is the WRITE WITH RESPONSE. When I do that from an Android app (nrfConnect), I receive a ERR UNLIKELY (code 14). Looks like the 'response' that belongs to a write with response is not sent.

I thought I was doing the right thing by doing:

g_dbus_method_invocation_return_value(invocation, g_variant_new ("()"));

...but apparently it is not what Bluez is expecting. What should I do to make Bluez send the 'response' that belongs to a 'Write with response'?

Here is my code:

static void bluez_characteristic_method_call(GDBusConnection *conn,
                                             const gchar *sender,
                                             const gchar *path,
                                             const gchar *interface,
                                             const gchar *method,
                                             GVariant *params,
                                             GDBusMethodInvocation *invocation,
                                             void *userdata) {

    log_debug(TAG, "local characteristic method called: %s", method);
    LocalCharacteristic *characteristic = (LocalCharacteristic *) userdata;
    g_assert(characteristic != NULL);

    Application *application = characteristic->application;
    g_assert(application != NULL);

    if (g_str_equal(method, "ReadValue")) {
        g_assert(g_str_equal(g_variant_get_type_string(params), "(a{sv})"));

        GVariant *result = g_variant_new_fixed_array(G_VARIANT_TYPE_BYTE,
                                                     characteristic->value->data,
                                                     characteristic->value->len,
                                                     sizeof(guint8));
        g_dbus_method_invocation_return_value(invocation, g_variant_new_tuple(&result, 1));
        return;
    } else if (g_str_equal(method, "WriteValue")) {
        g_assert(g_str_equal(g_variant_get_type_string(params), "(aya{sv})"));
        GVariant *valueVariant, *optionsVariant;
        g_variant_get(params, "(@ay@a{sv})", &valueVariant, &optionsVariant);

 
        // Copy byte array and store it
        size_t data_length = 0;
        guint8 *data = (guint8 *) g_variant_get_fixed_array(valueVariant, &data_length, sizeof(guint8));
        GByteArray *byteArray = g_byte_array_sized_new(data_length);
        g_byte_array_append(byteArray, data, data_length);
        binc_characteristic_set_value(characteristic, byteArray);

        // Send properties changed signal with new value
        binc_application_notify(application, characteristic->service_uuid, characteristic->uuid, byteArray);

        // Send a response for a Write With Response
        g_dbus_method_invocation_return_value(invocation, g_variant_new ("()"));
    } else if...

    ....
 }

Answer 1

I'm actually running into the same problem but using python dasbus: https://github.com/rhinstaller/dasbus/issues/88. After staring at dbus-monitor, btmon, and other tools, I tried downgrading bluez from 5.62 to 5.50. I'm now getting write responses. I'll be doing a bisect shortly and opening an issue with bluez but I think you should try an older version of bluez.

EDIT: bisected. bluez 5.61 should be okay to use.

838c0dc7641e1c991c0f3027bf94bee4606012f8 is the first bad commit
commit 838c0dc7641e1c991c0f3027bf94bee4606012f8
Author: Bernie Conrad <bernie@allthenticate.net>
Date:   Tue Sep 28 16:00:15 2021 -0700

    gatt: Fix not cleaning up when disconnected

    There is a current use after free possible on a gatt server if a client
    disconnects while a WriteValue call is being processed with dbus.

    This patch includes the addition of a pending disconnect callback to handle
    cleanup better if a disconnect occurs during a write, an acquire write
    or read operation using bt_att_register_disconnect with the cb.

 src/gatt-database.c | 128 ++++++++++++++++++++++++++++++----------------------
 1 file changed, 74 insertions(+), 54 deletions(-)

Copy/paste of some of the debugging here:

btmon, bluez 5.62:

> ACL Data RX: Handle 64 flags 0x02 dlen 12                          #146 [hci0] 20:53:37.594026
      ATT: Write Request (0x12) len 7
        Handle: 0x01f0
          Data: 00014e2300
> HCI Event: Number of Completed Packets (0x13) plen 5               #147 [hci0] 20:53:37.594694
        Num handles: 1
        Handle: 64
        Count: 2
< ACL Data TX: Handle 64 flags 0x00 dlen 9                           #148 [hci0] 20:53:42.599869
      ATT: Error Response (0x01) len 4
        Write Request (0x12)
        Handle: 0x01f0
        Error: Unlikely Error (0x0e)

btmon, bluez 5.50:

> ACL Data RX: Handle 64 flags 0x02 dlen 12                              #190 [hci0] 10:37:38.043505
      ATT: Write Request (0x12) len 7
        Handle: 0x005c
          Data: 0003cb2400
< ACL Data TX: Handle 64 flags 0x00 dlen 5                               #191 [hci0] 10:37:38.044305
      ATT: Write Response (0x13) len 0

Code:

@dbus_interface("org.bluez.GattCharacteristic1")
class BLECharacteristicGatt(InterfaceTemplate):

    def ReadValue(self, options: Dict[Str, Variant]) -> List[Byte]:
        print(f"UUID {self.implementation._service._uuid} / {self.implementation._uuid} read value")
        return list(self.implementation.value)

    def WriteValue(self, value: List[Byte], options: Dict[Str, Variant]) -> None:
        try:
            print(f"UUID {self.implementation._service._uuid} / {self.implementation._uuid} write value")
            self.implementation.value = value
        except Exception as e:
            print(e)

    @property
    def UUID(self) -> Str:
        return self.implementation._uuid

    @property
    def Service(self) -> ObjPath:
        return self.implementation._service._path

    @property
    def Flags(self) -> List[Str]:
        return self.implementation._flags

bluetoothd debug, bluez 5.62:

Mar 09 07:39:38 redacted bluetoothd[4136041]: src/device.c:gatt_debug() (chan 0x555620d5a4e0) ATT PDU received: 0x12
Mar 09 07:39:38 redacted bluetoothd[4136041]: src/device.c:gatt_debug() Write Req - handle: 0x0022
Mar 09 07:39:43 redacted bluetoothd[4136041]: src/device.c:gatt_debug() Write Complete: err -110
Mar 09 07:39:43 redacted bluetoothd[4136041]: src/device.c:gatt_debug() (chan 0x555620d5a4e0) ATT PDU received: 0x12
Mar 09 07:39:43 redacted bluetoothd[4136041]: src/device.c:gatt_debug() Write Req - handle: 0x0025
Mar 09 07:39:48 redacted bluetoothd[4136041]: src/device.c:gatt_debug() Write Complete: err -110