Code hangs when BLE client disconnects first

[billwirz]

• bleak version: 0.6.5a3 (develop)
• Python version: 3.7.3
• Operating System: Raspbian GNU/Linux 10 (buster), kernel: 4.19.118-v7+
• BlueZ version (bluetoothctl -v) in case of Linux: 5.50

Description

When connecting to a BLE device, if the client disconnects first, bleak seems to hang. This issue was fixed by modifying bluezdbus\client.py.

What I Did

I ran the notifications example "enable_notifications.py", connecting to a custom-built BLE device. This device was guaranteed to disconnect from the client before the 5 second asyncio.sleep had completed. I only modified it by commenting out the stop_notify line (no longer needed) and by adding a logging line after the BleakClient section, which never ran.

"""
Notifications
-------------
Example showing how to add notifications to a characteristic and handle the responses.
Updated on 2019-07-03 by hbldh <henrik.blidh@gmail.com>
""" 
async def run(address, loop, debug=False):
    if debug:
        import sys

        # loop.set_debug(True)
        l = logging.getLogger("asyncio")
        l.setLevel(logging.DEBUG)
        h = logging.StreamHandler(sys.stdout)
        h.setLevel(logging.DEBUG)
        l.addHandler(h)
        logger.addHandler(h)

    async with BleakClient(address, loop=loop) as client:
        x = await client.is_connected()
        logger.info("Connected: {0}".format(x))

        await client.start_notify(CHARACTERISTIC_UUID, notification_handler)
        await asyncio.sleep(5.0, loop=loop)
        #await client.stop_notify(CHARACTERISTIC_UUID)
    logger.info("BleakClient exited successfully")

In order to debug this problem, logger statements were added to bluezdbus\client.py, which made it clear that the code was hanging on BleakClient.disconnect when called by BleakClient.aexit, during the following section:

# Try to disconnect the actual device/peripheral
try:
	await self._bus.callRemote(
		self._device_path,
		"Disconnect",
		interface=defs.DEVICE_INTERFACE,
		destination=defs.BLUEZ_SERVICE,
	).asFuture(self.loop)
except Exception as e:
	logger.error("Attempt to disconnect device failed: {0}".format(e))

This was fixed by making the following changes to bluezdbus\client.py:

...
def __init__(self, address, loop=None, **kwargs):
   ...
        # BillMicro: device disconnection fix
        self._device_disconnected = False
...
async def disconnect(self) -> bool:
	"""Disconnect from the specified GATT server.

	Returns:
		Boolean representing if device is disconnected.

	"""
	# BillMicro: device disconnection fix
	if not self._device_disconnected:
		logger.debug("Disconnecting from BLE device...")

		# Remove all residual notifications.
		await self._cleanup_notifications()
                ...
        else:
            is_disconnected = True
...
def _properties_changed_callback(self, message):
	...
				task = self.loop.create_task(self._cleanup_all())
				# BillMicro: device disconnection fix
				self._device_disconnected = True
				...

However, this is a non-satisfactory solution. It can be be found here: 8794eac

[Ladvien]

I'm digging in on this one.

[billwirz]

Hi @Ladvien

Thanks for your suggestion - I agree that there must be a better way to fix this than what I did...

I tried using the ConnectionDone exception, as well as a number of others, but the code still hangs, and no exception is raised. I will keep trying to see if I can find a better solution or at least get a better handle on what's going on.

[Ladvien]

Hello @BillMicro,

Well, I've dug pretty deep. I'm not sure, but it seems like something is happening in the txdbus library and the deferred which is returned, then converted to an asyncio.future, is not completing or throwing an error. I got lost trying to trace it--new to all this, but I'll dig in a little more tomorrow.

[billwirz]

Hi @Ladvien

I'll take a look at that, as well as trying to understand the basics of how txdbus and twisted work. I found a version of bleak that doesn't do this - it's the latest proglove branch of the https://github.com/workaroundgmbh/bleak.git fork, so maybe I'll take a look at how that is different as well.

[Ladvien]

Oh nice! Thank you for sharing.

It looks like the Proglove folk are using bleak in testing or production. That's great. It's a huge project and would feel bad if Henrik had to maintain it on his own.

I took a look at their additions, they mention a "leaky event loop" on POSIX systems. I'm guessing that's what we were seeing. Glad there are smarter, more experienced people out there than me. :)

[hbldh]

This is troublesome indeed. An exception is desired, not a complete hanging...

This will be looked at in a later release though. Other issues have precendence right now.