No longer connecting to BLE device since bluez update

[vmedea]

Since the Bluez update i can no longer connect from my laptop's bulit-in bluetooth to a BLE-controlled lamp (which uses a USR IOT WH-BLE 102 module).

I have the following minimal reproduction test script:

import sys
import time

import gattlib

class _BLEConn(gattlib.GATTRequester):
    def __init__(self, macaddr):
        print('Opening connection')
        super().__init__(macaddr)
        self.connected = False

    def on_connect(self, mtu):
        print(f'Connected to device (mtu={mtu})')
        self.connected = True

    def on_connect_failed(self, code):
        print(f'Failed to connect to device (code={code})')

c = _BLEConn(sys.argv[1])
while not c.connected:
    time.sleep(1)

With commit 0fc58b149e0bb062bcf747d326a7a76e724023ea it connects to my device:

$ python3 test.py  ${NANLITE_MAC}
Opening connection
Connected to device (mtu=23)

However, with commit d38f82efac2a918e56f3f1232b07562214fb5ea4 (current HEAD) it hangs forever. on_connect is never called, nor is on_connect_failed:

$ python3 test.py  ${NANLITE_MAC}
Opening connection

I have also tried as root, but that didn't help.

I don't really know what information helps to debug this. This is the local bluetooth device:

Bus 001 Device 004: ID 04ca:300d Lite-On Technology Corp. Atheros AR3012 Bluetooth

Here's output from hcitool for the remote device:

$ sudo hcitool leinfo ${NANLITE_MAC}
Requesting information ...
        Handle: 32 (0x0020)
        LMP Version: 4.2 (0x8) LMP Subversion: 0x1312
        Manufacturer: ST Microelectronics (48)
        Features: 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00

gattool also works fine:

$ gatttool -I -b ${NANLITE_MAC}
[XX][LE]> connect
Attempting to connect to XX
Connection successful
[XX][LE]> primary
attr handle: 0x0001, end grp handle: 0x0004 uuid: 00001801-0000-1000-8000-00805f9b34fb
attr handle: 0x0005, end grp handle: 0x000b uuid: 00001800-0000-1000-8000-00805f9b34fb
attr handle: 0x000c, end grp handle: 0x0011 uuid: 0003cdd0-0000-1000-8000-00805f9b0131

[oscaracena]

Hi,

Thanks for your extensive report! The thing is that I have had similar problems with the latest release of bluez, and I decided to take another approach. I've started a new implementation of the library using D-Bus, which is very common these days. It is not finished, but it's already usable. If you wish, you can try it, just switch to the branch dbus and use it. As it is a pure Python implementation, you don't need to compile anything. It uses the module dasbus, so you need to install it (either using apt/yum/etc or with pip).

I tried to keep the compatibility as much as possible, but as they are very different in nature, I needed to deprecate some things, and add another ones. Feel free to comment whatever you see.

Thanks again for testing!

[vmedea]

Thanks for the info, I'll give it a try! Fairly sure I'll need to rework some things in my code. The main difference seems to be using UUIDs for writing instead of handles. Also, notifications for responses seem to be handled somewhat differently. And I'm not sure how the distinction between write_by_handle and write_cmd works now. But it's not a lot of code.

[oscaracena]

... And I'm not sure how the distinction between write_by_handle and write_cmd works now.

Yes, you are right. I've added another method, so now there are write_by_uuid and write_cmd_by_uuid, whether you need acknowledge or not.

I hope it will work for you.

[vmedea]

Thanks. It worked! All in all, it simplified my code, as it no longer has to look up the handles for UUIDs.

I do get this exception after connecting to the device:

Exception ignored in: <finalize object at 0x7f869b2d3720; dead>
Traceback (most recent call last):
  File "/usr/lib/python3.9/weakref.py", line 580, in __call__
    return info.func(*info.args, **(info.kwargs or {}))
KeyError: '5c100daf9e0e4017972b6ef2eaba14eb'

However after printing that, it continues without problems. The specific key is random on every start.

One thing that confused me a bit in the new API is that the notification callable gets two argument dictionaries, with the first one having one key Value and the other being empty. This seems to be due to dbus internals:

-    def on_notification(self, handle, data):
+    def on_notification(self, changed, invalid):
         '''
         Handle incoming subscribed data.
         '''
-        value = data[3:] # drop header
+        value = bytes(changed['Value'])

I think it would be more friendly to pass only the received data.

Edit: Some intermittent error:

  File "/.../gattlib/requester.py", line 99, in write_by_uuid
    return char.WriteValue(data, options({"type": "request"}))
  File "/.../dasbus/client/handler.py", line 450, in _call_method
    return self._get_method_reply(
  File "/.../dasbus/client/handler.py", line 483, in _get_method_reply
    return self._handle_method_error(error)
  File "/.../dasbus/client/handler.py", line 509, in _handle_method_error
    raise exception from None
dasbus.error.DBusError: Not connected

[oscaracena]

Good to know it almost works 😅 I need to review those exceptions... I think I can fix the first one, but I need to investigate the second a bit more, didn't see it before.

And you are right, I'll change it to pass only the value, much better.

I'm traveling just now, but as soon as I can, I'll review this.

Thanks again for your report!

[oscaracena]

Hi @vmedea!

I've fixed the first KeyError exception. It was produced by a double disconnection (the last one, on weakref's finalize).

I've also updated the interface for the notification callable. As you can be interested on other properties (not just the "value"), you can give it a filter (which is a list with the interested properties, being ["value"] by default). Then, when a notifications arrives, the engine will call your callback using the updated property as keyword args. Typically, you will define the callback as:

def on_notification(value):
    # do things with it

and just connect as this:

requester.enable_notifications(char_uuid, on_notification)

About the last edit, the "intermittent error", did it happen again?

[vmedea]

I've fixed the first KeyError exception. It was produced by a double disconnection (the last one, on weakref's finalize).

Awesome! Can confirm I haven't seen that problem anymore after pulling the new branch.

I've also updated the interface for the notification callable.

That makes sense, thanks.

About the last edit, the "intermittent error", did it happen again?

No, it's not currently happening anymore.

BTW, i've. had some problems with slow probing, and noticed only probing for LE devices can sometimes speed it up

diff --git a/gattlib/services.py b/gattlib/services.py
index 8629557109ece95147e9d22ae5094f9b66197b54..840f30c1a950426d19d6422d0ac16bb089afc479 100644
--- a/gattlib/services.py
+++ b/gattlib/services.py
@@ -8,7 +8,7 @@ from traceback import format_exc
 from typing import Optional, Dict, Callable

 from .dbus import BluezDBus, Signals
-from .utils import log, deprecated_args
+from .utils import log, deprecated_args, options


 Name = str
@@ -48,6 +48,7 @@ class DiscoveryService:
         self._devices = {}
         self._callback = callback
         self._obs_id = self._bluez.connect_signal(Signals.DEVICE_ADDED, self._on_new_device)
+        self._adapter.SetDiscoveryFilter(options({"Transport": "le"}))
         self._adapter.StartDiscovery()
         self._running = True
         self._log.info(" discover launched")

Edit: This isn't consistent, and with or without this, the discovery doesn't always return the same devices, it seems to depend on what bluez already knows? I'm kind of confused.

[vmedea]

Also I currently having another intermittent issue where it only detects services after a few seconds, but maybe i'm using it wrong, my code is

        logger.debug('Discovering devices')
        service = DiscoveryService(adapter)
        devices = service.discover(timeout=5)
        logger.debug(f'Devices found: {devices}')

        logger.debug('Opening connection')
        super().__init__(macaddr, auto_connect=True, adapter=adapter)

        self.connect_finished.wait()
        if not self.connect_status:
            raise Exception("Could not connect to device")

        import time # HACK
        time.sleep(5) # wait for interfaces to be added

        logger.debug('Discovering gatt services')
        services = self.discover_primary()
        chars = self.discover_characteristics(self.SERVICE)

Without the sleep it will often fail on discover_characteristics complaining about an unknown service id.

[oscaracena]

Hi!

No, it's not currently happening anymore.

Glad to hear it! 😃

Edit: This isn't consistent, and with or without this, the discovery doesn't always return the same devices, it seems to depend on what bluez already knows? I'm kind of confused.

Yes, I'm having the same issues when trying to discover devices. I'm not sure why bluez take so much in this process, its frustrating...

Without the sleep it will often fail on discover_characteristics complaining about an unknown service id.

I think that there is a property in the D-Bus object on which you can listen for changes that notifies you when the service list is available. I've not used it myself, but it is in the API. It may help you in this specific case.