kazola commented 1 year ago

bleak version: 0.19.5
Python version: 3.9
Operating System: Raspbian 11 bullseye
BlueZ version (bluetoothctl -v) in case of Linux: 5.66

Description

Connect reliably to a BLE device based on CC26X2R. It needs a lot of attempts to connect, used to be much more stable.

What I Did

Once it connects, everything works, but some times it takes a lot of attempts to connect. More than 10. I activated export BLEAK_LOGGING=1 The thing is that it seems to connect, from what I can understand from logs, but just too late and is discarded? As you can see, we have a lot of devices. I tried to isolate around important sections by including a mark such as

"----------------"

For example, I think the last part of the log can be enough:

2023-02-25 22:38:45,103 bleak.backends.bluezdbus.client DEBUG: Connecting to BlueZ path /org/bluez/hci0/dev_60_77_71_22_CA_57
2023-02-25 22:38:48,078 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_CA_57): ['org.bluez.Device1', {'Connected': <dbus_fast.signature.Variant ('b', True)>}, []]
2023-02-25 22:38:48,447 bleak.backends.bluezdbus.client DEBUG: _cleanup_all(/org/bluez/hci0/dev_60_77_71_22_CA_57)

----------connect attempt 3 of 3 failed, h hci0
[org.bluez.Error.Failed] le-connection-abort-by-local
2023-02-25 22:38:48,451 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_CA_57): ['org.bluez.Device1', {'Connected': <dbus_fast.signature.Variant ('b', False)>}, []]

On several spots it says connected! But it does not seem so. My connection routine for bleak is:

async def connect(self, mac):
        def c_rx(_: int, b: bytearray):
            self.ans += b

        n = 3
        for i in range(n):
            try:
                # we pass hci here
                h = self.h
                self.cli = BleakClient(mac, adapter=h)
                if await self.cli.connect(timeout=10):
                    await self.cli.start_notify(UUID_T, c_rx)
                    return 0

            except (asyncio.TimeoutError, BleakError, OSError) as ex:
                e = 'connect attempt {} of {} failed, h {}'
                print(e.format(i + 1, n, self.h))
                print(ex)
                await asyncio.sleep(1)
        return 1

While not perfect, now that I recall I have not a single connection problem when using this code on the laptop. Maybe something related to BLE service discovery? Maybe related to connection parameters? Again RPI has all these connection errors, laptop shows none.

Let's see if someone can help me, I am buying beers.

Logs

(I think the important part is at the end)

..
...org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_4D_C0_07): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:33,944 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_C8_16): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:33,946 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_C5_AF): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:33,947 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_28_11_A5_55_C8_39): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:33,947 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_2C_41_A1_D8_C7_C1): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:33,948 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_CA_41): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:33,949 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_4D_BF_C9): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:33,949 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_3D_7A_D6): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:33,950 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_CA_18): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:33,950 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_75_13): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:33,951 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_CA_57): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:33,952 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_76_17): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:33,953 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_76_0B): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:33,954 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0): ['org.bluez.Adapter1', {'Discovering': <dbus_fast.signature.Variant ('b', False)>}, []]

----------
2023-02-25 22:38:34 | [ BLE ] processing sensor 2302703 / mac 60:77:71:22:ca:57
2023-02-25 22:38:35 | [ BLE ] interacting with CC26X2 logger, info DO-2
2023-02-25 22:38:35,125 bleak.backends.bluezdbus.client DEBUG: Connecting to device @ 60:77:71:22:ca:57
2023-02-25 22:38:35,157 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0): ['org.bluez.Adapter1', {'Discovering': <dbus_fast.signature.Variant ('b', True)>}, []]
2023-02-25 22:38:35,176 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_11_30_41_82_8E_8A', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.Device1': {'Address': <dbus_fast.signature.Variant ('s', 11:30:41:82:8E:8A)>, 'AddressType': <dbus_fast.signature.Variant ('s', random)>, 'Alias': <dbus_fast.signature.Variant ('s', 11-30-41-82-8E-8A)>, 'Paired': <dbus_fast.signature.Variant ('b', False)>, 'Bonded': <dbus_fast.signature.Variant ('b', False)>, 'Trusted': <dbus_fast.signature.Variant ('b', False)>, 'Blocked': <dbus_fast.signature.Variant ('b', False)>, 'LegacyPairing': <dbus_fast.signature.Variant ('b', False)>, 'RSSI': <dbus_fast.signature.Variant ('n', -53)>, 'Connected': <dbus_fast.signature.Variant ('b', False)>, 'UUIDs': <dbus_fast.signature.Variant ('as', [])>, 'Adapter': <dbus_fast.signature.Variant ('o', /org/bluez/hci0)>, 'ManufacturerData': <dbus_fast.signature.Variant ('a{qv}', {6: <dbus_fast.signature.Variant ('ay', bytearray(b'\x01\t \x02\x0b\xf12\xa9\x9f\xe1r\x96\x9bhi\xa1L\x81\xaaK\x04\x98:8\x9b\x1e8'))>})>, 'ServicesResolved': <dbus_fast.signature.Variant ('b', False)>}, 'org.freedesktop.DBus.Properties': {}}]
2023-02-25 22:38:35,251 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_6C_B4_45_0D_44_87', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.Device1': {'Address': <dbus_fast.signature.Variant ('s', 6C:B4:45:0D:44:87)>, 'AddressType': <dbus_fast.signature.Variant ('s', random)>, 'Alias': <dbus_fast.signature.Variant ('s', 6C-B4-45-0D-44-87)>, 'Paired': <dbus_fast.signature.Variant ('b', False)>, 'Bonded': <dbus_fast.signature.Variant ('b', False)>, 'Trusted': <dbus_fast.signature.Variant ('b', False)>, 'Blocked': <dbus_fast.signature.Variant ('b', False)>, 'LegacyPairing': <dbus_fast.signature.Variant ('b', False)>, 'RSSI': <dbus_fast.signature.Variant ('n', -78)>, 'Connected': <dbus_fast.signature.Variant ('b', False)>, 'UUIDs': <dbus_fast.signature.Variant ('as', [])>, 'Adapter': <dbus_fast.signature.Variant ('o', /org/bluez/hci0)>, 'ManufacturerData': <dbus_fast.signature.Variant ('a{qv}', {76: <dbus_fast.signature.Variant ('ay', bytearray(b'\x10\x06\x00\x19\x99F\x8eH'))>})>, 'TxPower': <dbus_fast.signature.Variant ('n', 5)>, 'ServicesResolved': <dbus_fast.signature.Variant ('b', False)>}, 'org.freedesktop.DBus.Properties': {}}]
2023-02-25 22:38:35,293 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_75_13): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -53)>}, []]
2023-02-25 22:38:35,297 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_CA_41): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -41)>}, []]
2023-02-25 22:38:35,304 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_4D_BF_C9): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -70)>}, []]
2023-02-25 22:38:35,357 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_3D_7A_D6): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -53)>}, []]
2023-02-25 22:38:35,433 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_76_0B): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -29)>}, []]
2023-02-25 22:38:35,438 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_C8_16): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -41)>}, []]
2023-02-25 22:38:35,440 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_28_11_A5_55_E3_BB): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -70)>}, []]
2023-02-25 22:38:35,509 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_28_11_A5_55_C8_39): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -62)>}, []]
2023-02-25 22:38:35,687 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_47_0A_0C_EC_EA_F1): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -78)>, 'TxPower': <dbus_fast.signature.Variant ('n', 5)>}, []]
2023-02-25 22:38:35,692 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_C7_32): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -55)>}, []]
2023-02-25 22:38:35,699 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_24_CA_2B): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -69)>}, []]
2023-02-25 22:38:35,708 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_74_A8_D5_E7_25_19): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -78)>, 'TxPower': <dbus_fast.signature.Variant ('n', 12)>}, []]
2023-02-25 22:38:35,709 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_E6_C4_7F_C0_0B_BD', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.Device1': {'Address': <dbus_fast.signature.Variant ('s', E6:C4:7F:C0:0B:BD)>, 'AddressType': <dbus_fast.signature.Variant ('s', random)>, 'Alias': <dbus_fast.signature.Variant ('s', E6-C4-7F-C0-0B-BD)>, 'Paired': <dbus_fast.signature.Variant ('b', False)>, 'Bonded': <dbus_fast.signature.Variant ('b', False)>, 'Trusted': <dbus_fast.signature.Variant ('b', False)>, 'Blocked': <dbus_fast.signature.Variant ('b', False)>, 'LegacyPairing': <dbus_fast.signature.Variant ('b', False)>, 'RSSI': <dbus_fast.signature.Variant ('n', -77)>, 'Connected': <dbus_fast.signature.Variant ('b', False)>, 'UUIDs': <dbus_fast.signature.Variant ('as', [])>, 'Adapter': <dbus_fast.signature.Variant ('o', /org/bluez/hci0)>, 'ManufacturerData': <dbus_fast.signature.Variant ('a{qv}', {76: <dbus_fast.signature.Variant ('ay', bytearray(b'\x12\x02\x00\x00'))>})>, 'ServicesResolved': <dbus_fast.signature.Variant ('b', False)>}, 'org.freedesktop.DBus.Properties': {}}]
2023-02-25 22:38:35,900 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_58_93_D8_A4_B6_AB): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -65)>}, []]
2023-02-25 22:38:35,922 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_2C_41_A1_D8_C7_C1): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -72)>}, []]
2023-02-25 22:38:35,980 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_75_0C): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -56)>}, []]
2023-02-25 22:38:36,074 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_4D_D2_6A): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -61)>}, []]
2023-02-25 22:38:36,150 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_75_12): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -47)>}, []]
2023-02-25 22:38:36,173 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_CA_18): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -45)>}, []]
2023-02-25 22:38:36,440 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_76_17): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -69)>}, []]
2023-02-25 22:38:36,512 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_C5_AF): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -53)>}, []]
2023-02-25 22:38:36,527 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_58_93_D8_A4_B6_A6): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -44)>}, []]
2023-02-25 22:38:36,687 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_5A_84_2F): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -72)>}, []]
2023-02-25 22:38:36,829 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_4D_C0_07): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -60)>}, []]
2023-02-25 22:38:37,039 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_75_06): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -59)>}, []]
2023-02-25 22:38:37,317 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_CA_57): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -52)>}, []]
2023-02-25 22:38:37,326 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_11_30_41_82_8E_8A): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,329 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved (/): ['/org/bluez/hci0/dev_11_30_41_82_8E_8A', ['org.freedesktop.DBus.Properties', 'org.freedesktop.DBus.Introspectable', 'org.bluez.Device1']]
2023-02-25 22:38:37,330 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_E6_C4_7F_C0_0B_BD): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,332 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved (/): ['/org/bluez/hci0/dev_E6_C4_7F_C0_0B_BD', ['org.freedesktop.DBus.Properties', 'org.freedesktop.DBus.Introspectable', 'org.bluez.Device1']]
2023-02-25 22:38:37,334 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_CA_57): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,337 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_75_06): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,339 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_4D_C0_07): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,340 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_5A_84_2F): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,341 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_58_93_D8_A4_B6_A6): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,342 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_C5_AF): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,344 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_76_17): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,345 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_CA_18): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,346 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_75_12): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,348 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_4D_D2_6A): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,349 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_75_0C): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,351 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_2C_41_A1_D8_C7_C1): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,352 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_58_93_D8_A4_B6_AB): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,353 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_74_A8_D5_E7_25_19): ['org.bluez.Device1', {}, ['TxPower', 'RSSI']]
2023-02-25 22:38:37,355 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_24_CA_2B): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,356 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_C7_32): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,357 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_47_0A_0C_EC_EA_F1): ['org.bluez.Device1', {}, ['TxPower', 'RSSI']]
2023-02-25 22:38:37,359 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_28_11_A5_55_C8_39): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,360 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_28_11_A5_55_E3_BB): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,361 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_C8_16): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,362 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_76_0B): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,364 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_3D_7A_D6): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,365 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_4D_BF_C9): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,367 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_CA_41): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,368 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_75_13): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:37,369 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_6C_B4_45_0D_44_87): ['org.bluez.Device1', {}, ['TxPower', 'RSSI']]
2023-02-25 22:38:37,370 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0): ['org.bluez.Adapter1', {'Discovering': <dbus_fast.signature.Variant ('b', False)>}, []]
2023-02-25 22:38:37,378 bleak.backends.bluezdbus.client DEBUG: Connecting to BlueZ path /org/bluez/hci0/dev_60_77_71_22_CA_57
2023-02-25 22:38:39,043 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_CA_57): ['org.bluez.Device1', {'Connected': <dbus_fast.signature.Variant ('b', True)>}, []]
2023-02-25 22:38:39,416 bleak.backends.bluezdbus.client DEBUG: _cleanup_all(/org/bluez/hci0/dev_60_77_71_22_CA_57)

----------connect attempt 1 of 3 failed, h hci0
[org.bluez.Error.Failed] le-connection-abort-by-local
2023-02-25 22:38:39,417 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_CA_57): ['org.bluez.Device1', {'Connected': <dbus_fast.signature.Variant ('b', False)>}, []]
2023-02-25 22:38:40,419 bleak.backends.bluezdbus.client DEBUG: Connecting to device @ 60:77:71:22:ca:57
2023-02-25 22:38:40,427 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0): ['org.bluez.Adapter1', {'Discovering': <dbus_fast.signature.Variant ('b', True)>}, []]
2023-02-25 22:38:40,460 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_C5_AF): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -52)>}, []]
2023-02-25 22:38:40,466 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_C8_16): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -42)>}, []]
2023-02-25 22:38:40,470 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_3D_7A_D6): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -54)>}, []]
2023-02-25 22:38:40,496 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_47_0A_0C_EC_EA_F1): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -74)>, 'TxPower': <dbus_fast.signature.Variant ('n', 5)>}, []]
2023-02-25 22:38:40,535 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_76_0B): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -34)>}, []]
2023-02-25 22:38:40,601 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_58_93_D8_A4_B6_A6): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -48)>}, []]
2023-02-25 22:38:40,602 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_11_30_41_82_8E_8A', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.Device1': {'Address': <dbus_fast.signature.Variant ('s', 11:30:41:82:8E:8A)>, 'AddressType': <dbus_fast.signature.Variant ('s', random)>, 'Alias': <dbus_fast.signature.Variant ('s', 11-30-41-82-8E-8A)>, 'Paired': <dbus_fast.signature.Variant ('b', False)>, 'Bonded': <dbus_fast.signature.Variant ('b', False)>, 'Trusted': <dbus_fast.signature.Variant ('b', False)>, 'Blocked': <dbus_fast.signature.Variant ('b', False)>, 'LegacyPairing': <dbus_fast.signature.Variant ('b', False)>, 'RSSI': <dbus_fast.signature.Variant ('n', -62)>, 'Connected': <dbus_fast.signature.Variant ('b', False)>, 'UUIDs': <dbus_fast.signature.Variant ('as', [])>, 'Adapter': <dbus_fast.signature.Variant ('o', /org/bluez/hci0)>, 'ManufacturerData': <dbus_fast.signature.Variant ('a{qv}', {6: <dbus_fast.signature.Variant ('ay', bytearray(b'\x01\t \x02\x0b\xf12\xa9\x9f\xe1r\x96\x9bhi\xa1L\x81\xaaK\x04\x98:8\x9b\x1e8'))>})>, 'ServicesResolved': <dbus_fast.signature.Variant ('b', False)>}, 'org.freedesktop.DBus.Properties': {}}]
2023-02-25 22:38:40,646 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_75_13): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -56)>}, []]
2023-02-25 22:38:40,776 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_5A_84_2F): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -70)>}, []]
2023-02-25 22:38:40,791 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_58_93_D8_A4_B6_AB): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -46)>}, []]
2023-02-25 22:38:40,801 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_4D_BF_C9): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -71)>}, []]
2023-02-25 22:38:40,850 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_4D_C0_07): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -60)>}, []]
2023-02-25 22:38:40,853 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_24_CA_2B): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -71)>}, []]
2023-02-25 22:38:40,948 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_2C_41_A1_D8_C7_C1): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -75)>}, []]
2023-02-25 22:38:40,957 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_75_06): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -58)>}, []]
2023-02-25 22:38:41,041 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_28_11_A5_55_E3_BB): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -71)>}, []]
2023-02-25 22:38:41,063 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_CA_57): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -40)>}, []]
2023-02-25 22:38:41,072 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_11_30_41_82_8E_8A): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:41,073 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved (/): ['/org/bluez/hci0/dev_11_30_41_82_8E_8A', ['org.freedesktop.DBus.Properties', 'org.freedesktop.DBus.Introspectable', 'org.bluez.Device1']]
2023-02-25 22:38:41,074 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_CA_57): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:41,076 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_28_11_A5_55_E3_BB): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:41,078 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_75_06): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:41,079 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_2C_41_A1_D8_C7_C1): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:41,082 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_24_CA_2B): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:41,085 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_4D_C0_07): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:41,086 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_4D_BF_C9): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:41,087 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_58_93_D8_A4_B6_AB): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:41,087 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_5A_84_2F): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:41,088 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_75_13): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:41,088 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_58_93_D8_A4_B6_A6): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:41,088 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_76_0B): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:41,089 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_47_0A_0C_EC_EA_F1): ['org.bluez.Device1', {}, ['TxPower', 'RSSI']]
2023-02-25 22:38:41,089 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_3D_7A_D6): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:41,090 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_C8_16): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:41,090 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_C5_AF): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:41,090 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0): ['org.bluez.Adapter1', {'Discovering': <dbus_fast.signature.Variant ('b', False)>}, []]
2023-02-25 22:38:41,095 bleak.backends.bluezdbus.client DEBUG: Connecting to BlueZ path /org/bluez/hci0/dev_60_77_71_22_CA_57
2023-02-25 22:38:43,051 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_CA_57): ['org.bluez.Device1', {'Connected': <dbus_fast.signature.Variant ('b', True)>}, []]
2023-02-25 22:38:43,407 bleak.backends.bluezdbus.client DEBUG: _cleanup_all(/org/bluez/hci0/dev_60_77_71_22_CA_57)

----------connect attempt 2 of 3 failed, h hci0
[org.bluez.Error.Failed] le-connection-abort-by-local
2023-02-25 22:38:43,409 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_CA_57): ['org.bluez.Device1', {'Connected': <dbus_fast.signature.Variant ('b', False)>}, []]
2023-02-25 22:38:44,410 bleak.backends.bluezdbus.client DEBUG: Connecting to device @ 60:77:71:22:ca:57
2023-02-25 22:38:44,419 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0): ['org.bluez.Adapter1', {'Discovering': <dbus_fast.signature.Variant ('b', True)>}, []]
2023-02-25 22:38:44,472 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_11_30_41_82_8E_8A', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.Device1': {'Address': <dbus_fast.signature.Variant ('s', 11:30:41:82:8E:8A)>, 'AddressType': <dbus_fast.signature.Variant ('s', random)>, 'Alias': <dbus_fast.signature.Variant ('s', 11-30-41-82-8E-8A)>, 'Paired': <dbus_fast.signature.Variant ('b', False)>, 'Bonded': <dbus_fast.signature.Variant ('b', False)>, 'Trusted': <dbus_fast.signature.Variant ('b', False)>, 'Blocked': <dbus_fast.signature.Variant ('b', False)>, 'LegacyPairing': <dbus_fast.signature.Variant ('b', False)>, 'RSSI': <dbus_fast.signature.Variant ('n', -54)>, 'Connected': <dbus_fast.signature.Variant ('b', False)>, 'UUIDs': <dbus_fast.signature.Variant ('as', [])>, 'Adapter': <dbus_fast.signature.Variant ('o', /org/bluez/hci0)>, 'ManufacturerData': <dbus_fast.signature.Variant ('a{qv}', {6: <dbus_fast.signature.Variant ('ay', bytearray(b'\x01\t \x02\x0b\xf12\xa9\x9f\xe1r\x96\x9bhi\xa1L\x81\xaaK\x04\x98:8\x9b\x1e8'))>})>, 'ServicesResolved': <dbus_fast.signature.Variant ('b', False)>}, 'org.freedesktop.DBus.Properties': {}}]
2023-02-25 22:38:44,483 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_76_0B): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -34)>}, []]
2023-02-25 22:38:44,487 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_C8_16): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -41)>}, []]
2023-02-25 22:38:44,490 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_C5_AF): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -53)>}, []]
2023-02-25 22:38:44,562 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_75_13): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -58)>}, []]
2023-02-25 22:38:44,587 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_58_93_D8_A4_B6_A6): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -47)>}, []]
2023-02-25 22:38:44,702 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_3D_7A_D6): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -54)>}, []]
2023-02-25 22:38:44,738 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_2C_41_A1_D8_C7_C1): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -68)>}, []]
2023-02-25 22:38:44,758 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_C7_32): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -51)>}, []]
2023-02-25 22:38:44,765 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_4D_BF_C9): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -71)>}, []]
2023-02-25 22:38:44,787 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_5A_84_2F): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -62)>}, []]
2023-02-25 22:38:44,807 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_58_93_D8_A4_B6_AB): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -42)>}, []]
2023-02-25 22:38:44,927 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_28_11_A5_55_E3_BB): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -73)>}, []]
2023-02-25 22:38:45,056 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_4D_C0_07): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -59)>}, []]
2023-02-25 22:38:45,077 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_CA_57): ['org.bluez.Device1', {'RSSI': <dbus_fast.signature.Variant ('n', -42)>}, []]
2023-02-25 22:38:45,085 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_11_30_41_82_8E_8A): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:45,086 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved (/): ['/org/bluez/hci0/dev_11_30_41_82_8E_8A', ['org.freedesktop.DBus.Properties', 'org.freedesktop.DBus.Introspectable', 'org.bluez.Device1']]
2023-02-25 22:38:45,086 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_CA_57): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:45,087 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_4D_C0_07): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:45,088 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_28_11_A5_55_E3_BB): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:45,089 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_58_93_D8_A4_B6_AB): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:45,089 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_5A_84_2F): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:45,090 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_4D_BF_C9): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:45,091 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_C7_32): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:45,091 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_2C_41_A1_D8_C7_C1): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:45,092 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_3D_7A_D6): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:45,093 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_58_93_D8_A4_B6_A6): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:45,093 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_75_13): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:45,094 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_C5_AF): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:45,095 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_C8_16): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:45,095 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_00_1E_C0_6C_76_0B): ['org.bluez.Device1', {}, ['RSSI']]
2023-02-25 22:38:45,096 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0): ['org.bluez.Adapter1', {'Discovering': <dbus_fast.signature.Variant ('b', False)>}, []]
2023-02-25 22:38:45,103 bleak.backends.bluezdbus.client DEBUG: Connecting to BlueZ path /org/bluez/hci0/dev_60_77_71_22_CA_57
2023-02-25 22:38:48,078 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_CA_57): ['org.bluez.Device1', {'Connected': <dbus_fast.signature.Variant ('b', True)>}, []]
2023-02-25 22:38:48,447 bleak.backends.bluezdbus.client DEBUG: _cleanup_all(/org/bluez/hci0/dev_60_77_71_22_CA_57)

----------connect attempt 3 of 3 failed, h hci0
[org.bluez.Error.Failed] le-connection-abort-by-local
2023-02-25 22:38:48,451 bleak.backends.bluezdbus.manager DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_60_77_71_22_CA_57): ['org.bluez.Device1', {'Connected': <dbus_fast.signature.Variant ('b', False)>}, []]

----------
2023-02-25 22:38:49 | [ BLE ] error dl_cc26x2r_exception cc26x2 interact connecting

kazola commented 1 year ago

A bit more info, I created a extremely simplified script which only tries to connect once. This is the btmon output for a FAILURE:

pi@raspberrypi:~/li/ddt $ sudo btmon
Bluetooth monitor ver 5.66
= Note: Linux version 5.15.61-v7l+ (armv7l)                                                                                                                                                              0.163668
= Note: Bluetooth subsystem version 2.22                                                                                                                                                                 0.163686
= New Index: E4:5F:01:84:19:70 (Primary,UART,hci0)                                                                                                                                                [hci0] 0.163699
= Open Index: E4:5F:01:84:19:70                                                                                                                                                                   [hci0] 0.163710
= Index Info: E4:5F:01:84:19:70 (Cypress Semiconductor)                                                                                                                                           [hci0] 0.163715
@ MGMT Open: bluetoothd (privileged) version 1.21                                                                                                                                               {0x0001} 0.163720
@ RAW Open: hciconfig version 2.22                                                                                                                                                              {0x0002} 6.268052
@ RAW Close: hciconfig                                                                                                                                                                          {0x0002} 6.268466
@ RAW Open: hciconfig version 2.22                                                                                                                                                              {0x0002} 6.277072
@ RAW Close: hciconfig                                                                                                                                                                          {0x0002} 6.277330
@ MGMT Command: Start Service Discovery (0x003a) plen 4                                                                                                                                  {0x0001} [hci0] 6.419299
        Address type: 0x06
          LE Public
          LE Random
        RSSI: invalid (0x7f)
        UUIDs: 0
< HCI Command: LE Set Random Address (0x08|0x0005) plen 6                                                                                                                                      #1 [hci0] 6.419354
        Address: 24:18:28:43:00:C9 (Non-Resolvable)
> HCI Event: Command Complete (0x0e) plen 4                                                                                                                                                    #2 [hci0] 6.419652
      LE Set Random Address (0x08|0x0005) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7                                                                                                                                     #3 [hci0] 6.419680
        Type: Active (0x01)
        Interval: 11.250 msec (0x0012)
        Window: 11.250 msec (0x0012)
        Own address type: Random (0x01)
        Filter policy: Accept all advertisement (0x00)
> HCI Event: Command Complete (0x0e) plen 4                                                                                                                                                    #4 [hci0] 6.419967
      LE Set Scan Parameters (0x08|0x000b) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2                                                                                                                                         #5 [hci0] 6.419992
        Scanning: Enabled (0x01)
        Filter duplicates: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4                                                                                                                                                    #6 [hci0] 6.420336
      LE Set Scan Enable (0x08|0x000c) ncmd 1
        Status: Success (0x00)
@ MGMT Event: Command Complete (0x0001) plen 4                                                                                                                                           {0x0001} [hci0] 6.420369
      Start Service Discovery (0x003a) plen 1
        Status: Success (0x00)
        Address type: 0x06
          LE Public
          LE Random
@ MGMT Event: Discovering (0x0013) plen 2                                                                                                                                                {0x0001} [hci0] 6.420377
        Address type: 0x06
          LE Public
          LE Random
        Discovery: Enabled (0x01)
> HCI Event: LE Meta Event (0x3e) plen 43                                                                                                                                                      #7 [hci0] 6.459640
      LE Advertising Report (0x02)
        Num reports: 1
        Event type: Connectable undirected - ADV_IND (0x00)
        Address type: Public (0x00)
        Address: 00:1E:C0:6C:76:0B (Microchip Technology Inc.)
        Data length: 31
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
        128-bit Service UUIDs (complete): 1 entry
          Vendor specific
        Name (complete): MATP-2WA
        RSSI: -33 dBm (0xdf)
> HCI Event: LE Meta Event (0x3e) plen 21                                                                                                                                                      #8 [hci0] 6.548410
      LE Advertising Report (0x02)
        Num reports: 1
        Event type: Connectable undirected - ADV_IND (0x00)
        Address type: Public (0x00)
        Address: 60:77:71:22:C7:32 (Texas Instruments)
        Data length: 9
        Name (complete): DO-2
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
        RSSI: -49 dBm (0xcf)
@ MGMT Event: Device Found (0x0012) plen 45                                                                                                                                              {0x0001} [hci0] 6.548437
        LE Address: 00:1E:C0:6C:76:0B (Microchip Technology Inc.)
        RSSI: -33 dBm (0xdf)
        Flags: 0x00000000
        Data length: 31
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
        128-bit Service UUIDs (complete): 1 entry
          Vendor specific
        Name (complete): MATP-2WA
> HCI Event: LE Meta Event (0x3e) plen 43                                                                                                                                                      #9 [hci0] 6.563446
      LE Advertising Report (0x02)
        Num reports: 1
        Event type: Connectable undirected - ADV_IND (0x00)
        Address type: Public (0x00)
        Address: 00:1E:C0:6C:75:13 (Microchip Technology Inc.)
        Data length: 31
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
        128-bit Service UUIDs (complete): 1 entry
          Vendor specific
        Name (complete): MATP-2WA
        RSSI: -70 dBm (0xba)
@ MGMT Event: Device Found (0x0012) plen 23                                                                                                                                              {0x0001} [hci0] 6.563475
        LE Address: 60:77:71:22:C7:32 (Texas Instruments)
        RSSI: -49 dBm (0xcf)
        Flags: 0x00000000
        Data length: 9
        Name (complete): DO-2
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
> HCI Event: LE Meta Event (0x3e) plen 30                                                                                                                                                     #10 [hci0] 6.580774
      LE Advertising Report (0x02)
        Num reports: 1
        Event type: Connectable undirected - ADV_IND (0x00)
        Address type: Public (0x00)
        Address: 28:11:A5:55:C8:39 (Bose Corporation)
        Data length: 18
        Flags: 0x1a
          LE General Discoverable Mode
          Simultaneous LE and BR/EDR (Controller)
          Simultaneous LE and BR/EDR (Host)
        16-bit Service UUIDs (complete): 1 entry
          Bose Corporation (0xfebe)
        Company: not assigned (2561)
          Data: 4200ff448d7d79
        RSSI: -66 dBm (0xbe)
@ MGMT Event: Device Found (0x0012) plen 45                                                                                                                                              {0x0001} [hci0] 6.580800
        LE Address: 00:1E:C0:6C:75:13 (Microchip Technology Inc.)
        RSSI: -70 dBm (0xba)
        Flags: 0x00000000
        Data length: 31
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
        128-bit Service UUIDs (complete): 1 entry
          Vendor specific
        Name (complete): MATP-2WA
> HCI Event: LE Meta Event (0x3e) plen 42                                                                                                                                                     #11 [hci0] 6.583500
      LE Advertising Report (0x02)
        Num reports: 1
        Event type: Connectable undirected - ADV_IND (0x00)
        Address type: Public (0x00)
        Address: 00:1E:C0:4D:C0:07 (Microchip Technology Inc.)
        Data length: 30
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
        128-bit Service UUIDs (complete): 1 entry
          Vendor specific
        Name (complete): MATP-2W
        RSSI: -58 dBm (0xc6)
@ MGMT Event: Device Found (0x0012) plen 32                                                                                                                                              {0x0001} [hci0] 6.583529
        LE Address: 28:11:A5:55:C8:39 (Bose Corporation)
        RSSI: -66 dBm (0xbe)
        Flags: 0x00000000
        Data length: 18
        Flags: 0x1a
          LE General Discoverable Mode
          Simultaneous LE and BR/EDR (Controller)
          Simultaneous LE and BR/EDR (Host)
        16-bit Service UUIDs (complete): 1 entry
          Bose Corporation (0xfebe)
        Company: not assigned (2561)
          Data: 4200ff448d7d79
> HCI Event: LE Meta Event (0x3e) plen 43                                                                                                                                                     #12 [hci0] 6.587232
      LE Advertising Report (0x02)
        Num reports: 1
        Event type: Non connectable undirected - ADV_NONCONN_IND (0x03)
        Address type: Random (0x01)
        Address: 30:08:98:A9:CC:BF (Non-Resolvable)
        Data length: 31
        Company: Microsoft (6)
          Data: 0109200233f7b72eef7d0b9338f2f4e7dd3f59f31d1f60909fa380
        RSSI: -72 dBm (0xb8)
@ MGMT Event: Device Found (0x0012) plen 44                                                                                                                                              {0x0001} [hci0] 6.587266
        LE Address: 00:1E:C0:4D:C0:07 (Microchip Technology Inc.)
        RSSI: -58 dBm (0xc6)
        Flags: 0x00000000
        Data length: 30
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
        128-bit Service UUIDs (complete): 1 entry
          Vendor specific
        Name (complete): MATP-2W
@ MGMT Event: Device Found (0x0012) plen 45                                                                                                                                              {0x0001} [hci0] 6.587275
        LE Address: 30:08:98:A9:CC:BF (Non-Resolvable)
        RSSI: -72 dBm (0xb8)
        Flags: 0x00000004
          Not Connectable
        Data length: 31
        Company: Microsoft (6)
          Data: 0109200233f7b72eef7d0b9338f2f4e7dd3f59f31d1f60909fa380
> HCI Event: LE Meta Event (0x3e) plen 42                                                                                                                                                     #13 [hci0] 6.605614
      LE Advertising Report (0x02)
        Num reports: 1
        Event type: Connectable undirected - ADV_IND (0x00)
        Address type: Public (0x00)
        Address: 00:1E:C0:4D:D2:6A (Microchip Technology Inc.)
        Data length: 30
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
        128-bit Service UUIDs (complete): 1 entry
          Vendor specific
        Name (complete): MATP-2W
        RSSI: -75 dBm (0xb5)
> HCI Event: LE Meta Event (0x3e) plen 30                                                                                                                                                     #14 [hci0] 6.623952
      LE Advertising Report (0x02)
        Num reports: 1
        Event type: Connectable undirected - ADV_IND (0x00)
        Address type: Public (0x00)
        Address: 28:11:A5:55:E3:BB (Bose Corporation)
        Data length: 18
        Flags: 0x1a
          LE General Discoverable Mode
          Simultaneous LE and BR/EDR (Controller)
          Simultaneous LE and BR/EDR (Host)
        16-bit Service UUIDs (complete): 1 entry
          Bose Corporation (0xfebe)
        Company: not assigned (2817)
          Data: 020071cc0b8f0c
        RSSI: -71 dBm (0xb9)
@ MGMT Event: Device Found (0x0012) plen 44                                                                                                                                              {0x0001} [hci0] 6.623978
        LE Address: 00:1E:C0:4D:D2:6A (Microchip Technology Inc.)
        RSSI: -75 dBm (0xb5)
        Flags: 0x00000000
        Data length: 30
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
        128-bit Service UUIDs (complete): 1 entry
          Vendor specific
        Name (complete): MATP-2W
> HCI Event: LE Meta Event (0x3e) plen 42                                                                                                                                                     #15 [hci0] 6.690243
      LE Advertising Report (0x02)
        Num reports: 1
        Event type: Connectable undirected - ADV_IND (0x00)
        Address type: Public (0x00)
        Address: 00:1E:C0:4D:BF:C9 (Microchip Technology Inc.)
        Data length: 30
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
        128-bit Service UUIDs (complete): 1 entry
          Vendor specific
        Name (complete): MATP-2W
        RSSI: -67 dBm (0xbd)
@ MGMT Event: Device Found (0x0012) plen 32                                                                                                                                              {0x0001} [hci0] 6.690271
        LE Address: 28:11:A5:55:E3:BB (Bose Corporation)
        RSSI: -71 dBm (0xb9)
        Flags: 0x00000000
        Data length: 18
        Flags: 0x1a
          LE General Discoverable Mode
          Simultaneous LE and BR/EDR (Controller)
          Simultaneous LE and BR/EDR (Host)
        16-bit Service UUIDs (complete): 1 entry
          Bose Corporation (0xfebe)
        Company: not assigned (2817)
          Data: 020071cc0b8f0c
> HCI Event: LE Meta Event (0x3e) plen 21                                                                                                                                                     #16 [hci0] 6.732199
      LE Advertising Report (0x02)
        Num reports: 1
        Event type: Connectable undirected - ADV_IND (0x00)
        Address type: Public (0x00)
        Address: 60:77:71:22:CA:57 (Texas Instruments)
        Data length: 9
        Name (complete): DO-2
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
        RSSI: -40 dBm (0xd8)
@ MGMT Event: Device Found (0x0012) plen 44                                                                                                                                              {0x0001} [hci0] 6.732230
        LE Address: 00:1E:C0:4D:BF:C9 (Microchip Technology Inc.)
        RSSI: -67 dBm (0xbd)
        Flags: 0x00000000
        Data length: 30
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
        128-bit Service UUIDs (complete): 1 entry
          Vendor specific
        Name (complete): MATP-2W
> HCI Event: LE Meta Event (0x3e) plen 42                                                                                                                                                     #17 [hci0] 6.792129
      LE Advertising Report (0x02)
        Num reports: 1
        Event type: Connectable undirected - ADV_IND (0x00)
        Address type: Public (0x00)
        Address: 00:1E:C0:6C:75:0C (Microchip Technology Inc.)
        Data length: 30
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
        128-bit Service UUIDs (complete): 1 entry
          Vendor specific
        Name (complete): MATP-2W
        RSSI: -68 dBm (0xbc)
@ MGMT Event: Device Found (0x0012) plen 23                                                                                                                                              {0x0001} [hci0] 6.792160
        LE Address: 60:77:71:22:CA:57 (Texas Instruments)
        RSSI: -40 dBm (0xd8)
        Flags: 0x00000000
        Data length: 9
        Name (complete): DO-2
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
@ MGMT Command: Stop Discovery (0x0024) plen 1                                                                                                                                           {0x0001} [hci0] 6.794344
        Address type: 0x06
          LE Public
          LE Random
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2                                                                                                                                        #18 [hci0] 6.794395
        Scanning: Disabled (0x00)
        Filter duplicates: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4                                                                                                                                                   #19 [hci0] 6.796071
      LE Set Scan Enable (0x08|0x000c) ncmd 1
        Status: Success (0x00)
@ MGMT Event: Command Complete (0x0001) plen 4                                                                                                                                           {0x0001} [hci0] 6.796102
      Stop Discovery (0x0024) plen 1
        Status: Success (0x00)
        Address type: 0x06
          LE Public
          LE Random
@ MGMT Event: Discovering (0x0013) plen 2                                                                                                                                                {0x0001} [hci0] 6.796113
        Address type: 0x06
          LE Public
          LE Random
        Discovery: Disabled (0x00)
< HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7                                                                                                                                    #20 [hci0] 6.805028
        Type: Passive (0x00)
        Interval: 60.000 msec (0x0060)
        Window: 60.000 msec (0x0060)
        Own address type: Public (0x00)
        Filter policy: Ignore not in accept list (0x01)
> HCI Event: Command Complete (0x0e) plen 4                                                                                                                                                   #21 [hci0] 6.805348
      LE Set Scan Parameters (0x08|0x000b) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2                                                                                                                                        #22 [hci0] 6.805372
        Scanning: Enabled (0x01)
        Filter duplicates: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4                                                                                                                                                   #23 [hci0] 6.805695
      LE Set Scan Enable (0x08|0x000c) ncmd 1
        Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 21                                                                                                                                                     #24 [hci0] 8.738802
      LE Advertising Report (0x02)
        Num reports: 1
        Event type: Connectable undirected - ADV_IND (0x00)
        Address type: Public (0x00)
        Address: 60:77:71:22:CA:57 (Texas Instruments)
        Data length: 9
        Name (complete): DO-2
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
        RSSI: -51 dBm (0xcd)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2                                                                                                                                        #25 [hci0] 8.738889
        Scanning: Disabled (0x00)
        Filter duplicates: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4                                                                                                                                                   #26 [hci0] 8.741093
      LE Set Scan Enable (0x08|0x000c) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Create Connection (0x08|0x000d) plen 25                                                                                                                                     #27 [hci0] 8.741186
        Scan interval: 60.000 msec (0x0060)
        Scan window: 60.000 msec (0x0060)
        Filter policy: Accept list is not used (0x00)
        Peer address type: Public (0x00)
        Peer address: 60:77:71:22:CA:57 (Texas Instruments)
        Own address type: Public (0x00)
        Min connection interval: 30.00 msec (0x0018)
        Max connection interval: 50.00 msec (0x0028)
        Connection latency: 0 (0x0000)
        Supervision timeout: 420 msec (0x002a)
        Min connection length: 0.000 msec (0x0000)
        Max connection length: 0.000 msec (0x0000)
> HCI Event: Command Status (0x0f) plen 4                                                                                                                                                     #28 [hci0] 8.741767
      LE Create Connection (0x08|0x000d) ncmd 1
        Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 19                                                                                                                                                    #29 [hci0] 10.745527
      LE Connection Complete (0x01)
        Status: Success (0x00)
        Handle: 64
        Role: Central (0x00)
        Peer address type: Public (0x00)
        Peer address: 60:77:71:22:CA:57 (Texas Instruments)
        Connection interval: 48.75 msec (0x0027)
        Connection latency: 0 (0x0000)
        Supervision timeout: 420 msec (0x002a)
        Central clock accuracy: 0x00
@ MGMT Event: Device Connected (0x000b) plen 22                                                                                                                                         {0x0001} [hci0] 10.745604
        LE Address: 60:77:71:22:CA:57 (Texas Instruments)
        Flags: 0x00000008
          Connection Locally Initiated
        Data length: 9
        Name (complete): DO-2
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
< HCI Command: LE Read Remote Used Features (0x08|0x0016) plen 2                                                                                                                             #30 [hci0] 10.745885
        Handle: 64 Address: 60:77:71:22:CA:57 (Texas Instruments)
> HCI Event: Command Status (0x0f) plen 4                                                                                                                                                    #31 [hci0] 10.746323
      LE Read Remote Used Features (0x08|0x0016) ncmd 1
        Status: Success (0x00)
> HCI Event: Command Complete (0x0e) plen 14                                                                                                                                                 #32 [hci0] 10.746414
      LE Read Remote Used Features (0x08|0x0016) ncmd 1
        Status: Success (0x00)
        00 00 00 00 00 00 00 00 00 00                    ..........      
@ RAW Open: btmon (privileged) version 2.22                                                                                                                                                    {0x0002} 10.746975
@ RAW Close: btmon                                                                                                                                                                             {0x0002} 10.747029
> HCI Event: LE Meta Event (0x3e) plen 12                                                                                                                                                    #33 [hci0] 11.063092
      LE Read Remote Used Features (0x04)
        Status: Connection Failed to be Established (0x3e)
        Handle: 64 Address: 60:77:71:22:CA:57 (Texas Instruments)
        Features: 0x3f 0x00 0x00 0x08 0x00 0x00 0x00 0x00
          LE Encryption
          Connection Parameter Request Procedure
          Extended Reject Indication
          Peripheral-initiated Features Exchange
          LE Ping
          LE Data Packet Length Extension
          Remote Public Key Validation
> HCI Event: Disconnect Complete (0x05) plen 4                                                                                                                                               #34 [hci0] 11.063655
        Status: Success (0x00)
        Handle: 64 Address: 60:77:71:22:CA:57 (Texas Instruments)
        Reason: Connection Failed to be Established (0x3e)
@ MGMT Event: Device Disconnected (0x000c) plen 8                                                                                                                                       {0x0001} [hci0] 11.096121
        LE Address: 60:77:71:22:CA:57 (Texas Instruments)
        Reason: Unspecified (0x00)

dlech commented 1 year ago

used to be much more stable.

If it used to work better, then what has changed since then? Bleak version? BlueZ version? Other/more Bluetooth or Wi-fi devices?

kazola commented 1 year ago

Hi dlech,

By "before" I mean bleak==0.13.0.

Bluez version I bumped it to 5.66 because on another thread you commented to get away from 5.55.

There are 20 more BLE devices, can this be a problem because of active BLE scanning?

Again, on laptop works fine.

Do you think using the wi-fi (VNC to see the screen) while running my bleak-based program can be an issue? Because of coexistence or shared wi-fi/ble module in RPi?

I can do some tests if someone has something in mind.

dlech commented 1 year ago

[org.bluez.Error.Failed] le-connection-abort-by-local

I think the newer version of BlueZ gets this error more often, e.g. #993.

1220 suggests that adding a retry could work around the issue in most cases.

kazola commented 1 year ago

I added a retry based on time (try to connect for 30 seconds) instead of number of retries since it can fail several times in a row very quick.

It is, at least in my case, strongly related to using Wi-fi and BLE at the same time. I switched off Wi-Fi and I am using my cell connection, and works much better.

Thanks for your time.

karlp commented 1 year ago

yeah, newer bluez is .... wonky somehow. If i use bleak to connect to a string mac address, it now takes 5-6 or more attempts to get a connection. I can use nrf connect on my phone to connect every time. If I do the following steps manually in bluetoothctl, it works first time though.

bluetoothctl
scan le
<ignore spam>
connect blah

It's something with the devices being removed when scanning stops, but it's wayyyy more problematic than it used to be. The scanning spam stops when it gets connected, but resumes when you disconnect. I'm on bluez 5.66

dlech commented 1 year ago

Closing as duplicate of #1220.

hbldh / bleak

unreliable connection to my BLE device needs lots of attempts to connect #1240

Description

What I Did

Logs

1220 suggests that adding a retry could work around the issue in most cases.