Bleak find device only when runing bluetoothctl power on & scan on

Question

I'm using Xiaomi temperature and humidity sensor with custom firmware who tells me every 1 min the data when the device is connected.

My problem, normal Bleak find the devices only when I did in a second window the following:

bluetoothctl 
power on
scan on

When I exit bluetoothctl the python script don't find it again. Bleak supply a Discover Script which finds the goods without bluetoothctl but a connection later failed (I've try already mix both scripts) https://github.com/hbldh/bleak/blob/develop/examples/discover.py

from bleak import BleakClient
import asyncio



notify_uuid = "00002a6f-0000-1000-8000-00805f9b34fb"


def callback(sender, data):

    print(sender, data)

def run(addresses):
    loop = asyncio.get_event_loop()

    tasks = asyncio.gather(*(connect_to_device(address) for address in addresses))

    loop.run_until_complete(tasks)


async def connect_to_device(address):
    print("starting", address, "loop")
    async with BleakClient(address, timeout=50.0) as client:

        print("connect to", address)
        try:
            await client.start_notify(notify_uuid, callback)  
        except Exception as e:
            print(e)

    print("disconnect from", address)


if __name__ == "__main__":
    run(
        ["A4:C1:38:82:8A:50"]
    )

Debug on with power and scan on

starting A4:C1:38:82:8A:50 loop
2021-09-26 08:53:52,614 bleak.backends.bluezdbus.client DEBUG: Connecting to device @ A4:C1:38:82:8A:50 with hci0
2021-09-26 08:53:52,635 bleak.backends.bluezdbus.scanner DEBUG: cached devices: {}
2021-09-26 08:53:54,457 bleak.backends.bluezdbus.scanner DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_A4_C1_38_82_8A_50', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.Device1': {'Address': <dbus_next.signature.Variant ('s', A4:C1:38:82:8A:50)>, 'AddressType': <dbus_next.signature.Variant ('s', public)>, 'Name': <dbus_next.signature.Variant ('s', ATC_828A50)>, 'Alias': <dbus_next.signature.Variant ('s', ATC_828A50)>, 'Paired': <dbus_next.signature.Variant ('b', False)>, 'Trusted': <dbus_next.signature.Variant ('b', False)>, 'Blocked': <dbus_next.signature.Variant ('b', False)>, 'LegacyPairing': <dbus_next.signature.Variant ('b', False)>, 'RSSI': <dbus_next.signature.Variant ('n', -53)>, 'Connected': <dbus_next.signature.Variant ('b', False)>, 'UUIDs': <dbus_next.signature.Variant ('as', [])>, 'Adapter': <dbus_next.signature.Variant ('o', /org/bluez/hci0)>, 'ServiceData': <dbus_next.signature.Variant ('a{sv}', {'0000181a-0000-1000-8000-00805f9b34fb': <dbus_next.signature.Variant ('ay', b'\xa4\xc18\x82\x8aP\x00\xe8:d\x0ca\x81')>})>, 'ServicesResolved': <dbus_next.signature.Variant ('b', False)>}, 'org.freedesktop.DBus.Properties': {}}]
2021-09-26 08:54:00,157 bleak.backends.bluezdbus.client DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_A4_C1_38_82_8A_50): ['org.bluez.Device1', {'Connected': <dbus_next.signature.Variant ('b', True)>}, []]
2021-09-26 08:54:00,221 bleak.backends.bluezdbus.client DEBUG: Connection successful (/org/bluez/hci0/dev_A4_C1_38_82_8A_50)
2021-09-26 08:54:00,221 bleak.backends.bluezdbus.client DEBUG: Waiting for ServicesResolved (/org/bluez/hci0/dev_A4_C1_38_82_8A_50)
2021-09-26 08:54:01,237 bleak.backends.bluezdbus.client DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_A4_C1_38_82_8A_50/service0008', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.GattService1': {'UUID': <dbus_next.signature.Variant ('s', 00001801-0000-1000-8000-00805f9b34fb)>, 'Device': <dbus_next.signature.Variant ('o', /org/bluez/hci0/dev_A4_C1_38_82_8A_50)>, 'Primary': <dbus_next.signature.Variant ('b', True)>, 'Includes': <dbus_next.signature.Variant ('ao', [])>}, 'org.freedesktop.DBus.Properties': {}}]
2021-09-26 08:54:01,239 bleak.backends.bluezdbus.client DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_A4_C1_38_82_8A_50/service0008/char0009', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.GattCharacteristic1': {'UUID': <dbus_next.signature.Variant ('s', 00002a05-0000-1000-8000-00805f9b34fb)>, 'Service': <dbus_next.signature.Variant ('o', /org/bluez/hci0/dev_A4_C1_38_82_8A_50/service0008)>, 'Value': <dbus_next.signature.Variant ('ay', b'')>, 'Notifying': <dbus_next.signature.Variant ('b', False)>, 'Flags': <dbus_next.signature.Variant ('as', ['indicate'])>}, 'org.freedesktop.DBus.Properties': {}}]
2021-09-26 08:54:01,241 bleak.backends.bluezdbus.client DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_A4_C1_38_82_8A_50/service0008/char0009/desc000b', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.GattDescriptor1': {'UUID': <dbus_next.signature.Variant ('s', 00002902-0000-1000-8000-00805f9b34fb)>, 'Characteristic': <dbus_next.signature.Variant ('o', /org/bluez/hci0/dev_A4_C1_38_82_8A_50/service0008/char0009)>, 'Value': <dbus_next.signature.Variant ('ay', b'')>}, 'org.freedesktop.DBus.Properties': {}}]
2021-09-26 08:54:01,243 bleak.backends.bluezdbus.client DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_A4_C1_38_82_8A_50/service000c', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.GattService1': {'UUID': <dbus_next.signature.Variant ('s', 0000180f-0000-1000-8000-00805f9b34fb)>, 'Device': <dbus_next.signature.Variant ('o', /org/bluez/hci0/dev_A4_C1_38_82_8A_50)>, 'Primary': <dbus_next.signature.Variant ('b', True)>, 'Includes': <dbus_next.signature.Variant ('ao', [])>}, 'org.freedesktop.DBus.Properties': {}}]
2021-09-26 08:54:01,245 bleak.backends.bluezdbus.client DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_A4_C1_38_82_8A_50/service000c/char000d', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.GattCharacteristic1': {'UUID': <dbus_next.signature.Variant ('s', 00002a19-0000-1000-8000-00805f9b34fb)>, 'Service': <dbus_next.signature.Variant ('o', /org/bluez/hci0/dev_A4_C1_38_82_8A_50/service000c)>, 'Value': <dbus_next.signature.Variant ('ay', b'')>, 'Notifying': <dbus_next.signature.Variant ('b', False)>, 'Flags': <dbus_next.signature.Variant ('as', ['read', 'notify'])>, 'NotifyAcquired': <dbus_next.signature.Variant ('b', False)>}, 'org.freedesktop.DBus.Properties': {}}]
2021-09-26 08:54:01,246 bleak.backends.bluezdbus.client DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_A4_C1_38_82_8A_50/service000c/char000d/desc000f', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.GattDescriptor1': {'UUID': <dbus_next.signature.Variant ('s', 00002902-0000-1000-8000-00805f9b34fb)>, 'Characteristic': <dbus_next.signature.Variant ('o', /org/bluez/hci0/dev_A4_C1_38_82_8A_50/service000c/char000d)>, 'Value': <dbus_next.signature.Variant ('ay', b'')>}, 'org.freedesktop.DBus.Properties': {}}]
2021-09-26 08:54:01,248 bleak.backends.bluezdbus.client DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_A4_C1_38_82_8A_50/service0010', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.GattService1': {'UUID': <dbus_next.signature.Variant ('s', 0000181a-0000-1000-8000-00805f9b34fb)>, 'Device': <dbus_next.signature.Variant ('o', /org/bluez/hci0/dev_A4_C1_38_82_8A_50)>, 'Primary': <dbus_next.signature.Variant ('b', True)>, 'Includes': <dbus_next.signature.Variant ('ao', [])>}, 'org.freedesktop.DBus.Properties': {}}]
2021-09-26 08:54:01,250 bleak.backends.bluezdbus.client DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_A4_C1_38_82_8A_50/service0010/char0011', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.GattCharacteristic1': {'UUID': <dbus_next.signature.Variant ('s', 00002a1f-0000-1000-8000-00805f9b34fb)>, 'Service': <dbus_next.signature.Variant ('o', /org/bluez/hci0/dev_A4_C1_38_82_8A_50/service0010)>, 'Value': <dbus_next.signature.Variant ('ay', b'')>, 'Notifying': <dbus_next.signature.Variant ('b', False)>, 'Flags': <dbus_next.signature.Variant ('as', ['read', 'notify'])>, 'NotifyAcquired': <dbus_next.signature.Variant ('b', False)>}, 'org.freedesktop.DBus.Properties': {}}]
2021-09-26 08:54:01,251 bleak.backends.bluezdbus.client DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_A4_C1_38_82_8A_50/service0010/char0011/desc0013', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.GattDescriptor1': {'UUID': <dbus_next.signature.Variant ('s', 00002902-0000-1000-8000-00805f9b34fb)>, 'Characteristic': <dbus_next.signature.Variant ('o', /org/bluez/hci0/dev_A4_C1_38_82_8A_50/service0010/char0011)>, 'Value': <dbus_next.signature.Variant ('ay', b'')>}, 'org.freedesktop.DBus.Properties': {}}]
2021-09-26 08:54:01,253 bleak.backends.bluezdbus.client DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_A4_C1_38_82_8A_50/service0010/char0014', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.GattCharacteristic1': {'UUID': <dbus_next.signature.Variant ('s', 00002a6f-0000-1000-8000-00805f9b34fb)>, 'Service': <dbus_next.signature.Variant ('o', /org/bluez/hci0/dev_A4_C1_38_82_8A_50/service0010)>, 'Value': <dbus_next.signature.Variant ('ay', b'')>, 'Notifying': <dbus_next.signature.Variant ('b', False)>, 'Flags': <dbus_next.signature.Variant ('as', ['read', 'notify'])>, 'NotifyAcquired': <dbus_next.signature.Variant ('b', False)>}, 'org.freedesktop.DBus.Properties': {}}]
2021-09-26 08:54:01,254 bleak.backends.bluezdbus.client DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_A4_C1_38_82_8A_50/service0010/char0014/desc0016', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.GattDescriptor1': {'UUID': <dbus_next.signature.Variant ('s', 00002902-0000-1000-8000-00805f9b34fb)>, 'Characteristic': <dbus_next.signature.Variant ('o', /org/bluez/hci0/dev_A4_C1_38_82_8A_50/service0010/char0014)>, 'Value': <dbus_next.signature.Variant ('ay', b'')>}, 'org.freedesktop.DBus.Properties': {}}]
2021-09-26 08:54:01,255 bleak.backends.bluezdbus.client DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_A4_C1_38_82_8A_50/service0017', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.GattService1': {'UUID': <dbus_next.signature.Variant ('s', 00010203-0405-0607-0809-0a0b0c0d1912)>, 'Device': <dbus_next.signature.Variant ('o', /org/bluez/hci0/dev_A4_C1_38_82_8A_50)>, 'Primary': <dbus_next.signature.Variant ('b', True)>, 'Includes': <dbus_next.signature.Variant ('ao', [])>}, 'org.freedesktop.DBus.Properties': {}}]
2021-09-26 08:54:01,257 bleak.backends.bluezdbus.client DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_A4_C1_38_82_8A_50/service0017/char0018', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.GattCharacteristic1': {'UUID': <dbus_next.signature.Variant ('s', 00010203-0405-0607-0809-0a0b0c0d2b12)>, 'Service': <dbus_next.signature.Variant ('o', /org/bluez/hci0/dev_A4_C1_38_82_8A_50/service0017)>, 'Value': <dbus_next.signature.Variant ('ay', b'')>, 'Flags': <dbus_next.signature.Variant ('as', ['read', 'write-without-response'])>, 'WriteAcquired': <dbus_next.signature.Variant ('b', False)>}, 'org.freedesktop.DBus.Properties': {}}]
2021-09-26 08:54:01,258 bleak.backends.bluezdbus.client DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_A4_C1_38_82_8A_50/service0017/char0018/desc001a', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.GattDescriptor1': {'UUID': <dbus_next.signature.Variant ('s', 00002901-0000-1000-8000-00805f9b34fb)>, 'Characteristic': <dbus_next.signature.Variant ('o', /org/bluez/hci0/dev_A4_C1_38_82_8A_50/service0017/char0018)>, 'Value': <dbus_next.signature.Variant ('ay', b'')>}, 'org.freedesktop.DBus.Properties': {}}]
2021-09-26 08:54:01,259 bleak.backends.bluezdbus.client DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_A4_C1_38_82_8A_50/service001b', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.GattService1': {'UUID': <dbus_next.signature.Variant ('s', 00001f10-0000-1000-8000-00805f9b34fb)>, 'Device': <dbus_next.signature.Variant ('o', /org/bluez/hci0/dev_A4_C1_38_82_8A_50)>, 'Primary': <dbus_next.signature.Variant ('b', True)>, 'Includes': <dbus_next.signature.Variant ('ao', [])>}, 'org.freedesktop.DBus.Properties': {}}]
2021-09-26 08:54:01,261 bleak.backends.bluezdbus.client DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_A4_C1_38_82_8A_50/service001b/char001c', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.GattCharacteristic1': {'UUID': <dbus_next.signature.Variant ('s', 00001f1f-0000-1000-8000-00805f9b34fb)>, 'Service': <dbus_next.signature.Variant ('o', /org/bluez/hci0/dev_A4_C1_38_82_8A_50/service001b)>, 'Value': <dbus_next.signature.Variant ('ay', b'')>, 'Notifying': <dbus_next.signature.Variant ('b', False)>, 'Flags': <dbus_next.signature.Variant ('as', ['write-without-response', 'notify'])>, 'WriteAcquired': <dbus_next.signature.Variant ('b', False)>, 'NotifyAcquired': <dbus_next.signature.Variant ('b', False)>}, 'org.freedesktop.DBus.Properties': {}}]
2021-09-26 08:54:01,262 bleak.backends.bluezdbus.client DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_A4_C1_38_82_8A_50/service001b/char001c/desc001e', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.GattDescriptor1': {'UUID': <dbus_next.signature.Variant ('s', 00002902-0000-1000-8000-00805f9b34fb)>, 'Characteristic': <dbus_next.signature.Variant ('o', /org/bluez/hci0/dev_A4_C1_38_82_8A_50/service001b/char001c)>, 'Value': <dbus_next.signature.Variant ('ay', b'')>}, 'org.freedesktop.DBus.Properties': {}}]
2021-09-26 08:54:01,263 bleak.backends.bluezdbus.client DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_A4_C1_38_82_8A_50): ['org.bluez.Device1', {'UUIDs': <dbus_next.signature.Variant ('as', ['00001800-0000-1000-8000-00805f9b34fb', '00001801-0000-1000-8000-00805f9b34fb', '0000180f-0000-1000-8000-00805f9b34fb', '0000181a-0000-1000-8000-00805f9b34fb', '00001f10-0000-1000-8000-00805f9b34fb', '00010203-0405-0607-0809-0a0b0c0d1912'])>, 'ServicesResolved': <dbus_next.signature.Variant ('b', True)>}, []]
connect to A4:C1:38:82:8A:50
2021-09-26 08:54:01,427 bleak.backends.bluezdbus.client DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_A4_C1_38_82_8A_50): ['org.bluez.Device1', {'Name': <dbus_next.signature.Variant ('s', ATC)>, 'Alias': <dbus_next.signature.Variant ('s', ATC)>}, []]
2021-09-26 08:54:01,600 bleak.backends.bluezdbus.client DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_A4_C1_38_82_8A_50/service0010/char0014): ['org.bluez.GattCharacteristic1', {'Notifying': <dbus_next.signature.Variant ('b', True)>}, []]
2021-09-26 08:54:01,601 bleak.backends.bluezdbus.client DEBUG: Disconnecting (/org/bluez/hci0/dev_A4_C1_38_82_8A_50)
2021-09-26 08:54:04,634 bleak.backends.bluezdbus.client DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_A4_C1_38_82_8A_50): ['org.bluez.Device1', {'ServicesResolved': <dbus_next.signature.Variant ('b', False)>}, []]
2021-09-26 08:54:04,636 bleak.backends.bluezdbus.client DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_A4_C1_38_82_8A_50): ['org.bluez.Device1', {'Connected': <dbus_next.signature.Variant ('b', False)>}, []]
2021-09-26 08:54:04,637 bleak.backends.bluezdbus.client DEBUG: Device disconnected (/org/bluez/hci0/dev_A4_C1_38_82_8A_50)
2021-09-26 08:54:04,637 bleak.backends.bluezdbus.client DEBUG: _remove_signal_handlers(/org/bluez/hci0/dev_A4_C1_38_82_8A_50)
2021-09-26 08:54:04,643 bleak.backends.bluezdbus.client DEBUG: _disconnect_message_bus(/org/bluez/hci0/dev_A4_C1_38_82_8A_50)
disconnect from A4:C1:38:82:8A:50

And withouth:

starting A4:C1:38:82:8A:50 loop
2021-09-26 08:55:30,458 bleak.backends.bluezdbus.client DEBUG: Connecting to device @ A4:C1:38:82:8A:50 with hci0
2021-09-26 08:55:30,478 bleak.backends.bluezdbus.scanner DEBUG: cached devices: {}
2021-09-26 08:55:31,351 bleak.backends.bluezdbus.scanner DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0): ['org.bluez.Adapter1', {'Discovering': <dbus_next.signature.Variant ('b', True)>}, []]
2021-09-26 08:55:31,595 bleak.backends.bluezdbus.scanner DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_A4_C1_38_82_8A_50', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.Device1': {'Address': <dbus_next.signature.Variant ('s', A4:C1:38:82:8A:50)>, 'AddressType': <dbus_next.signature.Variant ('s', public)>, 'Name': <dbus_next.signature.Variant ('s', ATC_828A50)>, 'Alias': <dbus_next.signature.Variant ('s', ATC_828A50)>, 'Paired': <dbus_next.signature.Variant ('b', False)>, 'Trusted': <dbus_next.signature.Variant ('b', False)>, 'Blocked': <dbus_next.signature.Variant ('b', False)>, 'LegacyPairing': <dbus_next.signature.Variant ('b', False)>, 'RSSI': <dbus_next.signature.Variant ('n', -66)>, 'Connected': <dbus_next.signature.Variant ('b', False)>, 'UUIDs': <dbus_next.signature.Variant ('as', [])>, 'Adapter': <dbus_next.signature.Variant ('o', /org/bluez/hci0)>, 'ServiceData': <dbus_next.signature.Variant ('a{sv}', {'0000181a-0000-1000-8000-00805f9b34fb': <dbus_next.signature.Variant ('ay', b'\xa4\xc18\x82\x8aP\x00\xe8:d\x0c^\x83')>})>, 'ServicesResolved': <dbus_next.signature.Variant ('b', False)>}, 'org.freedesktop.DBus.Properties': {}}]
2021-09-26 08:55:31,630 bleak.backends.bluezdbus.client DEBUG: org.bluez.Device1 object not found, trying org.bluez.Adapter1.ConnectDevice (/org/bluez/hci0/dev_A4_C1_38_82_8A_50)
2021-09-26 08:55:31,633 bleak.backends.bluezdbus.client DEBUG: org.bluez.Adapter1.ConnectDevice not found (/org/bluez/hci0/dev_A4_C1_38_82_8A_50), try enabling bluetoothd --experimental
2021-09-26 08:55:31,633 bleak.backends.bluezdbus.client DEBUG: _remove_signal_handlers(/org/bluez/hci0/dev_A4_C1_38_82_8A_50)
2021-09-26 08:55:31,639 bleak.backends.bluezdbus.client DEBUG: _disconnect_message_bus(/org/bluez/hci0/dev_A4_C1_38_82_8A_50)
Traceback (most recent call last):
  File "/var/www/bt2/3.py", line 37, in <module>
    run(
  File "/var/www/bt2/3.py", line 20, in run
    loop.run_until_complete(tasks)
  File "/usr/lib/python3.9/asyncio/base_events.py", line 642, in run_until_complete
    return future.result()
  File "/var/www/bt2/3.py", line 25, in connect_to_device
    async with BleakClient(address, timeout=50.0) as client:
  File "/usr/local/lib/python3.9/dist-packages/bleak/backends/client.py", line 61, in __aenter__
    await self.connect()
  File "/usr/local/lib/python3.9/dist-packages/bleak/backends/bluezdbus/client.py", line 236, in connect
    raise BleakError(
bleak.exc.BleakError: Device with address A4:C1:38:82:8A:50 could not be found. Try increasing `timeout` value or moving the device closer.

Now with the experimental flag

starting A4:C1:38:82:8A:50 loop
2021-09-26 09:57:10,951 bleak.backends.bluezdbus.client DEBUG: Connecting to device @ A4:C1:38:82:8A:50 with hci0
2021-09-26 09:57:10,981 bleak.backends.bluezdbus.scanner DEBUG: cached devices: {'/org/bluez/hci0/dev_A4_C1_38_82_8A_50': {'Address': 'A4:C1:38:82:8A:50', 'AddressType': 'public', 'Name': 'ATC', 'Alias': 'ATC', 'Paired': False, 'Trusted': False, 'Blocked': False, 'LegacyPairing': False, 'Connected': True, 'UUIDs': ['00001800-0000-1000-8000-00805f9b34fb', '00001801-0000-1000-8000-00805f9b34fb', '0000180f-0000-1000-8000-00805f9b34fb', '0000181a-0000-1000-8000-00805f9b34fb', '00001f10-0000-1000-8000-00805f9b34fb', '00010203-0405-0607-0809-0a0b0c0d1912'], 'Adapter': '/org/bluez/hci0', 'ServiceData': {'0000181a-0000-1000-8000-00805f9b34fb': b'\xa4\xc18\x82\x8aP\x00\xe3<d\x0c^\xc5'}, 'ServicesResolved': True}}
2021-09-26 09:57:11,442 bleak.backends.bluezdbus.scanner DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0): ['org.bluez.Adapter1', {'Discovering': <dbus_next.signature.Variant ('b', True)>}, []]
2021-09-26 09:57:15,774 bleak.backends.bluezdbus.scanner DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_A4_C1_38_A2_65_F9', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.Device1': {'Address': <dbus_next.signature.Variant ('s', A4:C1:38:A2:65:F9)>, 'AddressType': <dbus_next.signature.Variant ('s', public)>, 'Name': <dbus_next.signature.Variant ('s', ATC_A265F9)>, 'Alias': <dbus_next.signature.Variant ('s', ATC_A265F9)>, 'Paired': <dbus_next.signature.Variant ('b', False)>, 'Trusted': <dbus_next.signature.Variant ('b', False)>, 'Blocked': <dbus_next.signature.Variant ('b', False)>, 'LegacyPairing': <dbus_next.signature.Variant ('b', False)>, 'RSSI': <dbus_next.signature.Variant ('n', -55)>, 'Connected': <dbus_next.signature.Variant ('b', False)>, 'UUIDs': <dbus_next.signature.Variant ('as', [])>, 'Adapter': <dbus_next.signature.Variant ('o', /org/bluez/hci0)>, 'ServiceData': <dbus_next.signature.Variant ('a{sv}', {'0000181a-0000-1000-8000-00805f9b34fb': <dbus_next.signature.Variant ('ay', b'\xa4\xc18\xa2e\xf9\x00\xe4<d\x0cr\xbd')>})>, 'ServicesResolved': <dbus_next.signature.Variant ('b', False)>}, 'org.freedesktop.DBus.Properties': {}}]
2021-09-26 09:57:16,367 bleak.backends.bluezdbus.scanner DEBUG: received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_A4_C1_38_83_74_A3', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.Device1': {'Address': <dbus_next.signature.Variant ('s', A4:C1:38:83:74:A3)>, 'AddressType': <dbus_next.signature.Variant ('s', public)>, 'Name': <dbus_next.signature.Variant ('s', ATC_8374A3)>, 'Alias': <dbus_next.signature.Variant ('s', ATC_8374A3)>, 'Paired': <dbus_next.signature.Variant ('b', False)>, 'Trusted': <dbus_next.signature.Variant ('b', False)>, 'Blocked': <dbus_next.signature.Variant ('b', False)>, 'LegacyPairing': <dbus_next.signature.Variant ('b', False)>, 'RSSI': <dbus_next.signature.Variant ('n', -65)>, 'Connected': <dbus_next.signature.Variant ('b', False)>, 'UUIDs': <dbus_next.signature.Variant ('as', [])>, 'Adapter': <dbus_next.signature.Variant ('o', /org/bluez/hci0)>, 'ServiceData': <dbus_next.signature.Variant ('a{sv}', {'0000181a-0000-1000-8000-00805f9b34fb': <dbus_next.signature.Variant ('ay', b'\xa4\xc18\x83t\xa3\x00\xe8<d\x0c9\xbf')>})>, 'ServicesResolved': <dbus_next.signature.Variant ('b', False)>}, 'org.freedesktop.DBus.Properties': {}}]
2021-09-26 09:57:18,255 bleak.backends.bluezdbus.scanner DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_A4_C1_38_83_74_A3): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -66)>}, []]
2021-09-26 09:57:19,553 bleak.backends.bluezdbus.scanner DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_A4_C1_38_A2_65_F9): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -55)>}, []]
2021-09-26 09:57:20,146 bleak.backends.bluezdbus.scanner DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_A4_C1_38_83_74_A3): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -66)>}, []]
2021-09-26 09:57:21,434 bleak.backends.bluezdbus.scanner DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_A4_C1_38_A2_65_F9): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -57)>}, []]
2021-09-26 09:57:21,460 bleak.backends.bluezdbus.scanner DEBUG: received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_A4_C1_38_A2_65_F9): ['org.bluez.Device1', {}, ['RSSI']]
Traceback (most recent call last):
  File "/var/www/bt2/3.py", line 37, in <module>
    run(
  File "/var/www/bt2/3.py", line 20, in run
    loop.run_until_complete(tasks)
  File "/usr/lib/python3.9/asyncio/base_events.py", line 642, in run_until_complete
    return future.result()
  File "/var/www/bt2/3.py", line 25, in connect_to_device
    async with BleakClient(address, timeout=50.0) as client:
  File "/usr/local/lib/python3.9/dist-packages/bleak/backends/client.py", line 61, in __aenter__
    await self.connect()
  File "/usr/local/lib/python3.9/dist-packages/bleak/backends/bluezdbus/client.py", line 137, in connect
    raise BleakError(
bleak.exc.BleakError: Device with address A4:C1:38:82:8A:50 was not found.

Can you update your question with some more details such as what error message you are getting? In the Bleak documentation there is a section on [troubleshooting](https://bleak.readthedocs.io/en/latest/troubleshooting.html), have you tried any of the suggestions in there? Have you looked at using a different library? There is an example at: https://stackoverflow.com/a/63751113/7721752 — ukBaz, Sep 25 '21 at 19:07
hello @ukBaz no but i will try it later, I've updated the question and added the debug logs, the error u asked was " Device with address A4:C1:38:82:8A:50 could not be found. Try increasing `timeout` value or moving the device closer." — StefanBD, Sep 26 '21 at 08:58

score 1 · Answer 1 · answered Sep 26 '21 at 09:29

Looking through the debug messages, it shows that the cached devices is empty:

2021-09-26 08:55:30,478 bleak.backends.bluezdbus.scanner DEBUG: cached devices: {}

This should be the same result as if you do bluetoothctl devices.

When you do a device discover/scan (e.g. a scan inside bluetoothctl) you will see devices added to the cache. These devices will be deleted from the cache if they are not interacted with in some way within a certain time period. To stop your device being deleted from the cache you can, inside bluetoothctl, do a connect A4:C1:38:82:8A:50. This should stop the device being deleted from the cache.

Bleak tries to workaround the feature of unused device being removed from the cache by using ConnectDevice. However it fails because the BlueZ experimental functionality is not enabled on your system.

2021-09-26 08:55:31,630 bleak.backends.bluezdbus.client DEBUG: org.bluez.Device1 object not found, trying org.bluez.Adapter1.ConnectDevice (/org/bluez/hci0/dev_A4_C1_38_82_8A_50)
2021-09-26 08:55:31,633 bleak.backends.bluezdbus.client DEBUG: org.bluez.Adapter1.ConnectDevice not found (/org/bluez/hci0/dev_A4_C1_38_82_8A_50), try enabling bluetoothd --experimental

ConnectDevice is not meant for production use and so sits behind the --experimental flag on bluetoothd. To switch this on by default edit the /lib/systemd/system/bluetooth.service file by adding the --experimental flag to bluetoothd

sudo sed -i '/^ExecStart.*bluetoothd\s*$/ s/$/ --experimental/' /lib/systemd/system/bluetooth.service

Personally I would not enable the experimental functionality, and do a bluetoothctl "scan-connect-disconnect" as a one-time provisioning step when adding a new device.

the problem is, this will not hold in the cache, when i exit bluetoothctl the device is again not found. "power on, scan on, connect A4:C1:38:82:8A:50 Device A4:C1:38:82:8A:50 not available", it will first list after i start the python script — StefanBD, Sep 26 '21 at 09:53
Then you will need to look for more debug information from `sudo btmon`, `journalctl -f -u bluetooth`, and `sudo busctl monitor org.bluez`. You might also want to look in the BlueZ config file in `/etc/bluetooth/main.conf` and compare it with the one in the source tree https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/src/main.conf. Also, is the cache being created in `/var/lib/bluetooth/` — ukBaz, Sep 26 '21 at 11:02

Bleak find device only when runing bluetoothctl power on & scan on

1 Answers1