Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Bluetooth - eve motion v1 pairing issue #76380

Closed
jsmith79 opened this issue Aug 7, 2022 · 20 comments · Fixed by #81621
Closed

Bluetooth - eve motion v1 pairing issue #76380

jsmith79 opened this issue Aug 7, 2022 · 20 comments · Fixed by #81621

Comments

@jsmith79
Copy link

jsmith79 commented Aug 7, 2022

The problem

When trying to pair home assistant with a eve motion v1 (HomeKit motion sensor) I am getting a message "An unhandled error occurred while attempting to pair with this device. This may be a temporary failure or your device may not be supported currently."
I first tried on my production system then performed a fresh install on a RPI4 4GB 64bit to make sure it was not my bluetooth adapter.

Home Assistant 2022.8.1
Supervisor 2022.07.0
Operating System 8.4
Frontend 20220802.0 - latest

What version of Home Assistant Core has the issue?

2022.8.1

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant OS

Integration causing the issue

homekit controller

Link to integration documentation on our website

https://www.home-assistant.io/integrations/homekit_controller/

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

aiohomekit and bleak debug log snippets 

2022-08-07 20:09:41.596 DEBUG (MainThread) [aiohomekit.controller.ble.discovery] Ensure connected with device EB:E6:CB:BB:A0:52: Eve Motion C11E
2022-08-07 20:09:41.596 DEBUG (MainThread) [bleak.backends.bluezdbus.client] Connecting to device @ EB:E6:CB:BB:A0:52 with hci0
2022-08-07 20:09:41.718 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_D0_70_44_D2_04_EB): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -75)>}, []]
2022-08-07 20:09:41.958 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_74_AC_B9_3F_8F_28): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -84)>}, []]
2022-08-07 20:09:41.961 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_F0_B3_EC_12_C8_6F): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -88)>}, []]
2022-08-07 20:09:42.283 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_84_FD_27_86_CA_8A): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -70)>}, []]
2022-08-07 20:09:42.442 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_D2_F0_38_38_17_CF): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -68)>}, []]
2022-08-07 20:09:43.225 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_4B_C1_32_65_19_EE): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -92)>}, []]
2022-08-07 20:09:43.289 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_7E_A7_4B_87_4F_C7): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -92)>}, []]
2022-08-07 20:09:43.292 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_74_AC_B9_3F_8F_28): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -83)>}, []]
2022-08-07 20:09:44.485 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved (/): ['/org/bluez/hci0/dev_C7_12_42_85_00_C0', ['org.freedesktop.DBus.Properties', 'org.freedesktop.DBus.Introspectable', 'org.bluez.Device1']]
2022-08-07 20:09:46.055 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_1E_E6_57_EC_56_9F): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -89)>}, []]
2022-08-07 20:09:46.743 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_F2_C5_B6_D0_67_F2): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -89)>}, []]
2022-08-07 20:09:50.489 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_3C_DC_87_FA_53_59): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -93)>}, []]
2022-08-07 20:09:51.122 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_DC_56_E7_59_BE_7E): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -64)>}, []]
2022-08-07 20:09:51.127 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_20_18_C6_8D_75_23): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -83)>}, []]
2022-08-07 20:09:51.134 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_6D_2D_2D_A9_72_5E): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -80)>}, []]
2022-08-07 20:09:51.150 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_E7_26_0F_69_1C_FC): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -76)>}, []]
2022-08-07 20:09:51.151 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_6C_E4_10_55_9C_32): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -60)>}, []]
2022-08-07 20:09:51.167 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_E7_26_0F_69_1C_FC): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -77)>}, []]
2022-08-07 20:09:51.187 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_88_C6_26_4D_68_9A): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -73)>, 'ManufacturerData': <dbus_next.signature.Variant ('a{qv}', {3: <dbus_next.signature.Variant ('ay', b'\x003B\x00\x00\x07\xdcR\x85\x05k/\x88\xc6&Mh\x9a"')>})>}, []]
2022-08-07 20:09:51.197 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_3C_2B_C0_1F_FB_A7): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -78)>}, []]
2022-08-07 20:09:51.203 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_40_CB_C0_EA_4A_C9): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -78)>}, []]
2022-08-07 20:09:51.278 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_54_3A_D6_6E_E6_99): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -72)>}, []]
2022-08-07 20:09:51.298 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_5B_45_8D_A0_BA_E8): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -58)>}, []]
2022-08-07 20:09:51.339 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_5D_64_2A_7E_02_B5): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -78)>}, []]
2022-08-07 20:09:51.341 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_25_FF_D0_0E_D4_FC): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -52)>}, []]
2022-08-07 20:09:51.394 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_65_8D_B2_E2_C8_6B): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -59)>}, []]
2022-08-07 20:09:51.423 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_09_1C_0A_0F_17_32): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -66)>}, []]
2022-08-07 20:09:51.468 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_5B_45_8D_A0_BA_E8): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -64)>}, []]
2022-08-07 20:09:51.480 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_0E_BF_27_1D_BF_AC): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -57)>}, []]
2022-08-07 20:09:51.513 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_54_51_9B_71_FA_0E): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -56)>}, []]
2022-08-07 20:09:51.638 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_74_AC_B9_3F_8F_28): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -84)>}, []]
2022-08-07 20:09:51.662 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_F0_B3_EC_12_C8_6F): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -88)>}, []]
2022-08-07 20:09:51.664 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_0E_90_82_0D_7C_37): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -59)>}, []]
2022-08-07 20:09:51.688 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_EB_E6_CB_BB_A0_52): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -64)>}, []]
2022-08-07 20:09:51.696 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_54_51_9B_71_FA_0E): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -56)>}, []]
2022-08-07 20:09:51.703 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_88_C6_26_4D_68_9A): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -73)>, 'ManufacturerData': <dbus_next.signature.Variant ('a{qv}', {3: <dbus_next.signature.Variant ('ay', b'\x003B\x00\x00\x07\xdcR\x85\x05k/"')>})>}, []]
2022-08-07 20:09:51.705 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_E7_26_0F_69_1C_FC): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -85)>}, []]
2022-08-07 20:09:51.742 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_D0_70_44_D2_04_EB): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -73)>}, []]
2022-08-07 20:09:51.786 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_88_C6_26_4D_68_9A): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -70)>, 'ManufacturerData': <dbus_next.signature.Variant ('a{qv}', {3: <dbus_next.signature.Variant ('ay', b'\x003B\x00\x00\x07\xdcR\x85\x05k/\x88\xc6&Mh\x9a"')>})>}, []]
2022-08-07 20:09:51.792 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_09_1C_0A_0F_17_32): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -69)>}, []]
2022-08-07 20:09:51.807 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_54_3A_D6_6E_E6_99): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -72)>}, []]
2022-08-07 20:09:51.838 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_5B_45_8D_A0_BA_E8): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -58)>}, []]
2022-08-07 20:09:51.853 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_0E_BF_27_1D_BF_AC): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -62)>}, []]
2022-08-07 20:09:51.860 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_DC_56_E7_59_BE_7E): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -70)>}, []]
2022-08-07 20:09:51.897 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_6C_E4_10_55_9C_32): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -59)>}, []]
2022-08-07 20:09:51.901 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_25_FF_D0_0E_D4_FC): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -55)>}, []]
2022-08-07 20:09:51.907 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_6D_2D_2D_A9_72_5E): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -78)>}, []]
2022-08-07 20:09:51.930 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_3C_2B_C0_1F_FB_A7): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -80)>}, []]
2022-08-07 20:09:51.942 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_65_8D_B2_E2_C8_6B): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -58)>}, []]
2022-08-07 20:09:51.944 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_74_AC_B9_3F_8F_28): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -85)>}, []]
2022-08-07 20:09:51.968 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_20_18_C6_8D_75_23): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -80)>}, []]
2022-08-07 20:09:52.259 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_40_CB_C0_EA_4A_C9): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -79)>}, []]
2022-08-07 20:09:52.261 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_03_DA_84_0C_66_A0): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -89)>}, []]
2022-08-07 20:09:52.303 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_84_FD_27_86_CA_8A): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -68)>}, []]
2022-08-07 20:09:52.325 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_3C_DC_87_FA_53_59): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -92)>}, []]
2022-08-07 20:09:52.391 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_F0_B3_EC_12_C8_6F): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -83)>}, []]
2022-08-07 20:09:52.458 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_5D_64_2A_7E_02_B5): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -79)>}, []]
2022-08-07 20:09:52.463 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_D2_F0_38_38_17_CF): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -61)>}, []]
2022-08-07 20:09:52.596 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_0E_90_82_0D_7C_37): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -64)>}, []]
2022-08-07 20:09:52.723 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_7E_A7_4B_87_4F_C7): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -93)>}, []]
2022-08-07 20:09:52.758 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_E2_47_11_2B_21_CE): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -57)>}, []]
2022-08-07 20:09:52.947 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_5D_64_2A_7E_02_B5): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -76)>}, []]
2022-08-07 20:09:52.974 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_EB_E6_CB_BB_A0_52): ['org.bluez.Device1', {'Connected': <dbus_next.signature.Variant ('b', True)>}, []]
2022-08-07 20:09:53.584 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_40_CB_C0_EA_4A_C9): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -81)>}, []]
2022-08-07 20:09:53.619 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_46_F0_55_34_E3_12): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -77)>}, []]
2022-08-07 20:09:54.481 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_EB_E6_CB_BB_A0_52): ['org.bluez.Device1', {'ServicesResolved': <dbus_next.signature.Variant ('b', True)>}, []]
2022-08-07 20:09:54.485 DEBUG (MainThread) [aiohomekit.controller.ble.client] Bleak error calling <function BleDiscovery.async_start_pairing at 0x7f9fcc57e0>, retrying...
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/ble/client.py", line 61, in _async_wrap
    return await func(*args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/ble/discovery.py", line 126, in async_start_pairing
    salt, pub_key = await self._async_start_pairing(alias)
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/ble/discovery.py", line 109, in _async_start_pairing
    ff_char = self.client.get_characteristic(
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/ble/bleak.py", line 33, in get_characteristic
    char = self.services.get_service(service_type).get_characteristic(
AttributeError: 'NoneType' object has no attribute 'get_characteristic'
2022-08-07 20:09:54.487 DEBUG (MainThread) [aiohomekit.controller.ble.discovery] Ensure connected with device EB:E6:CB:BB:A0:52: Eve Motion C11E
2022-08-07 20:09:54.488 ERROR (MainThread) [homeassistant.components.homekit_controller.config_flow] Pairing attempt failed with an unhandled exception
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/homekit_controller/config_flow.py", line 502, in async_step_pair
    self.finish_pairing = await discovery.async_start_pairing(self.hkid)
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/ble/client.py", line 61, in _async_wrap
    return await func(*args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/ble/discovery.py", line 126, in async_start_pairing
    salt, pub_key = await self._async_start_pairing(alias)
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/ble/discovery.py", line 109, in _async_start_pairing
    ff_char = self.client.get_characteristic(
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/ble/bleak.py", line 33, in get_characteristic
    char = self.services.get_service(service_type).get_characteristic(
AttributeError: 'NoneType' object has no attribute 'get_characteristic'
2022-08-07 20:10:00.461 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved (/): ['/org/bluez/hci0/dev_EB_90_D9_1B_93_74', ['org.freedesktop.DBus.Properties', 'org.freedesktop.DBus.Introspectable', 'org.bluez.Device1']]
2022-08-07 20:10:02.117 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_4B_C1_32_65_19_EE): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -92)>}, []]
2022-08-07 20:10:02.144 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_65_8D_B2_E2_C8_6B): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -64)>}, []]
2022-08-07 20:10:02.146 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_5B_45_8D_A0_BA_E8): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -66)>}, []]
2022-08-07 20:10:02.187 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_6C_E4_10_55_9C_32): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -61)>}, []]
2022-08-07 20:10:02.190 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_F2_C5_B6_D0_67_F2): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -88)>}, []]
2022-08-07 20:10:02.193 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_6D_2D_2D_A9_72_5E): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -79)>}, []]
2022-08-07 20:10:02.217 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_40_CB_C0_EA_4A_C9): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -77)>}, []]
2022-08-07 20:10:02.251 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_88_C6_26_4D_68_9A): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -68)>, 'ManufacturerData': <dbus_next.signature.Variant ('a{qv}', {3: <dbus_next.signature.Variant ('ay', b'\x003B\x00\x00\x07\xdcR\x85\x05k/\x88\xc6&Mh\x9a"')>})>}, []]
2022-08-07 20:10:02.287 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_E7_26_0F_69_1C_FC): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -77)>}, []]
2022-08-07 20:10:02.297 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_5D_64_2A_7E_02_B5): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -79)>}, []]
2022-08-07 20:10:02.319 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_54_51_9B_71_FA_0E): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -53)>}, []]
2022-08-07 20:10:02.324 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_25_FF_D0_0E_D4_FC): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -53)>}, []]
2022-08-07 20:10:02.327 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_0E_BF_27_1D_BF_AC): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -66)>}, []]
2022-08-07 20:10:02.338 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_6C_E4_10_55_9C_32): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -63)>}, []]
2022-08-07 20:10:02.375 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_54_3A_D6_6E_E6_99): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -72)>, 'ManufacturerData': <dbus_next.signature.Variant ('a{qv}', {117: <dbus_next.signature.Variant ('ay', b'B\x04\x01\x01oT:\xd6n\xe6\x99V:\xd6n\xe6\x98$\x00\x00\x00\x00\x00\x00')>})>}, []]
2022-08-07 20:10:02.381 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_3C_2B_C0_1F_FB_A7): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -88)>}, []]
2022-08-07 20:10:02.501 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_0E_90_82_0D_7C_37): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -58)>}, []]
2022-08-07 20:10:02.518 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_F0_B3_EC_12_C8_6F): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -92)>}, []]
2022-08-07 20:10:02.538 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_20_18_C6_8D_75_23): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -80)>, 'ManufacturerData': <dbus_next.signature.Variant ('a{qv}', {41197: <dbus_next.signature.Variant ('ay', b'\x00\t\x00\x00\x00\x00\x00u#\x00\x00\x048 \x18\xc6\x8du#\xff\x01')>})>}, []]
2022-08-07 20:10:02.583 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_3C_DC_87_FA_53_59): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -95)>}, []]
2022-08-07 20:10:02.589 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_03_DA_84_0C_66_A0): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -91)>}, []]
2022-08-07 20:10:02.596 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_09_1C_0A_0F_17_32): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -69)>}, []]
2022-08-07 20:10:02.655 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_7E_A7_4B_87_4F_C7): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -94)>}, []]
2022-08-07 20:10:02.657 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_DC_56_E7_59_BE_7E): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -72)>}, []]
2022-08-07 20:10:03.153 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_7E_A7_4B_87_4F_C7): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -92)>}, []]
2022-08-07 20:10:03.218 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_65_8D_B2_E2_C8_6B): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -67)>}, []]
2022-08-07 20:10:03.304 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_EB_E6_CB_BB_A0_52): ['org.bluez.Device1', {'ServicesResolved': <dbus_next.signature.Variant ('b', False)>, 'Connected': <dbus_next.signature.Variant ('b', False)>}, []]
2022-08-07 20:10:03.304 DEBUG (MainThread) [bleak.backends.bluezdbus.client] Device disconnected (/org/bluez/hci0/dev_EB_E6_CB_BB_A0_52)
2022-08-07 20:10:03.305 DEBUG (MainThread) [bleak.backends.bluezdbus.client] _cleanup_all(/org/bluez/hci0/dev_EB_E6_CB_BB_A0_52)
2022-08-07 20:10:03.305 DEBUG (MainThread) [aiohomekit.controller.ble.discovery] Eve Motion C11E (EB:E6:CB:BB:A0:52): Session closed callback

Additional information

No response

@probot-home-assistant
Copy link

homekit_controller documentation
homekit_controller source
(message by IssueLinks)

@probot-home-assistant
Copy link

Hey there @Jc2k, @bdraco, mind taking a look at this issue as it has been labeled with an integration (homekit_controller) you are listed as a code owner for? Thanks!
(message by CodeOwnersMention)

@ahknight
Copy link

I'm seeing the same issue with the Eve Weather outdoor sensor (v1, no screen).

Logger: homeassistant.components.homekit_controller.config_flow
Source: components/homekit_controller/config_flow.py:502 
Integration: HomeKit Controller (documentation, issues) 
First occurred: 10:25:42 AM (7 occurrences) 
Last logged: 10:28:06 AM

Pairing attempt failed with an unhandled exception
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/homekit_controller/config_flow.py", line 502, in async_step_pair
    self.finish_pairing = await discovery.async_start_pairing(self.hkid)
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/ble/client.py", line 61, in _async_wrap
    return await func(*args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/ble/discovery.py", line 126, in async_start_pairing
    salt, pub_key = await self._async_start_pairing(alias)
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/ble/discovery.py", line 109, in _async_start_pairing
    ff_char = self.client.get_characteristic(
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/ble/bleak.py", line 33, in get_characteristic
    char = self.services.get_service(service_type).get_characteristic(
AttributeError: 'NoneType' object has no attribute 'get_characteristic'

@ahknight
Copy link

I updated the Eve Weather (2015) firmware with the Eve app to 2.1.2 (809) and then tried again in Home Assistant (after unpairing/resetting the device). Same error.

@creedda
Copy link

creedda commented Aug 12, 2022

Seeing the same issue with my eve motion as well. Eve Water Guards work fine.

@bdraco
Copy link
Member

bdraco commented Aug 15, 2022

2022.8.5 won't fix it, but it should give a better error which might help figure out whats wrong.

@bdraco
Copy link
Member

bdraco commented Aug 15, 2022

It could be Jc2k/aiohomekit#135 but hopefully not since that one is unfixable without a kernel/bluez change

@jsmith79
Copy link
Author

Just thought I would resubmit the log after performing a fresh install of 2022.8.5, bleak and aiohomekit debug.

2022-08-16 17:01:43.628 DEBUG (MainThread) [aiohomekit.controller.ble.discovery] Eve Motion C11E (EB:E6:CB:BB:A0:52): Ensure connected with device EB:E6:CB:BB:A0:52: Eve Motion C11E; rssi=-48
2022-08-16 17:01:43.629 DEBUG (MainThread) [bleak.backends.bluezdbus.client] Connecting to device @ EB:E6:CB:BB:A0:52 with hci0
2022-08-16 17:01:43.805 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_5B_B6_13_9F_50_A4): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -90)>}, []]
2022-08-16 17:01:43.860 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved (/): ['/org/bluez/hci0/dev_4F_84_9D_E1_E6_DC', ['org.freedesktop.DBus.Properties', 'org.freedesktop.DBus.Introspectable', 'org.bluez.Device1']]
2022-08-16 17:01:44.066 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_F2_C5_B6_D0_67_F2): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -74)>}, []]
2022-08-16 17:01:44.228 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_65_8A_CA_37_10_3C): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -82)>}, []]
2022-08-16 17:01:44.230 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_7C_E9_9C_94_E7_43): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -70)>}, []]
2022-08-16 17:01:44.273 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_36_B5_56_26_CA_9C): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -66)>}, []]
2022-08-16 17:01:44.353 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_1C_E0_E2_DF_ED_95): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -94)>}, []]
2022-08-16 17:01:44.405 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_7E_AA_FE_70_4B_23): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -94)>}, []]
2022-08-16 17:01:44.432 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_FB_A7_38_32_81_D2): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -76)>}, []]
2022-08-16 17:01:44.569 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_EB_E6_CB_BB_A0_52): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -50)>}, []]
2022-08-16 17:01:44.572 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_0A_87_69_86_85_93): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -100)>}, []]
2022-08-16 17:01:44.726 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_E7_A7_0D_11_98_1C): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -58)>}, []]
2022-08-16 17:01:44.855 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_FA_2B_E5_D8_8C_0B): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -82)>}, []]
2022-08-16 17:01:44.883 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_5A_88_58_A3_E2_87): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -72)>}, []]
2022-08-16 17:01:44.885 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_15_13_81_6E_A7_67): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -80)>}, []]
2022-08-16 17:01:45.021 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_36_B5_56_26_CA_9C): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -66)>}, []]
2022-08-16 17:01:45.023 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_7E_AA_FE_70_4B_23): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -94)>}, []]
2022-08-16 17:01:45.025 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_2A_B9_89_5C_22_08): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -80)>}, []]
2022-08-16 17:01:45.047 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_5A_88_58_A3_E2_87): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -72)>}, []]
2022-08-16 17:01:45.304 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_52_58_2C_1B_72_02): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -82)>}, []]
2022-08-16 17:01:45.306 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_65_8A_CA_37_10_3C): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -84)>}, []]
2022-08-16 17:01:45.354 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_7E_73_A5_26_9C_22): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -80)>}, []]
2022-08-16 17:01:45.468 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_64_80_DC_DE_D4_6E): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -74)>}, []]
2022-08-16 17:01:45.470 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_5B_B6_13_9F_50_A4): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -76)>}, []]
2022-08-16 17:01:45.514 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_40_8C_FA_CF_3E_8B): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -94)>}, []]
2022-08-16 17:01:45.624 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_08_66_98_8E_64_75): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -70)>}, []]
2022-08-16 17:01:45.828 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_EB_E6_CB_BB_A0_52): ['org.bluez.Device1', {'Connected': <dbus_next.signature.Variant ('b', True)>}, []]
2022-08-16 17:01:45.887 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_EB_E6_CB_BB_A0_52): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -44)>}, []]
2022-08-16 17:01:45.889 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_0F_65_AF_71_4E_81): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -100)>}, []]
2022-08-16 17:01:45.891 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_7C_E9_9C_94_E7_43): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -70)>}, []]
2022-08-16 17:01:45.986 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_D2_D2_CD_85_27_48): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -74)>}, []]
2022-08-16 17:01:46.137 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_52_58_2C_1B_72_02): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -86)>}, []]
2022-08-16 17:01:46.139 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_C7_DF_15_79_0E_C2): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -92)>}, []]
2022-08-16 17:01:46.226 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_0A_87_69_86_85_93): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -98)>}, []]
2022-08-16 17:01:46.228 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_1C_E0_E2_DF_ED_95): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -96)>}, []]
2022-08-16 17:01:46.276 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_25_24_12_B1_E4_C3): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -100)>}, []]
2022-08-16 17:01:46.278 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_1D_AA_74_B4_BF_5B): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -94)>}, []]
2022-08-16 17:01:46.432 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_FB_A7_38_32_81_D2): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -70)>}, []]
2022-08-16 17:01:46.567 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_5F_32_C2_7D_6F_F8): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -82)>}, []]
2022-08-16 17:01:46.569 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_64_80_DC_DE_D4_6E): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -82)>}, []]
2022-08-16 17:01:46.812 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_77_91_80_99_BA_65', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.Device1': {'Address': <dbus_next.signature.Variant ('s', 77:91:80:99:BA:65)>, 'AddressType': <dbus_next.signature.Variant ('s', random)>, 'Alias': <dbus_next.signature.Variant ('s', 77-91-80-99-BA-65)>, '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', -100)>, 'Connected': <dbus_next.signature.Variant ('b', False)>, 'UUIDs': <dbus_next.signature.Variant ('as', [])>, 'Adapter': <dbus_next.signature.Variant ('o', /org/bluez/hci0)>, 'ManufacturerData': <dbus_next.signature.Variant ('a{qv}', {76: <dbus_next.signature.Variant ('ay', b'\x10\x07+\x1b6\x8dK\xe6(')>})>, 'TxPower': <dbus_next.signature.Variant ('n', 8)>, 'ServicesResolved': <dbus_next.signature.Variant ('b', False)>}, 'org.freedesktop.DBus.Properties': {}}]
2022-08-16 17:01:46.855 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_5B_B6_13_9F_50_A4): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -68)>}, []]
2022-08-16 17:01:46.860 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved (/): ['/org/bluez/hci0/dev_78_EC_D5_5F_6B_BC', ['org.freedesktop.DBus.Properties', 'org.freedesktop.DBus.Introspectable', 'org.bluez.Device1']]
2022-08-16 17:01:46.935 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_7E_AA_FE_70_4B_23): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -92)>}, []]
2022-08-16 17:01:46.987 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_7E_73_A5_26_9C_22): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -78)>}, []]
2022-08-16 17:01:46.989 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_2A_B9_89_5C_22_08): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -80)>}, []]
2022-08-16 17:01:47.062 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_23_CE_FE_49_1E_DC): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -82)>}, []]
2022-08-16 17:01:47.110 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_EB_E6_CB_BB_A0_52): ['org.bluez.Device1', {'ServicesResolved': <dbus_next.signature.Variant ('b', True)>}, []]
2022-08-16 17:01:47.112 ERROR (MainThread) [homeassistant.components.homekit_controller.config_flow] Pairing attempt failed with an unhandled exception
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/components/homekit_controller/config_flow.py", line 502, in async_step_pair
self.finish_pairing = await discovery.async_start_pairing(self.hkid)
File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/ble/client.py", line 65, in _async_wrap
return await func(*args, **kwargs)
File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/ble/discovery.py", line 137, in async_start_pairing
salt, pub_key = await self._async_start_pairing(alias)
File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/ble/discovery.py", line 119, in async_start_pairing
ff_char = self.client.get_characteristic(
File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/ble/bleak.py", line 37, in get_characteristic
raise ValueError(
ValueError: Service 00000055-0000-1000-8000-0026BB765291 not found, available services: []
2022-08-16 17:01:47.568 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_40_8C_FA_CF_3E_8B): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -94)>}, []]
2022-08-16 17:01:48.074 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_5E_2C_E6_85_7F_B5', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.Device1': {'Address': <dbus_next.signature.Variant ('s', 5E:2C:E6:85:7F:B5)>, 'AddressType': <dbus_next.signature.Variant ('s', random)>, 'Alias': <dbus_next.signature.Variant ('s', 5E-2C-E6-85-7F-B5)>, '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', -96)>, 'Connected': <dbus_next.signature.Variant ('b', False)>, 'UUIDs': <dbus_next.signature.Variant ('as', [])>, 'Adapter': <dbus_next.signature.Variant ('o', /org/bluez/hci0)>, 'ManufacturerData': <dbus_next.signature.Variant ('a{qv}', {76: <dbus_next.signature.Variant ('ay', b'\x07\x19\x01\x0f \x00\xf5\x8f\x01\x00\x04\x9f\xf6\x1cR\x8c\x9a\xf7\xe6\xb5\xc3Pj\xa2u\xf8
')>})>, 'ServicesResolved': <dbus_next.signature.Variant ('b', False)>}, 'org.freedesktop.DBus.Properties': {}}]
2022-08-16 17:01:48.078 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_65_8A_CA_37_10_3C): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -82)>}, []]
2022-08-16 17:01:48.082 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_52_58_2C_1B_72_02): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -82)>}, []]
2022-08-16 17:01:48.245 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_5B_B6_13_9F_50_A4): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -90)>}, []]
2022-08-16 17:01:48.402 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_E4_FB_8F_96_22_C4): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -80)>}, []]
2022-08-16 17:01:48.743 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_4A_FC_78_19_82_B5): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -98)>}, []]
2022-08-16 17:01:48.745 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_0A_87_69_86_85_93): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -100)>}, []]
2022-08-16 17:01:48.823 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_0F_65_AF_71_4E_81): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -100)>}, []]
2022-08-16 17:01:48.859 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved (/): ['/org/bluez/hci0/dev_EB_CB_72_81_4A_0D', ['org.freedesktop.DBus.Properties', 'org.freedesktop.DBus.Introspectable', 'org.bluez.Device1']]
2022-08-16 17:01:48.875 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_65_8A_CA_37_10_3C): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -84)>}, []]
2022-08-16 17:01:48.962 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_75_36_CB_7D_B2_61', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.Device1': {'Address': <dbus_next.signature.Variant ('s', 75:36:CB:7D:B2:61)>, 'AddressType': <dbus_next.signature.Variant ('s', random)>, 'Alias': <dbus_next.signature.Variant ('s', 75-36-CB-7D-B2-61)>, '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', -102)>, 'Connected': <dbus_next.signature.Variant ('b', False)>, 'UUIDs': <dbus_next.signature.Variant ('as', [])>, 'Adapter': <dbus_next.signature.Variant ('o', /org/bluez/hci0)>, 'ManufacturerData': <dbus_next.signature.Variant ('a{qv}', {76: <dbus_next.signature.Variant ('ay', b'\x10\x06%\x1e\x9br>(')>})>, 'TxPower': <dbus_next.signature.Variant ('n', 6)>, 'ServicesResolved': <dbus_next.signature.Variant ('b', False)>}, 'org.freedesktop.DBus.Properties': {}}]
2022-08-16 17:01:48.965 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_50_7A_CE_6F_47_02): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -50)>}, []]
2022-08-16 17:01:49.194 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_7C_E9_9C_94_E7_43): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -70)>}, []]
2022-08-16 17:01:49.282 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_23_CE_FE_49_1E_DC): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -86)>}, []]
2022-08-16 17:01:49.373 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_1C_E0_E2_DF_ED_95): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -98)>}, []]
2022-08-16 17:01:49.586 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_65_8A_CA_37_10_3C): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -84)>}, []]
2022-08-16 17:01:49.588 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_88_C6_26_42_40_F8): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -102)>}, []]
2022-08-16 17:01:50.088 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_64_80_DC_DE_D4_6E): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -84)>}, []]
2022-08-16 17:01:50.090 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_25_24_12_B1_E4_C3): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -100)>}, []]
2022-08-16 17:01:50.092 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_7E_AA_FE_70_4B_23): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -94)>}, []]
2022-08-16 17:01:50.263 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_36_B5_56_26_CA_9C): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -74)>}, []]
2022-08-16 17:01:50.392 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_E7_A7_0D_11_98_1C): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -66)>}, []]
2022-08-16 17:01:50.455 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_FB_A7_38_32_81_D2): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -70)>}, []]
2022-08-16 17:01:50.502 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_40_8C_FA_CF_3E_8B): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -94)>}, []]
2022-08-16 17:01:50.591 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_4A_FC_78_19_82_B5): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -100)>}, []]
2022-08-16 17:01:50.594 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_E7_A7_0D_11_98_1C): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -60)>}, []]
2022-08-16 17:01:50.599 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_7E_73_A5_26_9C_22): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -72)>}, []]
2022-08-16 17:01:50.715 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_5A_88_58_A3_E2_87): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -76)>}, []]
2022-08-16 17:01:50.893 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_5B_FF_42_6A_5C_18): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -94)>}, []]
2022-08-16 17:01:50.895 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_10_BF_BD_63_A0_EF): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -100)>}, []]
2022-08-16 17:01:50.978 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_64_80_DC_DE_D4_6E): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -78)>}, []]
2022-08-16 17:01:50.980 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_C4_70_49_0D_0B_55): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -72)>}, []]
2022-08-16 17:01:51.036 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_6E_B8_6B_1C_9A_A6', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.Device1': {'Address': <dbus_next.signature.Variant ('s', 6E:B8:6B:1C:9A:A6)>, 'AddressType': <dbus_next.signature.Variant ('s', random)>, 'Alias': <dbus_next.signature.Variant ('s', 6E-B8-6B-1C-9A-A6)>, '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', -96)>, 'Connected': <dbus_next.signature.Variant ('b', False)>, 'UUIDs': <dbus_next.signature.Variant ('as', [])>, 'Adapter': <dbus_next.signature.Variant ('o', /org/bluez/hci0)>, 'ManufacturerData': <dbus_next.signature.Variant ('a{qv}', {76: <dbus_next.signature.Variant ('ay', b'\x10\x06\x7f\x1eb\xc5\\x8f')>})>, 'TxPower': <dbus_next.signature.Variant ('n', 7)>, 'ServicesResolved': <dbus_next.signature.Variant ('b', False)>}, 'org.freedesktop.DBus.Properties': {}}]
2022-08-16 17:01:51.038 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_5B_B6_13_9F_50_A4): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -90)>}, []]
2022-08-16 17:01:51.045 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_FB_A7_38_32_81_D2): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -78)>}, []]
2022-08-16 17:01:51.472 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_15_13_81_6E_A7_67): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -64)>}, []]
2022-08-16 17:01:51.523 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_1D_AA_74_B4_BF_5B): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -98)>}, []]
2022-08-16 17:01:51.653 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_0A_87_69_86_85_93): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -98)>}, []]
2022-08-16 17:01:51.844 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_7C_E9_9C_94_E7_43): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -70)>, 'ManufacturerData': <dbus_next.signature.Variant ('a{qv}', {76: <dbus_next.signature.Variant ('ay', b'\x10\x07z\x1f\x01\xf6\x0e\xf4\x08')>})>}, []]
2022-08-16 17:01:52.024 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_08_66_98_8E_64_75): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -68)>}, []]
2022-08-16 17:01:52.110 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_DA_EC_19_28_1B_E2', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.Device1': {'Address': <dbus_next.signature.Variant ('s', DA:EC:19:28:1B:E2)>, 'AddressType': <dbus_next.signature.Variant ('s', random)>, 'Alias': <dbus_next.signature.Variant ('s', DA-EC-19-28-1B-E2)>, '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', -102)>, 'Connected': <dbus_next.signature.Variant ('b', False)>, 'UUIDs': <dbus_next.signature.Variant ('as', [])>, 'Adapter': <dbus_next.signature.Variant ('o', /org/bluez/hci0)>, 'ManufacturerData': <dbus_next.signature.Variant ('a{qv}', {76: <dbus_next.signature.Variant ('ay', b'\x12\x02\x00\x00')>})>, 'ServicesResolved': <dbus_next.signature.Variant ('b', False)>}, 'org.freedesktop.DBus.Properties': {}}]
2022-08-16 17:01:52.283 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_7E_AA_FE_70_4B_23): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -94)>}, []]
2022-08-16 17:01:52.285 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_10_BF_BD_63_A0_EF): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -100)>}, []]
2022-08-16 17:01:52.608 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_7E_AA_FE_70_4B_23): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -92)>}, []]
2022-08-16 17:01:52.610 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_0F_65_AF_71_4E_81): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -102)>}, []]
2022-08-16 17:01:52.972 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_40_8C_FA_CF_3E_8B): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -92)>}, []]
2022-08-16 17:01:52.974 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_C4_70_49_0D_0B_55): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -72)>}, []]
2022-08-16 17:01:53.103 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_36_B5_56_26_CA_9C): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -66)>}, []]
2022-08-16 17:01:53.364 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_40_8C_FA_CF_3E_8B): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -94)>}, []]
2022-08-16 17:01:53.653 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_6F_84_C0_5D_F7_0F): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -100)>}, []]
2022-08-16 17:01:53.655 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_0A_87_69_86_85_93): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -98)>}, []]
2022-08-16 17:01:53.858 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved (/): ['/org/bluez/hci0/dev_6C_47_26_47_B6_11', ['org.freedesktop.DBus.Properties', 'org.freedesktop.DBus.Introspectable', 'org.bluez.Device1']]
2022-08-16 17:01:53.865 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_08_66_98_8E_64_75): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -64)>}, []]
2022-08-16 17:01:53.913 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_5F_32_C2_7D_6F_F8): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -78)>}, []]
2022-08-16 17:01:54.422 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_E4_FB_8F_96_22_C4): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -88)>}, []]
2022-08-16 17:01:54.426 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_73_61_20_83_25_E7', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.Device1': {'Address': <dbus_next.signature.Variant ('s', 73:61:20:83:25:E7)>, 'AddressType': <dbus_next.signature.Variant ('s', random)>, 'Alias': <dbus_next.signature.Variant ('s', 73-61-20-83-25-E7)>, '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', -88)>, 'Connected': <dbus_next.signature.Variant ('b', False)>, 'UUIDs': <dbus_next.signature.Variant ('as', [])>, 'Adapter': <dbus_next.signature.Variant ('o', /org/bluez/hci0)>, 'ManufacturerData': <dbus_next.signature.Variant ('a{qv}', {76: <dbus_next.signature.Variant ('ay', b'\x10\x06k\x1e5\x0b>\xd6')>})>, 'TxPower': <dbus_next.signature.Variant ('n', 8)>, 'ServicesResolved': <dbus_next.signature.Variant ('b', False)>}, 'org.freedesktop.DBus.Properties': {}}]
2022-08-16 17:01:54.463 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_36_B5_56_26_CA_9C): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -64)>}, []]
2022-08-16 17:01:54.767 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded (/): ['/org/bluez/hci0/dev_60_6A_24_6C_2B_D8', {'org.freedesktop.DBus.Introspectable': {}, 'org.bluez.Device1': {'Address': <dbus_next.signature.Variant ('s', 60:6A:24:6C:2B:D8)>, 'AddressType': <dbus_next.signature.Variant ('s', random)>, 'Alias': <dbus_next.signature.Variant ('s', 60-6A-24-6C-2B-D8)>, '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', -102)>, 'Connected': <dbus_next.signature.Variant ('b', False)>, 'UUIDs': <dbus_next.signature.Variant ('as', [])>, 'Adapter': <dbus_next.signature.Variant ('o', /org/bluez/hci0)>, 'ManufacturerData': <dbus_next.signature.Variant ('a{qv}', {76: <dbus_next.signature.Variant ('ay', b'\x10\x07<\x1f\xd8R\xee\xfdX')>})>, 'TxPower': <dbus_next.signature.Variant ('n', 6)>, 'ServicesResolved': <dbus_next.signature.Variant ('b', False)>}, 'org.freedesktop.DBus.Properties': {}}]
2022-08-16 17:01:54.769 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_7E_AA_FE_70_4B_23): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -92)>}, []]
2022-08-16 17:01:55.039 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_68_B2_50_D5_75_B3): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -92)>}, []]
2022-08-16 17:01:55.087 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_5F_32_C2_7D_6F_F8): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -78)>}, []]
2022-08-16 17:01:55.089 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_50_7A_CE_6F_47_02): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -48)>}, []]
2022-08-16 17:01:55.138 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_D2_D2_CD_85_27_48): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -70)>}, []]
2022-08-16 17:01:55.140 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_15_13_81_6E_A7_67): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -78)>}, []]
2022-08-16 17:01:55.304 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_7C_E9_9C_94_E7_43): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -70)>, 'ManufacturerData': <dbus_next.signature.Variant ('a{qv}', {76: <dbus_next.signature.Variant ('ay', b'\x10\x07z\x1f\x01\xf6\x0e\xf0\x08')>})>}, []]
2022-08-16 17:01:55.307 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_40_8C_FA_CF_3E_8B): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -94)>}, []]
2022-08-16 17:01:55.309 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_5A_88_58_A3_E2_87): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -76)>}, []]
2022-08-16 17:01:55.473 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_1D_AA_74_B4_BF_5B): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -98)>}, []]
2022-08-16 17:01:55.636 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_F2_C5_B6_D0_67_F2): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -76)>}, []]
2022-08-16 17:01:55.765 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_5B_B6_13_9F_50_A4): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -88)>}, []]
2022-08-16 17:01:55.859 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved (/): ['/org/bluez/hci0/dev_02_7B_4C_D5_C8_D5', ['org.freedesktop.DBus.Properties', 'org.freedesktop.DBus.Introspectable', 'org.bluez.Device1']]
2022-08-16 17:01:55.893 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_36_B5_56_26_CA_9C): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -66)>}, []]
2022-08-16 17:01:55.926 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_E7_A7_0D_11_98_1C): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -66)>}, []]
2022-08-16 17:01:55.973 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_1C_E0_E2_DF_ED_95): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -94)>}, []]
2022-08-16 17:01:55.975 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_EB_E6_CB_BB_A0_52): ['org.bluez.Device1', {'ServicesResolved': <dbus_next.signature.Variant ('b', False)>, 'Connected': <dbus_next.signature.Variant ('b', False)>}, []]
2022-08-16 17:01:55.976 DEBUG (MainThread) [bleak.backends.bluezdbus.client] Device disconnected (/org/bluez/hci0/dev_EB_E6_CB_BB_A0_52)
2022-08-16 17:01:55.976 DEBUG (MainThread) [bleak.backends.bluezdbus.client] _cleanup_all(/org/bluez/hci0/dev_EB_E6_CB_BB_A0_52)
2022-08-16 17:01:55.976 DEBUG (MainThread) [aiohomekit.controller.ble.discovery] Eve Motion C11E (EB:E6:CB:BB:A0:52): Session closed callback; rssi=-48

@bdraco
Copy link
Member

bdraco commented Aug 16, 2022

It sure looks like Jc2k/aiohomekit#135 as it appears bluez can't resolve the services on the device.

ValueError: Service 00000055-0000-1000-8000-0026BB765291 not found, available services: []

@bdraco
Copy link
Member

bdraco commented Aug 16, 2022

bluez/bluez#316
bluez/bluez#30

These issues look related

@bdraco
Copy link
Member

bdraco commented Sep 6, 2022

Can you try 2022.9.x beta? I have an eve motion v1 pairing successfully on that version

@WizBangCrash
Copy link
Contributor

I have an Eve Energy (firmware: 2.1.2) and I am getting the same error on 2022.9.0
2022-09-08 16:03:24.056 ERROR (MainThread) [homeassistant.components.homekit_controller.config_flow] Pairing attempt failed with an unhandled exception Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/homekit_controller/config_flow.py", line 479, in async_step_pair self.finish_pairing = await discovery.async_start_pairing(self.hkid) File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/ble/client.py", line 75, in _async_wrap return await func(*args, **kwargs) File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/ble/discovery.py", line 138, in async_start_pairing salt, pub_key = await self._async_start_pairing(alias) File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/ble/discovery.py", line 120, in _async_start_pairing ff_char = self.client.get_characteristic( File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/ble/bleak.py", line 91, in get_characteristic raise ValueError( ValueError: Service 00000055-0000-1000-8000-0026BB765291 not found, available services: []

@virtualm2000
Copy link

I have successfully paired Eve Energy, Room, Thermo but there is something specific with Eve devices.
I have managed to replicate the problem but I can't figure out why is it happening.

Screenshot 2022-09-16 at 11 57 02

Screenshot 2022-09-16 at 11 59 43

I have 4 Eve Thermo that I can pair but not always from first try.
First I reset the device, it gets picked up by HA but then when pairing before pin prompt I get the dreaded ValueError: Service 00000055-0000-1000-8000-0026BB765291 not found, available services: [].
However bluetoothctl in container shows that the device actually has 00000055-0000-1000-8000-0026BB765291 present. So I thought about just rebooting the device not reseting it. It takes a few tries but I get the pin prompt with no error and pairing is successful and I can control the device with no issues. Everything works well until I restart the HA or I add another Eve Thermo. After that the device is not available with ValueError: Service 00000055-0000-1000-8000-0026BB765291 not found, available services: []. If I choose one device and reboot it (remove battery) then reload the integration it works again for a while.
The other Eve devices like Door and Degree work with no issues.

My setup: HA 2022.9.4 in kubernetes with Bluez 5.65 on host (Ubuntu Jammy) and 5.64 in container

@Mariuss811
Copy link

I got the same issue on 2022.9.4

Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/components/homekit_controller/config_flow.py", line 479, in async_step_pair
self.finish_pairing = await discovery.async_start_pairing(self.hkid)
File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/ble/client.py", line 75, in _async_wrap
return await func(*args, **kwargs)
File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/ble/discovery.py", line 139, in async_start_pairing
salt, pub_key = await self._async_start_pairing(alias)
File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/ble/discovery.py", line 121, in _async_start_pairing
ff_char = self.client.get_characteristic(
File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/ble/bleak.py", line 91, in get_characteristic
raise ValueError(
ValueError: Service 00000055-0000-1000-8000-0026BB765291 not found, available services: []

@bdraco
Copy link
Member

bdraco commented Sep 17, 2022

Jc2k/aiohomekit#135

@virtualm2000
Copy link

Jc2k/aiohomekit#135

It is strange it works fine sometimes.

@bdraco
Copy link
Member

bdraco commented Sep 17, 2022

Jc2k/aiohomekit#135

It is strange it works fine sometimes.

That's super annoying right? Unfortunately there isn't an api to tell bluez to try to resolve services again so we are stuck on this one.

@virtualm2000
Copy link

I have tested with a macos install and it works perfectly. I gave up on BlueZ, although the latest kernel 5.19 made the pairing process a bit better still after a while the devices would go undetected.

Now the issue I have is finding a long range bluetooth adapter compatible with mac. Any ideas?

Thank you!

@bdraco
Copy link
Member

bdraco commented Oct 29, 2022

We added some retry logic to try again if the service resolution fails in 2022.11.x. That might help but it really should be fixed at the bluez level as this is only a workaround for that

@creedda
Copy link

creedda commented Oct 29, 2022

Thank you for continuing to keep an eye on the problem even though the issue is with a dependency. Hopefully it will get fixed at the bluez level someday…

@bdraco bdraco mentioned this issue Nov 5, 2022
19 tasks
@github-actions github-actions bot locked and limited conversation to collaborators Dec 5, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

8 participants