core
core copied to clipboard
Retrying setup: hci0 (49:02:91:02:89:88): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress
The problem
Further to https://github.com/home-assistant/core/issues/83673#issuecomment-1356622120 i am on the latest core but i still have an issue with my BT device.
Logger: homeassistant.config_entries
Source: config_entries.py:1113
First occurred: 11:17:54 PM (2 occurrences)
Last logged: 11:19:59 PM
Config entry '49:02:91:02:89:88' for bluetooth integration not ready yet: hci0 (49:02:91:02:89:88): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress; Retrying in background
Only way i can resolve on a temp basis is by going to terminal and running "bluetoothct1, power off, power on, scan on" and even that doesn't work sometimes
What version of Home Assistant Core has the issue?
2022.12.7
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
Bluetooth
Link to integration documentation on our website
No response
Diagnostics information
2022-12-19 23:13:29.122 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration eufy_security which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2022-12-19 23:13:29.125 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration whatspie which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2022-12-19 23:13:29.130 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration tapo_control which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2022-12-19 23:13:29.132 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration hildebrandglow_dcc which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2022-12-19 23:13:29.134 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration tapo which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2022-12-19 23:13:29.136 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2022-12-19 23:13:29.138 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration sonoff which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2022-12-19 23:13:29.141 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration localtuya which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2022-12-19 23:13:33.861 WARNING (MainThread) [homeassistant.config_entries] Config entry '49:02:91:02:89:88' for bluetooth integration not ready yet: hci0 (49:02:91:02:89:88): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress; Retrying in background
2022-12-19 23:13:36.785 ERROR (SyncWorker_7) [homeassistant.components.command_line] Command failed (with return code 1): cat /sys/class/thermal/thermal_zone0/temp
2022-12-19 23:13:42.206 ERROR (MainThread) [homeassistant.components.life360] Amma A: Lost Connection: This user has lost connection to Life360. Visit our troubleshooting guide to help them reconnect.
2022-12-19 23:13:42.208 ERROR (MainThread) [homeassistant.components.life360] Abba: Lost Connection: This user has lost connection to Life360. Visit our troubleshooting guide to help them reconnect.
2022-12-19 23:13:42.209 ERROR (MainThread) [homeassistant.components.life360] Amma: Lost Connection: This user has lost connection to Life360. Visit our troubleshooting guide to help them reconnect.
2022-12-19 23:14:37.049 ERROR (SyncWorker_8) [homeassistant.components.command_line] Command failed (with return code 1): cat /sys/class/thermal/thermal_zone0/temp
2022-12-19 23:15:37.049 ERROR (SyncWorker_6) [homeassistant.components.command_line] Command failed (with return code 1): cat /sys/class/thermal/thermal_zone0/temp
2022-12-19 23:16:37.050 ERROR (SyncWorker_0) [homeassistant.components.command_line] Command failed (with return code 1): cat /sys/class/thermal/thermal_zone0/temp
2022-12-19 23:17:37.050 ERROR (SyncWorker_4) [homeassistant.components.command_line] Command failed (with return code 1): cat /sys/class/thermal/thermal_zone0/temp
2022-12-19 23:17:54.643 WARNING (MainThread) [homeassistant.config_entries] Config entry '49:02:91:02:89:88' for bluetooth integration not ready yet: hci0 (49:02:91:02:89:88): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress; Retrying in background
2022-12-19 23:18:37.052 ERROR (SyncWorker_2) [homeassistant.components.command_line] Command failed (with return code 1): cat /sys/class/thermal/thermal_zone0/temp
2022-12-19 23:19:37.053 ERROR (SyncWorker_6) [homeassistant.components.command_line] Command failed (with return code 1): cat /sys/class/thermal/thermal_zone0/temp
2022-12-19 23:19:59.645 WARNING (MainThread) [homeassistant.config_entries] Config entry '49:02:91:02:89:88' for bluetooth integration not ready yet: hci0 (49:02:91:02:89:88): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress; Retrying in background
2022-12-19 23:20:37.054 ERROR (SyncWorker_3) [homeassistant.components.command_line] Command failed (with return code 1): cat /sys/class/thermal/thermal_zone0/temp
2022-12-19 23:21:37.055 ERROR (SyncWorker_3) [homeassistant.components.command_line] Command failed (with return code 1): cat /sys/class/thermal/thermal_zone0/temp
2022-12-19 23:22:37.055 ERROR (SyncWorker_6) [homeassistant.components.command_line] Command failed (with return code 1): cat /sys/class/thermal/thermal_zone0/temp
2022-12-19 23:23:37.056 ERROR (SyncWorker_3) [homeassistant.components.command_line] Command failed (with return code 1): cat /sys/class/thermal/thermal_zone0/temp
2022-12-19 23:24:37.058 ERROR (SyncWorker_8) [homeassistant.components.command_line] Command failed (with return code 1): cat /sys/class/thermal/thermal_zone0/temp
2022-12-19 23:25:24.295 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [49:02:91:02:89:88] successfully turned back ON
2022-12-19 23:25:37.059 ERROR (SyncWorker_5) [homeassistant.components.command_line] Command failed (with return code 1): cat /sys/class/thermal/thermal_zone0/temp
2022-12-19 23:25:54.600 WARNING (MainThread) [homeassistant.config_entries] Config entry '49:02:91:02:89:88' for bluetooth integration not ready yet: hci0 (49:02:91:02:89:88): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress; Retrying in background
2022-12-19 23:25:58.116 WARNING (MainThread) [homeassistant.config_entries] Config entry '49:02:91:02:89:88' for bluetooth integration not ready yet: hci0 (49:02:91:02:89:88): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress; Retrying in background
2022-12-19 23:26:37.059 ERROR (SyncWorker_0) [homeassistant.components.command_line] Command failed (with return code 1): cat /sys/class/thermal/thermal_zone0/temp
2022-12-19 23:27:29.197 WARNING (MainThread) [homeassistant.config_entries] Config entry '49:02:91:02:89:88' for bluetooth integration not ready yet: hci0 (49:02:91:02:89:88): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress; Retrying in background
2022-12-19 23:27:37.060 ERROR (SyncWorker_1) [homeassistant.components.command_line] Command failed (with return code 1): cat /sys/class/thermal/thermal_zone0/temp
2022-12-19 23:27:45.804 DEBUG (MainThread) [homeassistant.components.bluetooth.scanner] Initializing bluetooth scanner with {'detection_callback': <bound method HaScanner._async_detection_callback of <homeassistant.components.bluetooth.scanner.HaScanner object at 0x7f1fd9d35000>>, 'scanning_mode': 'active', 'adapter': 'hci0'}
2022-12-19 23:27:45.806 DEBUG (MainThread) [homeassistant.components.bluetooth.scanner] hci0 (49:02:91:02:89:88): Starting bluetooth discovery attempt: (1/3)
2022-12-19 23:27:45.831 DEBUG (MainThread) [homeassistant.components.bluetooth.scanner] hci0 (49:02:91:02:89:88): adapter stopped responding; executing reset
2022-12-19 23:27:45.832 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Attempting to recover bluetooth adapter hci0 with mac address 49:02:91:02:89:88
2022-12-19 23:27:45.832 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Attempting to power cycle bluetooth adapter hci0 [49:02:91:02:89:88]
2022-12-19 23:27:45.834 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding cmd_code as type CmdCode
2022-12-19 23:27:45.835 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding controller_idx as type Controller
2022-12-19 23:27:45.836 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding param_len as type ParamLen
2022-12-19 23:27:45.840 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2022-12-19 23:27:45.843 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2022-12-19 23:27:45.853 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2022-12-19 23:27:45.854 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding command_opcode as type CmdCode
2022-12-19 23:27:45.855 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding status as type Status
2022-12-19 23:27:45.858 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding num_controllers as type IntUL
2022-12-19 23:27:45.859 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_index[i] as type IntUL
2022-12-19 23:27:45.861 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket Read: <event_code=CommandCompleteEvent, controller_idx=65535, param_len=7> <command_opcode=ReadControllerIndexList, status=Success> <num_controllers=1, controller_index[i]=[0]>
2022-12-19 23:27:45.863 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding cmd_code as type CmdCode
2022-12-19 23:27:45.866 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding controller_idx as type Controller
2022-12-19 23:27:45.867 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding param_len as type ParamLen
2022-12-19 23:27:45.869 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2022-12-19 23:27:45.870 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2022-12-19 23:27:45.875 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2022-12-19 23:27:45.876 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding command_opcode as type CmdCode
2022-12-19 23:27:45.879 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding status as type Status
2022-12-19 23:27:45.880 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding address as type Address
2022-12-19 23:27:45.881 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding bluetooth_version as type IntUL
2022-12-19 23:27:45.881 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding manufacturer as type IntUL
2022-12-19 23:27:45.883 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding supported_settings as type IntUL
2022-12-19 23:27:45.883 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding current_settings as type CurrentSettings
2022-12-19 23:27:45.886 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding class_of_device as type IntUL
2022-12-19 23:27:45.887 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding name as type Name
2022-12-19 23:27:45.890 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding short_name as type IntUL
2022-12-19 23:27:45.890 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket Read: <event_code=CommandCompleteEvent, controller_idx=0, param_len=283> <command_opcode=ReadControllerInformation, status=Success> <address=49:02:91:02:89:88, bluetooth_version=4, manufacturer=15, supported_settings=69887, current_settings={Powered: True, Connectable: False, FastConnectable: False, Discoverable: False, Bondable: False, LinkLevelSecurity: False, SecureSimplePairing: True, BREDR: True, HighSpeed: False, LowEnergy: False, Advertising: False, SecureConnections: False, DebugKeys: False, Privacy: False, ControllerConfiguration: False, StaticAddress: False, PHYConfiguration: False, WidebandSpeech: False}, class_of_device=2883584, name=b'homeassistant', short_name=0>
2022-12-19 23:27:45.891 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Response(header=<event_code=CommandCompleteEvent, controller_idx=0, param_len=283>, event_frame=<command_opcode=ReadControllerInformation, status=Success>, cmd_response_frame=<address=49:02:91:02:89:88, bluetooth_version=4, manufacturer=15, supported_settings=69887, current_settings={Powered: True, Connectable: False, FastConnectable: False, Discoverable: False, Bondable: False, LinkLevelSecurity: False, SecureSimplePairing: True, BREDR: True, HighSpeed: False, LowEnergy: False, Advertising: False, SecureConnections: False, DebugKeys: False, Privacy: False, ControllerConfiguration: False, StaticAddress: False, PHYConfiguration: False, WidebandSpeech: False}, class_of_device=2883584, name=b'homeassistant', short_name=0>)
2022-12-19 23:27:45.892 DEBUG (MainThread) [bluetooth_auto_recovery.recover] hci0 (49:02:91:02:89:88) idx is 0
2022-12-19 23:27:45.895 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Attempting to power cycle bluetooth adapter hci0 [49:02:91:02:89:88]
2022-12-19 23:27:45.895 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding cmd_code as type CmdCode
2022-12-19 23:27:45.899 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding controller_idx as type Controller
2022-12-19 23:27:45.900 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding param_len as type ParamLen
2022-12-19 23:27:45.901 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2022-12-19 23:27:45.901 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2022-12-19 23:27:45.902 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2022-12-19 23:27:45.902 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding command_opcode as type CmdCode
2022-12-19 23:27:45.904 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding status as type Status
2022-12-19 23:27:45.904 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding address as type Address
2022-12-19 23:27:45.905 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding bluetooth_version as type IntUL
2022-12-19 23:27:45.906 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding manufacturer as type IntUL
2022-12-19 23:27:45.906 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding supported_settings as type IntUL
2022-12-19 23:27:45.907 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding current_settings as type CurrentSettings
2022-12-19 23:27:45.908 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding class_of_device as type IntUL
2022-12-19 23:27:45.908 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding name as type Name
2022-12-19 23:27:45.909 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding short_name as type IntUL
2022-12-19 23:27:45.909 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket Read: <event_code=CommandCompleteEvent, controller_idx=0, param_len=283> <command_opcode=ReadControllerInformation, status=Success> <address=49:02:91:02:89:88, bluetooth_version=4, manufacturer=15, supported_settings=69887, current_settings={Powered: True, Connectable: False, FastConnectable: False, Discoverable: False, Bondable: False, LinkLevelSecurity: False, SecureSimplePairing: True, BREDR: True, HighSpeed: False, LowEnergy: False, Advertising: False, SecureConnections: False, DebugKeys: False, Privacy: False, ControllerConfiguration: False, StaticAddress: False, PHYConfiguration: False, WidebandSpeech: False}, class_of_device=2883584, name=b'homeassistant', short_name=0>
2022-12-19 23:27:45.909 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Current power state of bluetooth adapter is ON.
2022-12-19 23:27:45.910 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding powered as type IntUL
2022-12-19 23:27:45.910 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding cmd_code as type CmdCode
2022-12-19 23:27:45.910 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding controller_idx as type Controller
2022-12-19 23:27:45.910 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding param_len as type ParamLen
2022-12-19 23:27:45.911 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2022-12-19 23:27:45.911 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2022-12-19 23:27:45.912 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2022-12-19 23:27:45.912 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding command_opcode as type CmdCode
2022-12-19 23:27:45.912 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding status as type Status
2022-12-19 23:27:45.912 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding current_settings as type CurrentSettings
2022-12-19 23:27:45.912 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket Read: <event_code=CommandCompleteEvent, controller_idx=0, param_len=7> <command_opcode=SetPowered, status=Success> <current_settings={Powered: False, Connectable: False, FastConnectable: False, Discoverable: False, Bondable: False, LinkLevelSecurity: False, SecureSimplePairing: True, BREDR: True, HighSpeed: False, LowEnergy: False, Advertising: False, SecureConnections: False, DebugKeys: False, Privacy: False, ControllerConfiguration: False, StaticAddress: False, PHYConfiguration: False, WidebandSpeech: False}>
2022-12-19 23:27:45.913 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding cmd_code as type CmdCode
2022-12-19 23:27:45.913 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding controller_idx as type Controller
2022-12-19 23:27:45.914 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding param_len as type ParamLen
2022-12-19 23:27:45.914 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2022-12-19 23:27:45.914 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2022-12-19 23:27:45.914 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2022-12-19 23:27:45.916 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding class_of_device as type IntUL
2022-12-19 23:27:45.916 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket read <event_code=ClassOfDeviceChangedEvent, controller_idx=0, param_len=3> <class_of_device=0>
2022-12-19 23:27:45.917 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2022-12-19 23:27:45.917 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2022-12-19 23:27:45.917 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2022-12-19 23:27:45.917 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding command_opcode as type CmdCode
2022-12-19 23:27:45.919 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding status as type Status
2022-12-19 23:27:45.919 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding address as type Address
2022-12-19 23:27:45.919 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding bluetooth_version as type IntUL
2022-12-19 23:27:45.919 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding manufacturer as type IntUL
2022-12-19 23:27:45.920 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding supported_settings as type IntUL
2022-12-19 23:27:45.920 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding current_settings as type CurrentSettings
2022-12-19 23:27:45.920 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding class_of_device as type IntUL
2022-12-19 23:27:45.920 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding name as type Name
2022-12-19 23:27:45.920 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding short_name as type IntUL
2022-12-19 23:27:45.921 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket Read: <event_code=CommandCompleteEvent, controller_idx=0, param_len=283> <command_opcode=ReadControllerInformation, status=Success> <address=49:02:91:02:89:88, bluetooth_version=4, manufacturer=15, supported_settings=69887, current_settings={Powered: False, Connectable: False, FastConnectable: False, Discoverable: False, Bondable: False, LinkLevelSecurity: False, SecureSimplePairing: True, BREDR: True, HighSpeed: False, LowEnergy: False, Advertising: False, SecureConnections: False, DebugKeys: False, Privacy: False, ControllerConfiguration: False, StaticAddress: False, PHYConfiguration: False, WidebandSpeech: False}, class_of_device=2883584, name=b'homeassistant', short_name=0>
2022-12-19 23:27:45.921 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding powered as type IntUL
2022-12-19 23:27:45.921 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding cmd_code as type CmdCode
2022-12-19 23:27:45.924 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding controller_idx as type Controller
2022-12-19 23:27:45.924 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding param_len as type ParamLen
2022-12-19 23:27:45.974 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2022-12-19 23:27:45.974 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2022-12-19 23:27:45.974 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2022-12-19 23:27:45.975 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding class_of_device as type IntUL
2022-12-19 23:27:45.975 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket read <event_code=ClassOfDeviceChangedEvent, controller_idx=0, param_len=3> <class_of_device=2883584>
2022-12-19 23:27:45.977 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2022-12-19 23:27:45.978 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2022-12-19 23:27:45.978 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2022-12-19 23:27:45.978 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding command_opcode as type CmdCode
2022-12-19 23:27:45.978 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding status as type Status
2022-12-19 23:27:45.978 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding current_settings as type CurrentSettings
2022-12-19 23:27:45.979 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket Read: <event_code=CommandCompleteEvent, controller_idx=0, param_len=7> <command_opcode=SetPowered, status=Success> <current_settings={Powered: True, Connectable: False, FastConnectable: False, Discoverable: False, Bondable: False, LinkLevelSecurity: False, SecureSimplePairing: True, BREDR: True, HighSpeed: False, LowEnergy: False, Advertising: False, SecureConnections: False, DebugKeys: False, Privacy: False, ControllerConfiguration: False, StaticAddress: False, PHYConfiguration: False, WidebandSpeech: False}>
2022-12-19 23:27:45.979 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding cmd_code as type CmdCode
2022-12-19 23:27:45.980 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding controller_idx as type Controller
2022-12-19 23:27:45.980 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding param_len as type ParamLen
2022-12-19 23:27:45.981 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2022-12-19 23:27:45.981 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2022-12-19 23:27:45.982 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2022-12-19 23:27:45.982 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding command_opcode as type CmdCode
2022-12-19 23:27:45.982 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding status as type Status
2022-12-19 23:27:45.982 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding address as type Address
2022-12-19 23:27:45.982 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding bluetooth_version as type IntUL
2022-12-19 23:27:45.983 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding manufacturer as type IntUL
2022-12-19 23:27:45.983 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding supported_settings as type IntUL
2022-12-19 23:27:45.983 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding current_settings as type CurrentSettings
2022-12-19 23:27:45.983 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding class_of_device as type IntUL
2022-12-19 23:27:45.983 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding name as type Name
2022-12-19 23:27:45.984 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding short_name as type IntUL
2022-12-19 23:27:45.984 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket Read: <event_code=CommandCompleteEvent, controller_idx=0, param_len=283> <command_opcode=ReadControllerInformation, status=Success> <address=49:02:91:02:89:88, bluetooth_version=4, manufacturer=15, supported_settings=69887, current_settings={Powered: True, Connectable: False, FastConnectable: False, Discoverable: False, Bondable: False, LinkLevelSecurity: False, SecureSimplePairing: True, BREDR: True, HighSpeed: False, LowEnergy: False, Advertising: False, SecureConnections: False, DebugKeys: False, Privacy: False, ControllerConfiguration: False, StaticAddress: False, PHYConfiguration: False, WidebandSpeech: False}, class_of_device=2883584, name=b'homeassistant', short_name=0>
2022-12-19 23:27:45.984 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Power state of bluetooth adapter hci0 [49:02:91:02:89:88] is ON after power cycle
2022-12-19 23:27:47.488 DEBUG (MainThread) [homeassistant.components.bluetooth.scanner] hci0 (49:02:91:02:89:88): adapter reset result: True
2022-12-19 23:27:47.488 DEBUG (MainThread) [homeassistant.components.bluetooth.scanner] hci0 (49:02:91:02:89:88): Starting bluetooth discovery attempt: (2/3)
2022-12-19 23:27:47.495 DEBUG (MainThread) [homeassistant.components.bluetooth.scanner] hci0 (49:02:91:02:89:88): BleakError while starting bluetooth; attempt: (2/3): [org.bluez.Error.InProgress] Operation already in progress
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/components/bluetooth/scanner.py", line 229, in _async_start
await self.scanner.start() # type: ignore[no-untyped-call]
File "/usr/local/lib/python3.10/site-packages/bleak/__init__.py", line 156, in start
await self._backend.start()
File "/usr/local/lib/python3.10/site-packages/bleak/backends/bluezdbus/scanner.py", line 191, in start
self._stop = await manager.active_scan(
File "/usr/local/lib/python3.10/site-packages/bleak/backends/bluezdbus/manager.py", line 368, in active_scan
assert_reply(reply)
File "/usr/local/lib/python3.10/site-packages/bleak/backends/bluezdbus/utils.py", line 20, in assert_reply
raise BleakDBusError(reply.error_name, reply.body)
bleak.exc.BleakDBusError: [org.bluez.Error.InProgress] Operation already in progress
2022-12-19 23:27:58.006 DEBUG (MainThread) [homeassistant.components.bluetooth] Rediscovered adapters: {'hci0': {'address': '49:02:91:02:89:88', 'sw_version': 'homeassistant', 'hw_version': 'usb:v1D6Bp0246d053F', 'passive_scan': False, 'manufacturer': 'Broadcom Corp', 'product': 'BCM2046B1', 'vendor_id': '0a5c', 'product_id': '2046'}}
2022-12-19 23:27:58.008 DEBUG (MainThread) [homeassistant.components.bluetooth.scanner] Initializing bluetooth scanner with {'detection_callback': <bound method HaScanner._async_detection_callback of <homeassistant.components.bluetooth.scanner.HaScanner object at 0x7f1fdc93b220>>, 'scanning_mode': 'active', 'adapter': 'hci0'}
2022-12-19 23:27:58.009 DEBUG (MainThread) [homeassistant.components.bluetooth.scanner] hci0 (49:02:91:02:89:88): Starting bluetooth discovery attempt: (1/3)
2022-12-19 23:27:58.018 DEBUG (MainThread) [homeassistant.components.bluetooth.scanner] hci0 (49:02:91:02:89:88): adapter stopped responding; executing reset
2022-12-19 23:27:58.019 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Attempting to recover bluetooth adapter hci0 with mac address 49:02:91:02:89:88
2022-12-19 23:27:58.019 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Attempting to power cycle bluetooth adapter hci0 [49:02:91:02:89:88]
2022-12-19 23:27:58.023 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding cmd_code as type CmdCode
2022-12-19 23:27:58.024 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding controller_idx as type Controller
2022-12-19 23:27:58.024 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding param_len as type ParamLen
2022-12-19 23:27:58.025 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2022-12-19 23:27:58.026 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2022-12-19 23:27:58.026 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2022-12-19 23:27:58.027 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding command_opcode as type CmdCode
2022-12-19 23:27:58.027 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding status as type Status
2022-12-19 23:27:58.027 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding num_controllers as type IntUL
2022-12-19 23:27:58.028 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_index[i] as type IntUL
2022-12-19 23:27:58.028 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket Read: <event_code=CommandCompleteEvent, controller_idx=65535, param_len=7> <command_opcode=ReadControllerIndexList, status=Success> <num_controllers=1, controller_index[i]=[0]>
2022-12-19 23:27:58.029 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding cmd_code as type CmdCode
2022-12-19 23:27:58.029 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding controller_idx as type Controller
2022-12-19 23:27:58.030 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding param_len as type ParamLen
2022-12-19 23:27:58.032 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2022-12-19 23:27:58.032 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2022-12-19 23:27:58.032 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2022-12-19 23:27:58.033 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding command_opcode as type CmdCode
2022-12-19 23:27:58.033 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding status as type Status
2022-12-19 23:27:58.033 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding address as type Address
2022-12-19 23:27:58.034 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding bluetooth_version as type IntUL
2022-12-19 23:27:58.034 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding manufacturer as type IntUL
2022-12-19 23:27:58.035 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding supported_settings as type IntUL
2022-12-19 23:27:58.035 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding current_settings as type CurrentSettings
2022-12-19 23:27:58.036 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding class_of_device as type IntUL
2022-12-19 23:27:58.036 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding name as type Name
2022-12-19 23:27:58.036 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding short_name as type IntUL
2022-12-19 23:27:58.037 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket Read: <event_code=CommandCompleteEvent, controller_idx=0, param_len=283> <command_opcode=ReadControllerInformation, status=Success> <address=49:02:91:02:89:88, bluetooth_version=4, manufacturer=15, supported_settings=69887, current_settings={Powered: True, Connectable: False, FastConnectable: False, Discoverable: False, Bondable: False, LinkLevelSecurity: False, SecureSimplePairing: True, BREDR: True, HighSpeed: False, LowEnergy: False, Advertising: False, SecureConnections: False, DebugKeys: False, Privacy: False, ControllerConfiguration: False, StaticAddress: False, PHYConfiguration: False, WidebandSpeech: False}, class_of_device=2883584, name=b'homeassistant', short_name=0>
2022-12-19 23:27:58.038 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Response(header=<event_code=CommandCompleteEvent, controller_idx=0, param_len=283>, event_frame=<command_opcode=ReadControllerInformation, status=Success>, cmd_response_frame=<address=49:02:91:02:89:88, bluetooth_version=4, manufacturer=15, supported_settings=69887, current_settings={Powered: True, Connectable: False, FastConnectable: False, Discoverable: False, Bondable: False, LinkLevelSecurity: False, SecureSimplePairing: True, BREDR: True, HighSpeed: False, LowEnergy: False, Advertising: False, SecureConnections: False, DebugKeys: False, Privacy: False, ControllerConfiguration: False, StaticAddress: False, PHYConfiguration: False, WidebandSpeech: False}, class_of_device=2883584, name=b'homeassistant', short_name=0>)
2022-12-19 23:27:58.038 DEBUG (MainThread) [bluetooth_auto_recovery.recover] hci0 (49:02:91:02:89:88) idx is 0
2022-12-19 23:27:58.046 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Attempting to power cycle bluetooth adapter hci0 [49:02:91:02:89:88]
2022-12-19 23:27:58.046 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding cmd_code as type CmdCode
2022-12-19 23:27:58.046 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding controller_idx as type Controller
2022-12-19 23:27:58.047 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding param_len as type ParamLen
2022-12-19 23:27:58.047 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2022-12-19 23:27:58.048 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2022-12-19 23:27:58.048 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2022-12-19 23:27:58.048 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding command_opcode as type CmdCode
2022-12-19 23:27:58.049 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding status as type Status
2022-12-19 23:27:58.049 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding address as type Address
2022-12-19 23:27:58.049 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding bluetooth_version as type IntUL
2022-12-19 23:27:58.050 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding manufacturer as type IntUL
2022-12-19 23:27:58.050 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding supported_settings as type IntUL
2022-12-19 23:27:58.050 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding current_settings as type CurrentSettings
2022-12-19 23:27:58.051 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding class_of_device as type IntUL
2022-12-19 23:27:58.051 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding name as type Name
2022-12-19 23:27:58.051 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding short_name as type IntUL
2022-12-19 23:27:58.052 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket Read: <event_code=CommandCompleteEvent, controller_idx=0, param_len=283> <command_opcode=ReadControllerInformation, status=Success> <address=49:02:91:02:89:88, bluetooth_version=4, manufacturer=15, supported_settings=69887, current_settings={Powered: True, Connectable: False, FastConnectable: False, Discoverable: False, Bondable: False, LinkLevelSecurity: False, SecureSimplePairing: True, BREDR: True, HighSpeed: False, LowEnergy: False, Advertising: False, SecureConnections: False, DebugKeys: False, Privacy: False, ControllerConfiguration: False, StaticAddress: False, PHYConfiguration: False, WidebandSpeech: False}, class_of_device=2883584, name=b'homeassistant', short_name=0>
2022-12-19 23:27:58.054 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Current power state of bluetooth adapter is ON.
2022-12-19 23:27:58.054 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding powered as type IntUL
2022-12-19 23:27:58.054 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding cmd_code as type CmdCode
2022-12-19 23:27:58.055 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding controller_idx as type Controller
2022-12-19 23:27:58.055 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding param_len as type ParamLen
2022-12-19 23:27:58.057 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2022-12-19 23:27:58.057 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2022-12-19 23:27:58.059 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2022-12-19 23:27:58.059 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding command_opcode as type CmdCode
2022-12-19 23:27:58.059 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding status as type Status
2022-12-19 23:27:58.060 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding current_settings as type CurrentSettings
2022-12-19 23:27:58.060 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket Read: <event_code=CommandCompleteEvent, controller_idx=0, param_len=7> <command_opcode=SetPowered, status=Success> <current_settings={Powered: False, Connectable: False, FastConnectable: False, Discoverable: False, Bondable: False, LinkLevelSecurity: False, SecureSimplePairing: True, BREDR: True, HighSpeed: False, LowEnergy: False, Advertising: False, SecureConnections: False, DebugKeys: False, Privacy: False, ControllerConfiguration: False, StaticAddress: False, PHYConfiguration: False, WidebandSpeech: False}>
2022-12-19 23:27:58.062 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding cmd_code as type CmdCode
2022-12-19 23:27:58.062 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding controller_idx as type Controller
2022-12-19 23:27:58.062 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding param_len as type ParamLen
2022-12-19 23:27:58.063 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2022-12-19 23:27:58.063 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2022-12-19 23:27:58.063 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2022-12-19 23:27:58.064 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding class_of_device as type IntUL
2022-12-19 23:27:58.064 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket read <event_code=ClassOfDeviceChangedEvent, controller_idx=0, param_len=3> <class_of_device=0>
2022-12-19 23:27:58.064 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2022-12-19 23:27:58.065 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2022-12-19 23:27:58.065 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2022-12-19 23:27:58.065 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding command_opcode as type CmdCode
2022-12-19 23:27:58.065 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding status as type Status
2022-12-19 23:27:58.066 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding address as type Address
2022-12-19 23:27:58.066 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding bluetooth_version as type IntUL
2022-12-19 23:27:58.066 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding manufacturer as type IntUL
2022-12-19 23:27:58.066 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding supported_settings as type IntUL
2022-12-19 23:27:58.067 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding current_settings as type CurrentSettings
2022-12-19 23:27:58.067 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding class_of_device as type IntUL
2022-12-19 23:27:58.067 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding name as type Name
2022-12-19 23:27:58.067 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding short_name as type IntUL
2022-12-19 23:27:58.068 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket Read: <event_code=CommandCompleteEvent, controller_idx=0, param_len=283> <command_opcode=ReadControllerInformation, status=Success> <address=49:02:91:02:89:88, bluetooth_version=4, manufacturer=15, supported_settings=69887, current_settings={Powered: False, Connectable: False, FastConnectable: False, Discoverable: False, Bondable: False, LinkLevelSecurity: False, SecureSimplePairing: True, BREDR: True, HighSpeed: False, LowEnergy: False, Advertising: False, SecureConnections: False, DebugKeys: False, Privacy: False, ControllerConfiguration: False, StaticAddress: False, PHYConfiguration: False, WidebandSpeech: False}, class_of_device=2883584, name=b'homeassistant', short_name=0>
2022-12-19 23:27:58.070 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding powered as type IntUL
2022-12-19 23:27:58.070 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding cmd_code as type CmdCode
2022-12-19 23:27:58.072 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding controller_idx as type Controller
2022-12-19 23:27:58.072 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding param_len as type ParamLen
2022-12-19 23:27:58.120 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2022-12-19 23:27:58.121 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2022-12-19 23:27:58.122 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2022-12-19 23:27:58.122 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding class_of_device as type IntUL
2022-12-19 23:27:58.122 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket read <event_code=ClassOfDeviceChangedEvent, controller_idx=0, param_len=3> <class_of_device=2883584>
2022-12-19 23:27:58.127 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2022-12-19 23:27:58.127 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2022-12-19 23:27:58.127 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2022-12-19 23:27:58.127 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding command_opcode as type CmdCode
2022-12-19 23:27:58.128 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding status as type Status
2022-12-19 23:27:58.129 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding current_settings as type CurrentSettings
2022-12-19 23:27:58.132 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket Read: <event_code=CommandCompleteEvent, controller_idx=0, param_len=7> <command_opcode=SetPowered, status=Success> <current_settings={Powered: True, Connectable: False, FastConnectable: False, Discoverable: False, Bondable: False, LinkLevelSecurity: False, SecureSimplePairing: True, BREDR: True, HighSpeed: False, LowEnergy: False, Advertising: False, SecureConnections: False, DebugKeys: False, Privacy: False, ControllerConfiguration: False, StaticAddress: False, PHYConfiguration: False, WidebandSpeech: False}>
2022-12-19 23:27:58.133 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding cmd_code as type CmdCode
2022-12-19 23:27:58.134 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding controller_idx as type Controller
2022-12-19 23:27:58.134 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding param_len as type ParamLen
2022-12-19 23:27:58.135 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2022-12-19 23:27:58.136 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2022-12-19 23:27:58.137 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2022-12-19 23:27:58.138 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding command_opcode as type CmdCode
2022-12-19 23:27:58.138 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding status as type Status
2022-12-19 23:27:58.139 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding address as type Address
2022-12-19 23:27:58.139 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding bluetooth_version as type IntUL
2022-12-19 23:27:58.140 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding manufacturer as type IntUL
2022-12-19 23:27:58.140 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding supported_settings as type IntUL
2022-12-19 23:27:58.141 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding current_settings as type CurrentSettings
2022-12-19 23:27:58.142 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding class_of_device as type IntUL
2022-12-19 23:27:58.143 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding name as type Name
2022-12-19 23:27:58.143 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding short_name as type IntUL
2022-12-19 23:27:58.144 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket Read: <event_code=CommandCompleteEvent, controller_idx=0, param_len=283> <command_opcode=ReadControllerInformation, status=Success> <address=49:02:91:02:89:88, bluetooth_version=4, manufacturer=15, supported_settings=69887, current_settings={Powered: True, Connectable: False, FastConnectable: False, Discoverable: False, Bondable: False, LinkLevelSecurity: False, SecureSimplePairing: True, BREDR: True, HighSpeed: False, LowEnergy: False, Advertising: False, SecureConnections: False, DebugKeys: False, Privacy: False, ControllerConfiguration: False, StaticAddress: False, PHYConfiguration: False, WidebandSpeech: False}, class_of_device=2883584, name=b'homeassistant', short_name=0>
2022-12-19 23:27:58.146 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Power state of bluetooth adapter hci0 [49:02:91:02:89:88] is ON after power cycle
2022-12-19 23:27:59.648 DEBUG (MainThread) [homeassistant.components.bluetooth.scanner] hci0 (49:02:91:02:89:88): adapter reset result: True
2022-12-19 23:27:59.648 DEBUG (MainThread) [homeassistant.components.bluetooth.scanner] hci0 (49:02:91:02:89:88): Starting bluetooth discovery attempt: (2/3)
2022-12-19 23:27:59.654 DEBUG (MainThread) [homeassistant.components.bluetooth.scanner] hci0 (49:02:91:02:89:88): BleakError while starting bluetooth; attempt: (2/3): [org.bluez.Error.InProgress] Operation already in progress
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/components/bluetooth/scanner.py", line 229, in _async_start
await self.scanner.start() # type: ignore[no-untyped-call]
File "/usr/local/lib/python3.10/site-packages/bleak/__init__.py", line 156, in start
await self._backend.start()
File "/usr/local/lib/python3.10/site-packages/bleak/backends/bluezdbus/scanner.py", line 191, in start
self._stop = await manager.active_scan(
File "/usr/local/lib/python3.10/site-packages/bleak/backends/bluezdbus/manager.py", line 368, in active_scan
assert_reply(reply)
File "/usr/local/lib/python3.10/site-packages/bleak/backends/bluezdbus/utils.py", line 20, in assert_reply
raise BleakDBusError(reply.error_name, reply.body)
bleak.exc.BleakDBusError: [org.bluez.Error.InProgress] Operation already in progress
2022-12-19 23:27:59.655 WARNING (MainThread) [homeassistant.config_entries] Config entry '49:02:91:02:89:88' for bluetooth integration not ready yet: hci0 (49:02:91:02:89:88): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress; Retrying in background
Example YAML snippet
No response
Anything in the logs that might be useful for us?
No response
Additional information
No response
Hey there @bdraco, mind taking a look at this issue as it has been labeled with an integration (bluetooth
) you are listed as a code owner for? Thanks!
Code owner commands
Code owners of bluetooth
can trigger bot actions by commenting:
-
@home-assistant close
Closes the issue. -
@home-assistant rename Awesome new title
Change the title of the issue. -
@home-assistant reopen
Reopen the issue. -
@home-assistant unassign bluetooth
Removes the current integration label and assignees on the issue, add the integration domain after the command.
(message by CodeOwnersMention)
bluetooth documentation bluetooth source (message by IssueLinks)
What's the solution, I am having the same problem. There are no comments as to how to fix this ?
What's the solution, I am having the same problem. There are no comments as to how to fix this ?
@ausfas The resolution for this is on another post you have commented on, but the quick answer is check this list and see if your Bluetooth device is on here https://www.home-assistant.io/integrations/bluetooth/ If you find your Bluetooth device on the list see if it has CSR in brackets next to it.
If your device is not on the list, then you will need to replace your device with one from the list preferably one that has CSR.
I'm trying to use integrated bluetooth of RPi4. My config.txt file on RPi4 has following:
enable_uart=1
#To disable blutooth uncomment below
#dtoverlay=disable-bt
dtoverlay=disable-wifi
#To enable bluetooth uncomment below
#dtoverlay=miniuart-bt
There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.
I'm having this same issue. My rpi bt just suddenly stopped working with this same error. Ice tried deleting and reading the bt integration but it worked for an hour then did this again. On 2023.4.6 (or whatever latest as of this post)
it does it to me too, what's up with that?
2023-04-25 05:34:23.066 WARNING (SyncWorker_3) [homeassistant.loader] We found a custom integration auto_backup which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant 2023-04-25 05:34:23.074 WARNING (SyncWorker_3) [homeassistant.loader] We found a custom integration hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant 2023-04-25 05:34:23.079 WARNING (SyncWorker_3) [homeassistant.loader] We found a custom integration browser_mod which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant 2023-04-25 05:34:47.726 WARNING (MainThread) [homeassistant.setup] Setup of hassio is taking over 10 seconds. 2023-04-25 05:34:47.773 WARNING (MainThread) [homeassistant.setup] Setup of bluetooth is taking over 10 seconds. 2023-04-25 05:34:47.786 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /supervisor/options request 2023-04-25 05:34:52.820 WARNING (MainThread) [hass_nabucasa.cloud_api] Fetched https://alexa-api.nabucasa.com/access_token (400) 2023-04-25 05:34:57.290 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:34:57.721 WARNING (MainThread) [homeassistant.config_entries] Config entry 'B8:27:EB:67:3A:4D' for bluetooth integration not ready yet: hci0 (B8:27:EB:67:3A:4D): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress; Retrying in background 2023-04-25 05:34:59.067 WARNING (MainThread) [homeassistant.helpers.entity] Updating state for binary_sensor.remote_ui (<class 'homeassistant.components.cloud.binary_sensor.CloudRemoteBinary'>) took 0.828 seconds. Please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue+label%3A%22integration%3A+cloud%22 2023-04-25 05:35:35.820 WARNING (MainThread) [homeassistant.config_entries] Config entry 'LG webOS TV B637' for homekit_controller integration not ready yet: Timeout while waiting for connection to device 10.0.0.17:35650; Retrying in background 2023-04-25 05:35:37.035 ERROR (MainThread) [homeassistant.components.esphome.dashboard] Error requesting ESPHome Dashboard data: Cannot connect to host 127.0.0.1:62463 ssl:default [Connect call failed ('127.0.0.1', 62463)] 2023-04-25 05:35:47.251 ERROR (MainThread) [homeassistant.util.logging] Exception in setup_update_entity when dispatching 'esphome_63a13b874f2d71a17d8a7ba47e9fbd59_on_device_update': () Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/esphome/update.py", line 56, in setup_update_entity async_add_entities([ESPHomeUpdateEntity(entry_data, dashboard)]) File "/usr/src/homeassistant/homeassistant/components/esphome/update.py", line 90, in init if coordinator.supports_update and not self._device_info.has_deep_sleep: File "/usr/src/homeassistant/homeassistant/components/esphome/dashboard.py", line 91, in supports_update raise RuntimeError("Data needs to be loaded first") RuntimeError: Data needs to be loaded first
2023-04-25 05:35:47.600 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:36:03.597 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:36:39.167 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:37:07.670 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:37:21.641 WARNING (MainThread) [homeassistant.config_entries] Config entry 'B8:27:EB:67:3A:4D' for bluetooth integration not ready yet: hci0 (B8:27:EB:67:3A:4D): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress; Retrying in background 2023-04-25 05:37:32.078 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:37:47.325 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:38:12.471 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:38:49.036 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:38:49.057 WARNING (MainThread) [homeassistant.config_entries] Config entry 'B8:27:EB:67:3A:4D' for bluetooth integration not ready yet: hci0 (B8:27:EB:67:3A:4D): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress; Retrying in background 2023-04-25 05:38:59.323 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:39:14.509 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:39:39.707 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:40:24.939 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:40:51.075 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:40:53.468 WARNING (MainThread) [homeassistant.config_entries] Config entry 'B8:27:EB:67:3A:4D' for bluetooth integration not ready yet: hci0 (B8:27:EB:67:3A:4D): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress; Retrying in background 2023-04-25 05:41:03.888 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:41:19.317 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:41:44.817 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:42:30.297 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:43:55.559 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:45:20.827 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:46:46.153 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:48:11.486 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:49:36.820 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:51:02.126 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:52:27.321 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:53:52.659 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:55:17.941 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:56:43.484 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:58:08.715 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 05:59:34.033 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:00:59.508 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:02:02.381 ERROR (MainThread) [frontend.js.latest.202304111] https://kz0gr76j4jvfmkuj1968fw0alujc57fd.ui.nabu.casa/lovelace/default_view:0:0 Uncaught 2023-04-25 06:02:22.215 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:02:22.237 WARNING (MainThread) [homeassistant.config_entries] Config entry 'B8:27:EB:67:3A:4D' for bluetooth integration not ready yet: hci0 (B8:27:EB:67:3A:4D): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress; Retrying in background 2023-04-25 06:02:27.272 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:02:27.293 WARNING (MainThread) [homeassistant.config_entries] Config entry 'B8:27:EB:67:3A:4D' for bluetooth integration not ready yet: hci0 (B8:27:EB:67:3A:4D): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress; Retrying in background 2023-04-25 06:02:37.457 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:02:52.833 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:03:18.155 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:04:03.449 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:04:27.216 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:04:27.239 WARNING (MainThread) [homeassistant.config_entries] Config entry 'B8:27:EB:67:3A:4D' for bluetooth integration not ready yet: hci0 (B8:27:EB:67:3A:4D): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress; Retrying in background 2023-04-25 06:04:37.425 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:04:52.662 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:05:18.203 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:05:27.267 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:05:27.288 WARNING (MainThread) [homeassistant.config_entries] Config entry 'B8:27:EB:67:3A:4D' for bluetooth integration not ready yet: hci0 (B8:27:EB:67:3A:4D): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress; Retrying in background 2023-04-25 06:05:37.426 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:05:52.825 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:06:18.341 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:07:03.900 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:08:29.283 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:09:54.714 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:10:35.838 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /addons/5c53de3b_esphome/changelog request 2023-04-25 06:10:35.846 WARNING (MainThread) [homeassistant.components.hassio] Could not fetch changelog for 5c53de3b_esphome: 2023-04-25 06:11:19.836 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:12:45.117 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:14:10.528 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:15:35.748 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:17:01.063 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:18:26.220 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:19:51.543 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:21:17.051 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:22:42.525 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:24:07.638 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:25:32.961 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:26:58.222 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:28:23.464 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:29:48.651 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:31:14.028 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:32:39.538 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:34:04.752 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:35:30.062 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:36:55.406 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:38:20.562 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:39:45.931 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:41:11.478 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:42:36.800 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:44:01.996 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:45:27.519 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:46:52.701 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:48:17.900 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:49:43.369 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:51:08.492 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:52:33.629 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:53:58.801 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:55:23.953 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:56:49.208 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:58:14.424 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 06:59:39.558 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:01:04.868 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:02:30.157 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:03:55.709 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:05:20.864 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:06:46.339 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:08:11.603 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:09:37.041 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:11:02.454 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:12:27.974 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:13:53.174 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:15:18.725 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:15:47.025 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:15:47.050 WARNING (MainThread) [homeassistant.config_entries] Config entry 'B8:27:EB:67:3A:4D' for bluetooth integration not ready yet: hci0 (B8:27:EB:67:3A:4D): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress; Retrying in background 2023-04-25 07:15:57.477 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:16:12.687 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:16:38.127 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:17:23.436 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:18:48.602 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:20:13.987 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:21:39.518 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:23:04.838 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:24:30.143 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:25:55.506 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:27:20.750 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:28:28.808 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:28:28.868 WARNING (MainThread) [homeassistant.config_entries] Config entry 'B8:27:EB:67:3A:4D' for bluetooth integration not ready yet: hci0 (B8:27:EB:67:3A:4D): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress; Retrying in background 2023-04-25 07:28:39.013 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:28:54.197 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:29:19.463 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:30:04.855 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:31:27.527 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:31:27.548 WARNING (MainThread) [homeassistant.config_entries] Config entry 'B8:27:EB:67:3A:4D' for bluetooth integration not ready yet: hci0 (B8:27:EB:67:3A:4D): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress; Retrying in background 2023-04-25 07:31:37.817 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:31:53.162 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:32:18.407 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:33:03.799 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:34:29.165 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:35:54.268 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:37:19.398 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:38:44.513 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:40:09.747 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:41:35.186 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:43:00.694 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:44:26.188 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:45:51.674 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:47:16.918 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:48:42.125 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:50:07.481 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:51:32.773 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:52:57.917 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:54:23.238 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:55:48.346 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:57:13.662 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 07:58:38.807 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 08:00:04.067 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 08:01:29.616 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 08:02:54.909 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 08:04:20.125 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 08:05:45.525 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 08:06:07.360 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 08:06:07.381 WARNING (MainThread) [homeassistant.config_entries] Config entry 'B8:27:EB:67:3A:4D' for bluetooth integration not ready yet: hci0 (B8:27:EB:67:3A:4D): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress; Retrying in background 2023-04-25 08:06:17.727 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 08:06:32.942 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 08:06:58.055 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 08:07:43.213 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [B8:27:EB:67:3A:4D] could not be reset due to timeout 2023-04-25 08:07:43.220 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Executing USB reset for Bluetooth adapter hci0 2023-04-25 08:07:43.229 DEBUG (MainThread) [bluetooth_auto_recovery.recover] hci0 is not a USB devices while attempting USB reset: ttyAMA0 is not a USB device 2023-04-25 08:07:43.231 DEBUG (MainThread) [homeassistant.components.bluetooth.scanner] hci0 (B8:27:EB:67:3A:4D): adapter reset result: False 2023-04-25 08:07:43.232 DEBUG (MainThread) [homeassistant.components.bluetooth.scanner] hci0 (B8:27:EB:67:3A:4D): Starting bluetooth discovery attempt: (2/3) 2023-04-25 08:07:43.243 DEBUG (MainThread) [homeassistant.components.bluetooth.scanner] hci0 (B8:27:EB:67:3A:4D): BleakError while starting bluetooth; attempt: (2/3): [org.bluez.Error.InProgress] Operation already in progress Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/bluetooth/scanner.py", line 223, in _async_start await self.scanner.start() # type: ignore[no-untyped-call] File "/usr/local/lib/python3.10/site-packages/bleak/init.py", line 182, in start await self._backend.start() File "/usr/local/lib/python3.10/site-packages/bleak/backends/bluezdbus/scanner.py", line 191, in start self._stop = await manager.active_scan( File "/usr/local/lib/python3.10/site-packages/bleak/backends/bluezdbus/manager.py", line 368, in active_scan assert_reply(reply) File "/usr/local/lib/python3.10/site-packages/bleak/backends/bluezdbus/utils.py", line 22, in assert_reply raise BleakDBusError(reply.error_name, reply.body) bleak.exc.BleakDBusError: [org.bluez.Error.InProgress] Operation already in progress
I'm having the same issue with the built-in BT of the Raspberry Pi CM4 on my HA Yellow.
[EDIT]: The issue seams to stop once I configure it to only scan passively. But once I reverse the config, the issue comes back immediately.
Home Assistant 2023.5.0 Supervisor 2023.04.1 Operating System 10.1
Same issue on RP3
There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.
I still get this error
There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.
Still not solved
Still not solved, have this on my Raspberry Pi CM4 on the HA Yellow!
I'm having the same issue with the built-in BT of the Raspberry Pi CM4 on my HA Yellow.
[EDIT]: The issue seams to stop once I configure it to only scan passively. But once I reverse the config, the issue comes back immediately.
Home Assistant 2023.5.0 Supervisor 2023.04.1 Operating System 10.1
This is the same experience I just had as well, only on a Raspberry Pi 3 (32-bit). Core: 2024.1.6 Supervisor: 2023.12.1 Operating System: 11.4
Its likely you have an integration blocking the event loop
- Install profiler integration https://my.home-assistant.io/redirect/config_flow_start/?domain=profiler
- Enable asyncio debug service as soon as possible after startup https://www.home-assistant.io/integrations/profiler/#service-profilerset_asyncio_debug
- Watch logs for RuntimeError: Non-thread-safe operation and long asyncio delays
- Download and post logs with full trace
For 2024.5.x and later Home Assistant debug mode can also be enabled in configuration.yaml
homeassistant:
debug: true
Since we haven't heard back from the OP, and this looks like a duplicate of #92379, I'm going to close this issue
It does look like there is something else going on with the OP's system that is causing instability. If you do come back to this issue, please follow the following guide to identify the source
https://community.home-assistant.io/t/2024-5-tracking-down-instability-issues-caused-by-integrations/724441