search

hbldh / bleak

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

Bleak can't connect on ubuntu #94

Closed corentinbettiol closed 4 years ago

corentinbettiol commented 5 years ago

Description

Bleak randomly throw an exception during any connexion attempt on linux (almost every time):

me@my-computer~$ python3 test.py

Traceback (most recent call last):
  File "/home/me/.local/lib/python3.7/site-packages/bleak/backends/bluezdbus/client.py", line 98, in connect
    ).asFuture(self.loop)
txdbus.error.RemoteError: org.bluez.Error.Failed: Software caused connection abort

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "test.py", line 25, in <module>
    loop.run_until_complete(run(address, loop, True))
  File "/usr/lib/python3.7/asyncio/base_events.py", line 584, in run_until_complete
    return future.result()
  File "test.py", line 18, in run
    async with BleakClient(address, loop=loop) as client:
  File "/home/me/.local/lib/python3.7/site-packages/bleak/backends/client.py", line 41, in __aenter__
    await self.connect()
  File "/home/me/.local/lib/python3.7/site-packages/bleak/backends/bluezdbus/client.py", line 100, in connect
    raise BleakError(str(e))
bleak.exc.BleakError: org.bluez.Error.Failed: Software caused connection abort

What I Did

Pasted this program in a file named test.py and then launched it.

import asyncio
from bleak import BleakClient

async def run(address, loop, debug=False):
    async with BleakClient(address, loop=loop) as client:
        x = await client.is_connected()
        print("Connected: {0}".format(x))

if __name__ == "__main__":
    address = "F8:F0:05:F4:C5:B4"
    loop = asyncio.get_event_loop()
    loop.run_until_complete(run(address, loop))

But discover() works well though.

What I'm doing

I created a small benchmark, who launch X times this program and display success/total attempts :

import asyncio, bleak

async def run(address, loop, debug=False):
    try:
        async with bleak.BleakClient(address, loop=loop) as client:
            x = await client.is_connected(timeout=5)
            print(" V", end="", flush=True)
            return True
    except Exception as e:
        print(" X", end="", flush=True)
        return False

if __name__ == "__main__":
    success = 0
    address = "MAC ADDR"

    for i in range(0, 10000):
        loop = asyncio.get_event_loop()
        if loop.run_until_complete(run(address, loop)):
            success += 1
        print("\033[K\r" + str(success) + "/" + str(i + 1), sep=" ", end="", flush=True)
        # \033[K erase the line & \r return to the first char of the line

Current status: image

JoeHut commented 5 years ago

I am running into those again from time to time... To me it looks like a Bluez issue however. Can you check the output in the journal?

$ journalctl -f | grep bluetooth

And can you try whether it works after you did a manual reset of the adapter?

$ bluetoothctl
gent registered
[bluetooth]# power off
Changing power off succeeded
[bluetooth]# power on
[CHG] Controller A0:88:69:F9:DD:90 Class: 0x0000010c
Changing power on succeeded
[CHG] Controller A0:88:69:F9:DD:90 Powered: yes
[bluetooth]#

What version of Bluez are you running?

corentinbettiol commented 5 years ago

On every computer with Xubuntu/Lubuntu 18.04+ there is no BLE device found using only bluetoothctl or Bleak.

(edit: not "on every computer" but "on my computer with the BLE firmware bug with xubuntu as the main OS and lubuntu in a VM")

I find devices only by running hcitool lescan just before executing discovery or connect functions.

With just Bleak: 

[CHG] Controller mac Discovering: yes
[default timeout of Bleak discover()]
[CHG] Controller mac Discovering: no

With hcitool lescan executed on another terminal & Bleak:

[NEW] Device mac name
[NEW] Device mac name
[NEW] Device mac name
[NEW] Device mac name
[NEW] Device mac name
[NEW] Device mac name
[NEW] Device mac name
[NEW] Device mac name
[NEW] Device mac name
[CHG] Device mac RSSI: -86
[CHG] Device mac RSSI: -79
[NEW] Device mac name
[CHG] Device mac RSSI: -69
[CHG] Device mac RSSI: -86
[NEW] Device mac name
[CHG] Device mac RSSI: -70
[NEW] Device mac name
[CHG] Device mac RSSI: -85
[CHG] Device mac RSSI: -78
[CHG] Device mac RSSI: -70
[NEW] Device mac name
[CHG] Device mac RSSI: -72
[NEW] Device mac name
[CHG] Device mac RSSI: -81
[CHG] Device mac RSSI: -70
[NEW] Device mac name
[CHG] Device mac RSSI: -70
[NEW] Device mac name
[NEW] Device mac name
[NEW] Device mac name
[NEW] Device mac name
[NEW] Device mac name
[NEW] Device mac name
[CHG] Device mac RSSI: -59
[CHG] Device mac RSSI: -88
[NEW] Device mac name
[NEW] Device mac name
...

I had bluez 5.48.

Updated to 5.50, and then magic started to spread everywhere:

me@computer$ bluetoothctl -v
bluetoothctl: 5.50
me@computer$ bluetoothctl   
Agent registered
[bluetooth]# scan on
Discovery started
[CHG] Controller mac Discovering: yes
[NEW] Device mac name
[CHG] Device mac RSSI: -83
[NEW] Device mac name
[NEW] Device mac name
[CHG] Device mac RSSI: -62
[CHG] Device mac UUIDs: id

No more hcitool lescan !

But there is in fact one new line every 30 seconds, and when I try to use it with Bleak (with a 50 sec timeout), I got nothing. And when I re-started manual scanning, I got some results less than 15 seconds after:

image

edit: Searched some time in the bluetooth mailing list archive, and found a mention of a bug, where btmon shows lots of BLE devices during scanning, and [bluetoothctl]# scan on barely list some values.

Extract of their message:

At Endless we are working on enabling a machine with a Qualcomm Atheros QCA9377 adapter, and are experiencing problems when scanning for BLE devices.

My adapter:

my@computer$ lspci -knn | grep Net -A2; lsusb
03:00.0 Network controller [0280]: Qualcomm Atheros QCA9377 802.11ac Wireless Network Adapter [168c:0042] (rev 31)
    Subsystem: AzureWave QCA9377 802.11ac Wireless Network Adapter [1a3b:2b31]
    Kernel driver in use: ath10k_pci
    Kernel modules: ath10k_pci
[some other things]

So if I understand their email well; there is an firmware bug in the bluetooth controller that made it return results only when using direct messaging (like hcitool lescan is doing) instead of using DBUS api like bluetoothctl ?

hbldh commented 5 years ago

It seems to be an error coming from BlueZ, reported through txdbus (the lib bleak uses to to do DBus communication) and it is then reported as an error by bleak, which cannot proceed without the results. As such, it is not an bug in bleak directly.

@corentinbettiol This is a tall order, I know, but are you in possession of some computer with another Bluetooth chip on which you can try to install the same Xubuntu/Lubuntu version and see if the error exists there as well? Or even if you have a USB bluetooth adapter and specify the use of that one instead? I am right now unable to devote any time to bleak, so I cannot help you further right now, but it is of interest to now if this error is in Bluez 5.50 or, as your research implies, in the adapter itself.

corentinbettiol commented 5 years ago

I'm on my personal computer right now (xubuntu 18.04 too), I have BlueZ 5.48 and here's my adapter:

me@home$ lspci -knn | grep Net -A2; lsusb
02:00.0 Network controller [0280]: Intel Corporation Dual Band Wireless-AC 3168NGW [Stone Peak] [8086:24fb] (rev 10)
    Subsystem: Intel Corporation Device [8086:2110]
    Kernel driver in use: iwlwifi
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 003: ID 1770:ff00  
Bus 001 Device 002: ID 1532:0037 Razer USA, Ltd 
Bus 001 Device 005: ID 0bda:0129 Realtek Semiconductor Corp. RTS5129 Card Reader Controller
Bus 001 Device 004: ID 8087:0aa7 Intel Corp. 
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

I'm able to discover some bluetooth devices, as well as using bleak: image
(using scan on from bluetoothctl)

image (using bleak on an app)

Starting search... Found 3 devices.

I updated BlueZ to 5.50, and it's working fine too (using bluetoothctl and Bleak):

me@home$ bluetoothctl -v
bluetoothctl: 5.50

me@home$ bluetoothctl
Agent registered
[bluetooth]# scan on
Discovery started
[CHG] Controller F8:94:C2:6B:1C:6D Discovering: yes
[CHG] Device 1B:6F:4A:48:94:2D RSSI: -58
[CHG] Device 68:A3:78:2C:B8:68 RSSI: -78
[CHG] Device 90:DD:5D:9C:EA:C9 RSSI: -58
[NEW] Device 51:42:EE:FF:C6:75 51-42-EE-FF-C6-75
[bluetooth]# scan off
Discovery stopped
[CHG] Controller F8:94:C2:6B:1C:6D Discovering: no
[CHG] Device 51:42:EE:FF:C6:75 RSSI is nil
[CHG] Device 90:DD:5D:9C:EA:C9 RSSI is nil
[CHG] Device 68:A3:78:2C:B8:68 RSSI is nil
[CHG] Device 1B:6F:4A:48:94:2D RSSI is nil
[bluetooth]# exit
hbldh commented 5 years ago

Ok, this seems to be an issue with a specific chipset/adapter/driver. @JoeHut are you having these problems using the same adapter/chipset?

andersou commented 5 years ago

this worked for me: https://askubuntu.com/a/1050311

hbldh commented 4 years ago

@andersou Thank you for reporting this! I cannot verify this myself. @corentinbettiol could you try the proposed solution and see if it works? Or have you found a different solution or left any attempt to solve it?

corentinbettiol commented 4 years ago

Sorry, I no longer have access to the computer with the faulty card, nor do I need to use Bleak (for the moment).

hbldh commented 4 years ago

I will close this issue and hope that the proposed solution above works.