search

hbldh / bleak

A cross platform Bluetooth Low Energy Client for Python using asyncio
MIT License
1.83k stars 302 forks source link

dbus-next backend: EOFError on connect should be encapsulated in BleakError #409

Open devbis opened 3 years ago

devbis commented 3 years ago

Description

On connecting sometimes it raises EOFError. I think it should be encapsulated in BleakError to be able catching a single BleakError instead of catching multiple os-dependent errors.

I don't think that EOF error relates to bleak itself. I suppose that it is the problem with bluetooth chip or my setup.

Traceback (most recent call last):
  File "/root/ble2mqtt/ble2mqtt/ble2mqtt.py", line 562, in _run_device_tasks
    t.result()
  File "/root/ble2mqtt/ble2mqtt/ble2mqtt.py", line 363, in manage_device
    disconnect_fut = await device.connect()
  File "/root/ble2mqtt/ble2mqtt/devices/base.py", line 167, in connect
    await self.client.connect()
  File "/usr/lib/python3.7/site-packages/bleak/backends/bluezdbus/client.py", line 307, in connect
    await self._cleanup_all()
  File "/usr/lib/python3.7/site-packages/bleak/backends/bluezdbus/client.py", line 381, in _cleanup_all
    await self._cleanup_notifications()
  File "/usr/lib/python3.7/site-packages/bleak/backends/bluezdbus/client.py", line 344, in _cleanup_notifications
    await remove_match(self._bus, rule)
  File "/usr/lib/python3.7/site-packages/dbus_next/aio/message_bus.py", line 305, in call
    await future
  File "/usr/lib/python3.7/site-packages/dbus_next/aio/message_bus.py", line 366, in _message_reader
    if self._unmarshaller.unmarshall():
  File "/usr/lib/python3.7/site-packages/dbus_next/_private/unmarshaller.py", line 304, in unmarshall
    self._unmarshall()
  File "/usr/lib/python3.7/site-packages/dbus_next/_private/unmarshaller.py", line 243, in _unmarshall
    self.read(16, prefetch=True)
  File "/usr/lib/python3.7/site-packages/dbus_next/_private/unmarshaller.py", line 91, in read
    raise EOFError()
EOFError
dlech commented 3 years ago

I have pushed a new commit to the dbus-next-2 branch that should improve the logging to see how we get here in the first place - or it may avoid the error altogether now since some things were rearranged.

devbis commented 3 years ago

Thank you, I'm going to test the changes.

devbis commented 3 years ago

Unforturnately, I still have to catch EOFError in my app while writing to gatt_char. Otherwise I get

Sat Jan 16 14:07:19 2021 daemon.err ble2mqtt[16745]: Traceback (most recent call last):
Sat Jan 16 14:07:19 2021 daemon.err ble2mqtt[16745]:   File "/usr/lib/python3.7/site-packages/ble2mqtt-0.1.0a11-py3.7.egg/ble2mqtt/protocols/redmond.py", line 154, in handle_queue
Sat Jan 16 14:07:19 2021 daemon.err ble2mqtt[16745]:     True,
Sat Jan 16 14:07:19 2021 daemon.err ble2mqtt[16745]:   File "/usr/lib/python3.7/site-packages/bleak-0.11.0a1-py3.7.egg/bleak/backends/bluezdbus/client.py", line 777, in write_gatt_char
Sat Jan 16 14:07:19 2021 daemon.err ble2mqtt[16745]:     {"type": Variant("s", "request" if response else "command")},
Sat Jan 16 14:07:19 2021 daemon.err ble2mqtt[16745]:   File "/usr/lib/python3.7/site-packages/dbus_next/aio/message_bus.py", line 305, in call
Sat Jan 16 14:07:19 2021 daemon.err ble2mqtt[16745]:     await future
Sat Jan 16 14:07:19 2021 daemon.err ble2mqtt[16745]:   File "/usr/lib/python3.7/site-packages/dbus_next/aio/message_bus.py", line 366, in _message_reader
Sat Jan 16 14:07:19 2021 daemon.err ble2mqtt[16745]:     if self._unmarshaller.unmarshall():
Sat Jan 16 14:07:19 2021 daemon.err ble2mqtt[16745]:   File "/usr/lib/python3.7/site-packages/dbus_next/_private/unmarshaller.py", line 304, in unmarshall
Sat Jan 16 14:07:19 2021 daemon.err ble2mqtt[16745]:     self._unmarshall()
Sat Jan 16 14:07:19 2021 daemon.err ble2mqtt[16745]:   File "/usr/lib/python3.7/site-packages/dbus_next/_private/unmarshaller.py", line 243, in _unmarshall
Sat Jan 16 14:07:19 2021 daemon.err ble2mqtt[16745]:     self.read(16, prefetch=True)
Sat Jan 16 14:07:19 2021 daemon.err ble2mqtt[16745]:   File "/usr/lib/python3.7/site-packages/dbus_next/_private/unmarshaller.py", line 91, in read
Sat Jan 16 14:07:19 2021 daemon.err ble2mqtt[16745]:     raise EOFError()
Sat Jan 16 14:07:19 2021 daemon.err ble2mqtt[16745]: EOFError
dlech commented 3 years ago

Can you enable debug logging so that we can see the sequence of events that lead up to this?

devbis commented 3 years ago

I'll try to do that. But I'm almost sure that it relates to the buggy Realtek driver for the Bluetooth chip. It restarts and raises errors randomly.

devbis commented 3 years ago

Here is a log of my application with enabled debug in bleak.

https://pastebin.com/eqqZ34B5

Let me know if I can get more info on the issue.

elupus commented 3 years ago

Had the same error just now on different use case. My connection is on a quite low signal connection. Where it has e tendency to loose the devices from time to time.

2021-07-16 21:03:25 WARNING (MainThread) [bleak.backends.bluezdbus.client] Failed to cancel connection (/org/bluez/hci0/dev_CC_F9_57_96_4B_7B): 'NoneType' object has no attribute 'call'
2021-07-16 21:03:25 ERROR (MainThread) [custom_components.fjaraskupan] Unexpected error fetching Fjäråskupan Updater data:
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 187, in _async_refresh
self.data = await self._async_update_data()
File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 147, in _async_update_data
return await self.update_method()
File "/config/custom_components/fjaraskupan/__init__.py", line 71, in async_update_data
await device.update()
File "/usr/local/lib/python3.9/site-packages/fjaraskupan/__init__.py", line 182, in update
async with self:
File "/usr/local/lib/python3.9/site-packages/fjaraskupan/__init__.py", line 130, in __aenter__
await self._client.__aenter__()
File "/usr/local/lib/python3.9/site-packages/bleak/backends/client.py", line 61, in __aenter__
await self.connect()
File "/usr/local/lib/python3.9/site-packages/bleak/backends/bluezdbus/client.py", line 287, in connect
reply = await asyncio.wait_for(
File "/usr/local/lib/python3.9/asyncio/tasks.py", line 481, in wait_for
return fut.result()
File "/usr/local/lib/python3.9/site-packages/dbus_next/aio/message_bus.py", line 305, in call
await future
File "/usr/local/lib/python3.9/site-packages/dbus_next/aio/message_bus.py", line 366, in _message_reader
if self._unmarshaller.unmarshall():
File "/usr/local/lib/python3.9/site-packages/dbus_next/_private/unmarshaller.py", line 304, in unmarshall
self._unmarshall()
File "/usr/local/lib/python3.9/site-packages/dbus_next/_private/unmarshaller.py", line 243, in _unmarshall
self.read(16, prefetch=True)
File "/usr/local/lib/python3.9/site-packages/dbus_next/_private/unmarshaller.py", line 91, in read
raise EOFError()
EOFError
elupus commented 3 years ago

For reference here is the client: https://github.com/elupus/fjaraskupan/blob/master/src/fjaraskupan/__init__.py And here is it's use in home assistant. https://github.com/home-assistant/core/pull/53140/files#diff-19e97ba9eb9accceecc6015ed5cc41554534c829d48bc74b7cb37331df4bcea9R71

stuartlynne commented 2 years ago

Seeing the same or very similar, this is Linux based app.

Traceback (most recent call last):
  File "/usr/lib/python3.8/multiprocessing/process.py", line 315, in _bootstrap
    self.run()
  File "/lvm1/home/sl/work/work22/trainer_dashboard/trainer_dashboard/ble/../ble/blemain.py", line 206, in run
    loop.run_until_complete(self.main(loop))
  File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
    return future.result()
  File "/lvm1/home/sl/work/work22/trainer_dashboard/trainer_dashboard/ble/../ble/blemain.py", line 413, in main
    self.process_tasks()
  File "/lvm1/home/sl/work/work22/trainer_dashboard/trainer_dashboard/ble/../ble/blemain.py", line 269, in process_tasks
    print('BLE.process_tasks: %s done results: %s' % (t.get_name(), t.result()), file=sys.stderr)
  File "/lvm1/home/sl/work/work22/trainer_dashboard/trainer_dashboard/ble/../ble/smo2.py", line 131, in run
    await self._run(device, service_uuids, data=data, optional=None, read=read, debug=debug)
  File "/lvm1/home/sl/work/work22/trainer_dashboard/trainer_dashboard/ble/../ble/bleclient.py", line 85, in _run
    value = await client.read_gatt_char(uuid)
  File "/usr/local/lib/python3.8/dist-packages/bleak/backends/bluezdbus/client.py", line 668, in read_gatt_char
    reply = await self._bus.call(
  File "/usr/local/lib/python3.8/dist-packages/dbus_next/aio/message_bus.py", line 305, in call 
    await future
  File "/usr/local/lib/python3.8/dist-packages/dbus_next/aio/message_bus.py", line 365, in _message_reader
    if self._unmarshaller.unmarshall():
  File "/usr/local/lib/python3.8/dist-packages/dbus_next/_private/unmarshaller.py", line 304, in unmarshall
    self._unmarshall()
  File "/usr/local/lib/python3.8/dist-packages/dbus_next/_private/unmarshaller.py", line 243, in _unmarshall
    self.read(16, prefetch=True)
  File "/usr/local/lib/python3.8/dist-packages/dbus_next/_private/unmarshaller.py", line 91, in read
    raise EOFError()
EOFError
dlech commented 2 years ago

@stuartlynne do you have a minimal reproducible test case?

Is it possible that the D-Bus server or BlueZ (bluetoothd) was restarted while your Python program was running?

stuartlynne commented 2 years ago

Unfortunately, I don't have a test case and it was not easily reproducible.

For now, I added a specific try: / except EOFError as e: when reading or writing.