bluez WriteValue: returning expected None leads to timeout and Unlikely Error 0x0E/14

[roysjosh]

I'm writing a little bluez app using dasbus. Reading values works great. Writing values half works: I get the write but the client never gets the GATT Write Response. This leads to an error exactly like https://github.com/nettlep/gobbledegook/issues/12

> 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)

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

Thoughts?

[roysjosh]

Hmm but dbus-monitor --system shows a method return... Then why isn't btmon showing a write response?

method call time=1646798754.328918 sender=:1.9633 -> destination=:1.9684 serial=2832 path=/redacted/service/2/characteristic/2; interface=org.bluez.GattCharacteristic1; member=WriteValue
   array of bytes [
      00 01 bb 22 00
   ]
   array [
      dict entry(
         string "device"
         variant             object path "/org/bluez/hci0/dev_55_78_61_1D_1F_01"
      )
      dict entry(
         string "link"
         variant             string "LE"
      )
      dict entry(
         string "mtu"
         variant             uint16 185
      )
   ]
method return time=1646798754.329427 sender=:1.9684 -> destination=:1.9633 serial=23 reply_serial=2832

[poncovka]

Hi, if the app seems to work (based on the dbus-monitor output), couldn't the issue be on the client side?

[roysjosh]

It could be, certainly. Currently I'm testing with both a proprietary iOS app and nRFConnect on Android. Both get the same failure. Here is bluetoothd's debug...

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

[poncovka]

My very wild guess is that the -110 error code is actually ETIMEDOUT, which means that the connection timed out. It is kind of based on this function, but I might be completely wrong. Anyway, it seems more and more unlikely that this is caused by dasbus.

[roysjosh]

I agree. It looks like the 5s timeout comes from https://github.com/bluez/bluez/blob/57d33535d56cf9e36e93e226ba7b6b7d5334ab1f/src/shared/gatt-db.c#L2071 (and lines 2024/2032). I'm going to poke around bluez, see if I can find an older version that works. Thanks!