bluetooth integration constant state of initializing / retrying setup (bluetooth is broken with some adapters on newer linux kernels, kernel must be manually patched, workaround is to switch to ESPHome proxies instead) #92379

vlape · 2023-05-02T22:55:49Z

Mod Issue Summary - Read First

See https://lore.kernel.org/linux-bluetooth/[email protected]/T/#mb094e06d495879436ce9a8722ad7ad87527ea74b

A summary:

Bluetooth initialization is unreliable/broken on newer linux kernels for a large sample of adapters
No fixes are available without patching the kernel and it will likely be a LONG time before debian updates the kernel, if you want to manually compile and patch your kernel, see https://lore.kernel.org/linux-bluetooth/CABBYNZ+5RMqNVMyYKi+gOVaV+K6k8Z-C37KnfGa=qRUORc3dWg@mail.gmail.com/ Use proper fix for Bluetooth LE advertisement stall (#2598) operating-system#2714
Newer Home Assistant OS has some patches that solves the problem for some adapters so be sure you have the latest HAOS: Bluetooth failing after upgrade to HAOS 10 on Raspberry Pi operating-system#2485 Bluetooth failing after upgrade to HAOS 10 on Intel Bluetooth hardware operating-system#2535
- The recommended workaround if you can't run HAOS or patch the kernel manually is to use an ESPHome proxy instead https://esphome.github.io/bluetooth-proxies/

The problem

Bluetooth integration in perpetual state of initializing / retrying setup.
Deleting integration, restarting HA and configuring after auto discovered, several times, does not resolve.

What version of Home Assistant Core has the issue?

core-2023.4.6

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

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

Diagnostics information

home-assistant_bluetooth_2023-05-02T22-28-03.303Z.log

Example YAML snippet

No response

Anything in the logs that might be useful for us?

Retrying setup: hci0 (XXXXX): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress

Logger: bluetooth_auto_recovery.recover
Source: components/bluetooth/util.py:78
First occurred: 5:36:41 PM (28 occurrences)
Last logged: 5:52:42 PM

Bluetooth adapter hci0 [XXXXXXXX] could not be reset due to timeout


Logger: homeassistant.config_entries
Source: config_entries.py:1242
First occurred: 5:44:58 PM (4 occurrences)
Last logged: 5:51:51 PM

Config entry 'XXXXX' for bluetooth integration not ready yet: hci0 (XXXXX): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress; Retrying in background

Additional information

Home Assistant Yellow

System Information

version	core-2023.4.6
installation_type	Home Assistant OS
dev	false
hassio	true
docker	true
user	root
virtualenv	false
python_version	3.10.10
os_name	Linux
os_version	6.1.21-v8
arch	aarch64
timezone	America/Chicago
config_dir	/config

Home Assistant Community Store

GitHub API	ok
GitHub Content	ok
GitHub Web	ok
GitHub API Calls Remaining	4929
Installed Version	1.32.1
Stage	running
Available Repositories	1278
Downloaded Repositories	10

Home Assistant Cloud

logged_in	true
subscription_expiration	May 3, 2023 at 7:00 PM
relayer_connected	true
relayer_region	us-east-1
remote_enabled	true
remote_connected	true
alexa_enabled	false
google_enabled	false
remote_server	us-east-1-7.ui.nabu.casa
can_reach_cert_server	ok
can_reach_cloud_auth	ok
can_reach_cloud	ok

Home Assistant Supervisor

host_os	Home Assistant OS 10.1
update_channel	stable
supervisor_version	supervisor-2023.04.1
agent_version	1.5.1
docker_version	23.0.3
disk_total	234.0 GB
disk_used	9.6 GB
healthy	true
supported	true
board	yellow
supervisor_api	ok
version_api	ok
installed_addons	Mosquitto broker (6.2.1), Studio Code Server (5.5.7), Terminal & SSH (9.7.0), Network UPS Tools (0.11.2)

Dashboards

dashboards	3
resources	6
views	6
mode	storage

Recorder

oldest_recorder_run	April 24, 2023 at 3:54 AM
current_recorder_run	May 2, 2023 at 5:36 PM
estimated_db_size	652.32 MiB
database_engine	sqlite
database_version	3.38.5

home-assistant · 2023-05-02T22:55:58Z

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 Renames 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)}}

codyc1515 · 2023-05-04T08:19:32Z

This issue seems to have begun in 2023.05 release. Logs enclosed.

Logger: homeassistant.components.bluetooth.scanner
Source: components/bluetooth/scanner.py:305
Integration: Bluetooth (documentation, issues)
First occurred: 20:10:15 (15 occurrences)
Last logged: 20:17:20

hci0 (XX:XX:XX:XX:XX:XX): Failed to restart Bluetooth scanner: hci0 (XX:XX:XX:XX:XX:XX): Failed to start Bluetooth: [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

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/bluetooth/scanner.py", line 350, in _async_restart_scanner
    await self._async_start()
  File "/usr/src/homeassistant/homeassistant/components/bluetooth/scanner.py", line 305, in _async_start
    raise ScannerStartError(
homeassistant.components.bluetooth.scanner.ScannerStartError: hci0 (XX:XX:XX:XX:XX:XX): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress

wackla33 · 2023-05-04T22:14:48Z

I've been having the same problem for a week

IkHier · 2023-05-05T07:55:20Z

Same issue after may update !?
HA Yellow setup...

wackla33 · 2023-05-05T10:07:40Z

The solution for me was BLUETOOTH LOW ENERGY MONITOR

CheeseySandal · 2023-05-05T12:30:48Z

Same here, I'm also getting the following, not sure if related.

OS Version: Home Assistant OS 10.1
Home Assistant Core: 2023.5.1

[core-ssh ~]$ ha core check
Processing... Done.

Error: Testing configuration at /config
INFO:homeassistant.util.package:Attempting install of pybluez==0.22
ERROR:homeassistant.util.package:Unable to install package pybluez==0.22: error: subprocess-exited-with-error

  × python setup.py bdist_wheel did not run successfully.
  │ exit code: 1
  ╰─> [19 lines of output]
      running bdist_wheel
      running build
      running build_py
      creating build
      creating build/lib.linux-aarch64-cpython-311
      creating build/lib.linux-aarch64-cpython-311/bluetooth
      copying bluetooth/ble.py -> build/lib.linux-aarch64-cpython-311/bluetooth
      copying bluetooth/osx.py -> build/lib.linux-aarch64-cpython-311/bluetooth
      copying bluetooth/widcomm.py -> build/lib.linux-aarch64-cpython-311/bluetooth
      copying bluetooth/btcommon.py -> build/lib.linux-aarch64-cpython-311/bluetooth
      copying bluetooth/__init__.py -> build/lib.linux-aarch64-cpython-311/bluetooth
      copying bluetooth/msbt.py -> build/lib.linux-aarch64-cpython-311/bluetooth
      copying bluetooth/bluez.py -> build/lib.linux-aarch64-cpython-311/bluetooth
      running build_ext
      building 'bluetooth._bluetooth' extension
      creating build/temp.linux-aarch64-cpython-311
      creating build/temp.linux-aarch64-cpython-311/bluez
      gcc -Wsign-compare -DNDEBUG -g -fwrapv -O3 -Wall -fno-semantic-interposition -fno-builtin-malloc -fno-builtin-calloc -fno-builtin-realloc -fno-builtin-free -DTHREAD_STACK_SIZE=0x100000 -fPIC -I./port3 -I/usr/local/include/python3.11 -c bluez/btmodule.c -o build/temp.linux-aarch64-cpython-311/bluez/btmodule.o
      error: command 'gcc' failed: No such file or directory
      [end of output]

  note: This error originates from a subprocess, and is likely not a problem with pip.
  ERROR: Failed building wheel for pybluez
ERROR: Could not build wheels for pybluez, which is required to install pyproject.toml-based projects
[notice] A new release of pip is available: 23.1 -> 23.1.2
[notice] To update, run: pip install --upgrade pip
INFO:homeassistant.util.package:Attempting install of pybluez==0.22
ERROR:homeassistant.util.package:Unable to install package pybluez==0.22: error: subprocess-exited-with-error

  × python setup.py bdist_wheel did not run successfully.
  │ exit code: 1
  ╰─> [19 lines of output]
      running bdist_wheel
      running build
      running build_py
      creating build
      creating build/lib.linux-aarch64-cpython-311
      creating build/lib.linux-aarch64-cpython-311/bluetooth
      copying bluetooth/ble.py -> build/lib.linux-aarch64-cpython-311/bluetooth
      copying bluetooth/osx.py -> build/lib.linux-aarch64-cpython-311/bluetooth
      copying bluetooth/widcomm.py -> build/lib.linux-aarch64-cpython-311/bluetooth
      copying bluetooth/btcommon.py -> build/lib.linux-aarch64-cpython-311/bluetooth
      copying bluetooth/__init__.py -> build/lib.linux-aarch64-cpython-311/bluetooth
      copying bluetooth/msbt.py -> build/lib.linux-aarch64-cpython-311/bluetooth
      copying bluetooth/bluez.py -> build/lib.linux-aarch64-cpython-311/bluetooth
      running build_ext
      building 'bluetooth._bluetooth' extension
      creating build/temp.linux-aarch64-cpython-311
      creating build/temp.linux-aarch64-cpython-311/bluez
      gcc -Wsign-compare -DNDEBUG -g -fwrapv -O3 -Wall -fno-semantic-interposition -fno-builtin-malloc -fno-builtin-calloc -fno-builtin-realloc -fno-builtin-free -DTHREAD_STACK_SIZE=0x100000 -fPIC -I./port3 -I/usr/local/include/python3.11 -c bluez/btmodule.c -o build/temp.linux-aarch64-cpython-311/bluez/btmodule.o
      error: command 'gcc' failed: No such file or directory
      [end of output]

  note: This error originates from a subprocess, and is likely not a problem with pip.
  ERROR: Failed building wheel for pybluez
ERROR: Could not build wheels for pybluez, which is required to install pyproject.toml-based projects
[notice] A new release of pip is available: 23.1 -> 23.1.2
[notice] To update, run: pip install --upgrade pip
INFO:homeassistant.util.package:Attempting install of pybluez==0.22
ERROR:homeassistant.util.package:Unable to install package pybluez==0.22: error: subprocess-exited-with-error

  × python setup.py bdist_wheel did not run successfully.
  │ exit code: 1
  ╰─> [19 lines of output]
      running bdist_wheel
      running build
      running build_py
      creating build
      creating build/lib.linux-aarch64-cpython-311
      creating build/lib.linux-aarch64-cpython-311/bluetooth
      copying bluetooth/ble.py -> build/lib.linux-aarch64-cpython-311/bluetooth
      copying bluetooth/osx.py -> build/lib.linux-aarch64-cpython-311/bluetooth
      copying bluetooth/widcomm.py -> build/lib.linux-aarch64-cpython-311/bluetooth
      copying bluetooth/btcommon.py -> build/lib.linux-aarch64-cpython-311/bluetooth
      copying bluetooth/__init__.py -> build/lib.linux-aarch64-cpython-311/bluetooth
      copying bluetooth/msbt.py -> build/lib.linux-aarch64-cpython-311/bluetooth
      copying bluetooth/bluez.py -> build/lib.linux-aarch64-cpython-311/bluetooth
      running build_ext
      building 'bluetooth._bluetooth' extension
      creating build/temp.linux-aarch64-cpython-311
      creating build/temp.linux-aarch64-cpython-311/bluez
      gcc -Wsign-compare -DNDEBUG -g -fwrapv -O3 -Wall -fno-semantic-interposition -fno-builtin-malloc -fno-builtin-calloc -fno-builtin-realloc -fno-builtin-free -DTHREAD_STACK_SIZE=0x100000 -fPIC -I./port3 -I/usr/local/include/python3.11 -c bluez/btmodule.c -o build/temp.linux-aarch64-cpython-311/bluez/btmodule.o
      error: command 'gcc' failed: No such file or directory
      [end of output]

  note: This error originates from a subprocess, and is likely not a problem with pip.
  ERROR: Failed building wheel for pybluez
ERROR: Could not build wheels for pybluez, which is required to install pyproject.toml-based projects
[notice] A new release of pip is available: 23.1 -> 23.1.2
[notice] To update, run: pip install --upgrade pip
Failed config
  General Errors:
    - Platform error device_tracker.bluetooth_tracker - Requirements for bluetooth_tracker not found: ['pybluez==0.22'].

Successful config (partial)

[core-ssh ~]$

Woersi86 · 2023-05-05T13:01:46Z

+1

Logger: homeassistant.components.bluetooth.scanner
Source: components/bluetooth/scanner.py:305
Integration: Bluetooth (documentation, issues)
First occurred: 14:10:14 (95 occurrences)
Last logged: 14:57:19

hci0 (E4:5F:01:68:53:51): Failed to restart Bluetooth scanner: hci0 (E4:5F:01:68:53:51): Failed to start Bluetooth: [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

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/bluetooth/scanner.py", line 350, in _async_restart_scanner
    await self._async_start()
  File "/usr/src/homeassistant/homeassistant/components/bluetooth/scanner.py", line 305, in _async_start
    raise ScannerStartError(
homeassistant.components.bluetooth.scanner.ScannerStartError: hci0 (E4:5F:01:68:53:51): Failed to start Bluetooth: [org.bluez.Error.InProgress] Operation already in progress

bdraco · 2023-05-06T13:52:25Z

Please see
home-assistant/operating-system#2485
home-assistant/operating-system#2535

mukul-k · 2023-05-06T20:08:37Z

Same issue on my Home Assistant Yellow after updating.

bjorndegroot · 2023-05-08T19:55:38Z

Same issue here.

codyc1515 · 2023-05-08T20:03:12Z

I fixed this by restoring my Raspberry Pi's /boot/config.txt file back to defaults.

bjorndegroot · 2023-05-11T05:33:11Z

I'm using the Supervised version of HA. I can find a config file in the boot folder, but I don't know what the defaults are. I'm using a debian installation on a Thin Client by the way.

Does anybody know how to fix this?

St3fanBC · 2023-05-12T14:12:20Z

Same issue for me after upgrading to latest HA v2023.5.2 on HA Yellow

dMopp · 2023-05-12T19:51:00Z

Same :( HA Supervised

codyc1515 · 2023-05-12T21:04:55Z

I'm using the Supervised version of HA. I can find a config file in the boot folder, but I don't know what the defaults are. I'm using a debian installation on a Thin Client by the way.

Does anybody know how to fix this?

Could you please upload here a copy of your /boot/config.txt file? There shouldn't be anything private in it.

bjorndegroot · 2023-05-12T21:25:53Z

I'm using the Supervised version of HA. I can find a config file in the boot folder, but I don't know what the defaults are. I'm using a debian installation on a Thin Client by the way.
Does anybody know how to fix this?

Could you please upload here a copy of your /boot/config.txt file? There shouldn't be anything private in it.

Automatically generated file; DO NOT EDIT.

Linux/x86 5.10.178 Kernel Configuration

CONFIG_CC_VERSION_TEXT="gcc-10 (Debian 10.2.1-6) 10.2.1 20210110"
CONFIG_CC_IS_GCC=y
CONFIG_GCC_VERSION=100201
CONFIG_LD_VERSION=235020000
CONFIG_CLANG_VERSION=0
CONFIG_AS_IS_GNU=y
CONFIG_AS_VERSION=23502
CONFIG_LLD_VERSION=0
CONFIG_CC_CAN_LINK=y
CONFIG_CC_CAN_LINK_STATIC=y
CONFIG_CC_HAS_ASM_GOTO=y
CONFIG_CC_HAS_ASM_INLINE=y
CONFIG_IRQ_WORK=y
CONFIG_BUILDTIME_TABLE_SORT=y
CONFIG_THREAD_INFO_IN_TASK=y

dMopp · 2023-05-12T23:23:35Z

3c3
< # Linux/x86 5.10.162 Kernel Configuration
---
> # Linux/x86 5.10.178 Kernel Configuration
9a10,11
> CONFIG_AS_IS_GNU=y
> CONFIG_AS_VERSION=23502
26c28
< CONFIG_BUILD_SALT="5.10.0-21-amd64"
---
> CONFIG_BUILD_SALT="5.10.0-22-amd64"
415c417
< # CONFIG_MICROCODE_OLD_INTERFACE is not set
---
> # CONFIG_MICROCODE_LATE_LOADING is not set
1693d1694
< CONFIG_NET_CLS_TCINDEX=m


just a diff between the 2 boot configs i have in place (standard debian)
[bootconf.txt](https://github.com/home-assistant/core/files/11468300/bootconf.txt)

and here the complete file

St3fanBC · 2023-05-16T10:33:38Z

Seems like it's fixed here in the latest update from yesterday... mine is not flapping after the update restart 👍

bjorndegroot · 2023-05-26T19:31:51Z

That's correct. After last weeks update the issue is fixed here too.

vlape · 2023-05-26T23:34:34Z

Mine worked for a couple days, then this week's update seemed to break.
Retrying setup: hci0 (REDACTED): Failed to start Bluetooth: [org.bluez.Error.NotReady] Resource Not Ready

Logger: homeassistant.config_entries
Source: config_entries.py:1287
First occurred: 6:19:30 PM (1 occurrences)
Last logged: 6:19:30 PM

Config entry 'D8:3A:DD:09:0A:FF' for bluetooth integration not ready yet: hci0 (D8:3A:DD:09:0A:FF): Failed to start Bluetooth: [org.bluez.Error.NotReady] Resource Not Ready; Retrying in background

Logger: bluetooth_auto_recovery.recover
Source: components/bluetooth/util.py:78
First occurred: 6:19:25 PM (11 occurrences)
Last logged: 6:21:27 PM

Could not cycle the Bluetooth adapter hci0 [D8:3A:DD:09:0A:FF]: [Errno 110] Operation timed out
Bluetooth adapter hci0 [D8:3A:DD:09:0A:FF] could not be reset due to timeout after 5 seconds

2023-05-26 18:26:03.410 WARNING (MainThread) [bluetooth_auto_recovery.recover] Could not cycle the Bluetooth adapter hci0 [REDACTED]: [Errno 110] Operation timed out
2023-05-26 18:26:08.414 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [REDACTED] could not be reset due to timeout after 5 seconds
2023-05-26 18:26:08.418 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Executing USB reset for Bluetooth adapter hci0
2023-05-26 18:26:08.429 DEBUG (MainThread) [bluetooth_auto_recovery.recover] hci0 is not a USB devices while attempting USB reset: ttyS0 is not a USB device
2023-05-26 18:26:08.431 DEBUG (MainThread) [homeassistant.components.bluetooth.scanner] hci0 (REDACTED): adapter reset result: False
2023-05-26 18:26:08.431 DEBUG (MainThread) [homeassistant.components.bluetooth.scanner] hci0 (REDACTED): Starting bluetooth discovery attempt: (2/3)
2023-05-26 18:26:08.434 DEBUG (MainThread) [homeassistant.components.bluetooth.scanner] hci0 (REDACTED): BleakError while starting bluetooth; attempt: (2/3): [org.bluez.Error.NotReady] Resource Not Ready
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 357, 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.NotReady] Resource Not Ready
2023-05-26 18:26:08.440 WARNING (MainThread) [homeassistant.config_entries] Config entry 'REDACTED' for bluetooth integration not ready yet: hci0 (REDACTED): Failed to start Bluetooth: [org.bluez.Error.NotReady] Resource Not Ready; Retrying in background
2023-05-26 18:26:14.510 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 0x7f4e9d0700>>, 'scanning_mode': 'active', 'adapter': 'hci0'}
2023-05-26 18:26:14.511 DEBUG (MainThread) [homeassistant.components.bluetooth.scanner] hci0 (REDACTED): Starting bluetooth discovery attempt: (1/3)
2023-05-26 18:26:14.523 DEBUG (MainThread) [homeassistant.components.bluetooth.scanner] hci0 (REDACTED): adapter stopped responding; executing reset
2023-05-26 18:26:14.523 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Attempting to recover bluetooth adapter hci0 with mac address REDACTED
2023-05-26 18:26:14.523 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Attempting to power cycle bluetooth adapter hci0 [REDACTED]
2023-05-26 18:26:14.534 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding cmd_code as type CmdCode
2023-05-26 18:26:14.536 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding controller_idx as type Controller
2023-05-26 18:26:14.537 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding param_len as type ParamLen
2023-05-26 18:26:14.538 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2023-05-26 18:26:14.539 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2023-05-26 18:26:14.540 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2023-05-26 18:26:14.540 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding command_opcode as type CmdCode
2023-05-26 18:26:14.540 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding status as type Status
2023-05-26 18:26:14.541 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding num_controllers as type IntUL
2023-05-26 18:26:14.541 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_index[i] as type IntUL
2023-05-26 18:26:14.542 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]>
2023-05-26 18:26:14.543 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding cmd_code as type CmdCode
2023-05-26 18:26:14.543 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding controller_idx as type Controller
2023-05-26 18:26:14.544 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding param_len as type ParamLen
2023-05-26 18:26:14.545 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2023-05-26 18:26:14.546 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2023-05-26 18:26:14.547 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2023-05-26 18:26:14.547 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding command_opcode as type CmdCode
2023-05-26 18:26:14.547 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding status as type Status
2023-05-26 18:26:14.548 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding address as type Address
2023-05-26 18:26:14.548 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding bluetooth_version as type IntUL
2023-05-26 18:26:14.549 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding manufacturer as type IntUL
2023-05-26 18:26:14.549 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding supported_settings as type IntUL
2023-05-26 18:26:14.550 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding current_settings as type CurrentSettings
2023-05-26 18:26:14.550 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding class_of_device as type IntUL
2023-05-26 18:26:14.550 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding name as type Name
2023-05-26 18:26:14.551 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding short_name as type IntUL
2023-05-26 18:26:14.551 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket Read: <event_code=CommandCompleteEvent, controller_idx=0, param_len=283> <command_opcode=ReadControllerInformation, status=Success> <address=REDACTED, bluetooth_version=9, manufacturer=305, supported_settings=114431, current_settings={Powered: False, Connectable: False, FastConnectable: False, Discoverable: False, Bondable: False, LinkLevelSecurity: False, SecureSimplePairing: True, BREDR: True, HighSpeed: False, LowEnergy: True, Advertising: False, SecureConnections: True, DebugKeys: False, Privacy: False, ControllerConfiguration: False, StaticAddress: False, PHYConfiguration: False, WidebandSpeech: False}, class_of_device=0, name=b'ha.nbtx.us', short_name=0>
2023-05-26 18:26:14.552 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=REDACTED, bluetooth_version=9, manufacturer=305, supported_settings=114431, current_settings={Powered: False, Connectable: False, FastConnectable: False, Discoverable: False, Bondable: False, LinkLevelSecurity: False, SecureSimplePairing: True, BREDR: True, HighSpeed: False, LowEnergy: True, Advertising: False, SecureConnections: True, DebugKeys: False, Privacy: False, ControllerConfiguration: False, StaticAddress: False, PHYConfiguration: False, WidebandSpeech: False}, class_of_device=0, name=b'ha.nbtx.us', short_name=0>)
2023-05-26 18:26:14.552 DEBUG (MainThread) [bluetooth_auto_recovery.recover] hci0 (REDACTED) idx is 0
2023-05-26 18:26:14.557 DEBUG (MainThread) [bluetooth_auto_recovery.recover] rfkill_idx of hci0 is 1
2023-05-26 18:26:14.557 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Attempting to power cycle bluetooth adapter hci0 [REDACTED]
2023-05-26 18:26:14.557 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding cmd_code as type CmdCode
2023-05-26 18:26:14.558 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding controller_idx as type Controller
2023-05-26 18:26:14.559 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding param_len as type ParamLen
2023-05-26 18:26:14.561 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2023-05-26 18:26:14.561 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2023-05-26 18:26:14.562 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2023-05-26 18:26:14.562 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding command_opcode as type CmdCode
2023-05-26 18:26:14.563 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding status as type Status
2023-05-26 18:26:14.563 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding address as type Address
2023-05-26 18:26:14.564 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding bluetooth_version as type IntUL
2023-05-26 18:26:14.564 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding manufacturer as type IntUL
2023-05-26 18:26:14.565 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding supported_settings as type IntUL
2023-05-26 18:26:14.565 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding current_settings as type CurrentSettings
2023-05-26 18:26:14.566 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding class_of_device as type IntUL
2023-05-26 18:26:14.566 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding name as type Name
2023-05-26 18:26:14.567 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding short_name as type IntUL
2023-05-26 18:26:14.567 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket Read: <event_code=CommandCompleteEvent, controller_idx=0, param_len=283> <command_opcode=ReadControllerInformation, status=Success> <address=REDACTED, bluetooth_version=9, manufacturer=305, supported_settings=114431, current_settings={Powered: False, Connectable: False, FastConnectable: False, Discoverable: False, Bondable: False, LinkLevelSecurity: False, SecureSimplePairing: True, BREDR: True, HighSpeed: False, LowEnergy: True, Advertising: False, SecureConnections: True, DebugKeys: False, Privacy: False, ControllerConfiguration: False, StaticAddress: False, PHYConfiguration: False, WidebandSpeech: False}, class_of_device=0, name=b'ha.nbtx.us', short_name=0>
2023-05-26 18:26:14.570 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Current power state of bluetooth adapter hci0 [REDACTED] is OFF, trying to turn it back ON
2023-05-26 18:26:14.581 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Bouncing Bluetooth adapter hci0
2023-05-26 18:26:14.581 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Setting hci0 down
2023-05-26 18:26:15.085 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Setting hci0 up
2023-05-26 18:26:17.107 WARNING (MainThread) [bluetooth_auto_recovery.recover] Could not cycle the Bluetooth adapter hci0 [REDACTED]: [Errno 110] Operation timed out
2023-05-26 18:26:17.110 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding powered as type IntUL
2023-05-26 18:26:17.111 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding cmd_code as type CmdCode
2023-05-26 18:26:17.112 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding controller_idx as type Controller
2023-05-26 18:26:17.113 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding param_len as type ParamLen
2023-05-26 18:26:19.153 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2023-05-26 18:26:19.154 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2023-05-26 18:26:19.156 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2023-05-26 18:26:19.156 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding command_opcode as type CmdCode
2023-05-26 18:26:19.157 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding status as type Status
2023-05-26 18:26:19.158 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket read <event_code=CommandStatusEvent, controller_idx=0, param_len=3> <command_opcode=SetPowered, status=AuthenticationFailed>

smart7324 · 2023-07-24T13:14:44Z

Same issue for me:

Could not reset the power state of the Bluetooth adapter hci0 due to timeout after 5 seconds
Could not cycle the Bluetooth adapter hci0: [Errno 1] Operation not permitted
Bluetooth adapter hci0 could not be reset:
Closing Bluetooth adapter hci0 failed: [Errno 9] Bad file descriptor.

Home Assistant 2023.7.2

sammcj · 2023-07-31T03:26:18Z

The same for me on 2023.7.2, Fedora 38, HA running in a container.

I've tried it with multiple different BT adapters as well.

77degrees · 2023-08-07T19:47:07Z

Same issue for me, using an adapter from the recommended documentation: Warmstor WBT-AD01 (CSR8510A10)

Home Assistant 2023.8.1
Supervisor 2023.07.1
Operating System 10.4
Frontend 20230802.0 - latest

Error 1

Logger: bluetooth_auto_recovery.recover
Source: components/bluetooth/util.py:78
First occurred: 2:40:08 PM (30 occurrences)
Last logged: 2:44:11 PM

Bluetooth adapter hci0 [00:50:56:FB:58:19] could not be reset:
Closing Bluetooth adapter hci0 [00:50:56:FB:58:19] failed: [Errno 9] Bad file descriptor
Could not determine the power state of the Bluetooth adapter hci0 [00:50:56:FB:58:19] due to timeout after 5 seconds
Could not cycle the Bluetooth adapter hci0 [00:50:56:FB:58:19]: [Errno 38] Function not implemented

Error 2

Logger: bluetooth_auto_recovery.recover
Source: runner.py:179
First occurred: 2:40:28 PM (7 occurrences)
Last logged: 2:44:04 PM

Bluetooth management socket connection lost: [Errno 22] Invalid argument

Error 3

Logger: homeassistant.config_entries
Source: config_entries.py:1250
First occurred: 2:42:00 PM (1 occurrences)
Last logged: 2:42:00 PM

Config entry '00:50:56:FB:58:19' for bluetooth integration not ready yet: hci0 (00:50:56:FB:58:19): Failed to start Bluetooth: adapter 'hci0' not found; Retrying in background

bdraco · 2023-08-07T19:54:13Z

Newer linux kernels broke bluetooth. HAOS has some patches that will fix some of the adapters but unless you want to patch the kernel, local adapters won't work.

The best option right now is to switch to https://esphome.github.io/bluetooth-proxies/

GRClark · 2023-08-07T20:06:18Z

Newer linux kernels broke bluetooth. HAOS has some patches that will fix some of the adapters but unless you want to patch the kernel, local adapters won't work.

The best option right now is to switch to https://esphome.github.io/bluetooth-proxies/

Yeah I didn't see this issue when I was running Raspberry Pi OS Debian 10 until I upgraded to Debian 11 was when I started getting this problem.

sergeolkhovik · 2024-05-12T19:33:08Z

Gentlemen, my 2c. I have HA running on some old Mac Pro (5,1 if I remember correctly), I tried to pass both built-in bluetooth and some cheap Chineese USB BT 5.1 sticks without any success. I plugged in another USB device - CSR 4.0 (if I remember correctly) and it worked well.
Environment - Ubuntu 23.10 (both host and guest, then I updated guest to 24.04 without any difference), Qemu/KVM.

LAPDragnet · 2024-05-13T06:00:25Z

It seems to be hit-or-miss for what works and what does not. I bought this adapter https://www.startech.com/en-us/networking-io/usba-bluetooth-v5-c2 but it fails in a similar fashion to the built-in unit.

sergeolkhovik · 2024-05-13T07:27:47Z

Just an update, the cheap ones that didn't work: https://www.aliexpress.com/item/1005005721208212.html or anything like that
The worked one:

lsusb | grep Cam
Bus 003 Device 002: ID 0a12:0001 Cambridge Silicon Radio, Ltd Bluetooth Dongle (HCI mode)

(I think this one even doesn't support 5.x, only 4.x).

Guest kernel: 6.8.0-31-generic
Host:
6.5.0-14-generic
Qemu: 1:8.0.4+dfsg-1ubuntu3.23.10.5

sergeolkhovik · 2024-05-13T09:38:57Z

Looks like I was toooo optimistic:

habluetooth.scanner.ScannerStartError: hci0 (00:1A:7D:DA:71:0A): Failed to start Bluetooth: passive scanning on Linux requires BlueZ >= 5.55 with --experimental enabled and Linux kernel >= 5.10; Try power cycling the Bluetooth hardware.
2024-05-13 12:32:56.587 WARNING (MainThread) [bluetooth_auto_recovery.recover] Could not reset the power state of the Bluetooth adapter hci0 [00:1A:7D:DA:71:0A] due to timeout after 5 seconds
2024-05-13 12:32:56.591 WARNING (MainThread) [bluetooth_auto_recovery.recover] Could not cycle the Bluetooth adapter hci0 [00:1A:7D:DA:71:0A]: [Errno 1] Operation not permitted
2024-05-13 12:32:56.591 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth management socket connection lost: [Errno 22] Invalid argument

bdraco · 2024-05-29T09:47:19Z

Just an update, the cheap ones that didn't work: aliexpress.com/item/1005005721208212.html or anything like that The worked one:
lsusb | grep Cam
Bus 003 Device 002: ID 0a12:0001 Cambridge Silicon Radio, Ltd Bluetooth Dongle (HCI mode)
(I think this one even doesn't support 5.x, only 4.x).

Guest kernel: 6.8.0-31-generic Host: 6.5.0-14-generic Qemu: 1:8.0.4+dfsg-1ubuntu3.23.10.5

Here is the one I use that I have zero issues with on my Blue, Green, and Yellows running HAOS https://www.aliexpress.us/item/2255800893640297.html

allergicapple · 2024-06-06T17:25:02Z

Same issue: cycling retries on the bluetooth device.

Fixed it on my Raspberry 3 B simply by unblocking it:

user@raspberrypi:~ $ rfkill list
0: hci0: Bluetooth
  Soft blocked: yes
  Hard blocked: no
1: phy0: Wireless LAN
  Soft blocked: yes
  Hard blocked: no
user@raspberrypi:~ $ rfkill unblock 0
user@raspberrypi:~ $ rfkill list
0: hci0: Bluetooth
  Soft blocked: no
  Hard blocked: no
1: phy0: Wireless LAN
  Soft blocked: yes
  Hard blocked: no

After that I could use bluetoothctl just as normal, whereas it previously would fail with the usual org.bluez.Error.Failed and the HA device now also behaved normally.

hubertott · 2024-06-14T22:21:06Z

Had been holding back on the System Update for a couple of versions. Then ran into this issue.

Post upgrades.

Core
2024.6.2
Supervisor
2024.06.0
Operating System
12.3
Frontend
20240610.0

Fixed on my Raspberry Pi 3B using built-in Bluetooth.

I just needed to do a full reboot (not just a restart).

HTH

StahlTim · 2024-06-15T07:13:11Z

Fixed on my Raspberry Pi 3B using built-in Bluetooth.

I just needed to do a full reboot (not just a restart).

HTH

Does this fix the issue consistently?

For me, a reboot (or unplugging the power) temporarily fixes the symptoms/issue for 1-3 days.

EDIT: After that time I start getting the following errors again (and active scanning devices do not work anymore):
[habluetooth.scanner] hci0 (XX:XX:XX:XX:XX:XX): Successful fall-back to passive scanning mode after active scanning failed (4/4)

mitch1006 · 2024-08-05T19:17:25Z

Same issue.
I just plug a bluetooth UGREEN key and config bluetooth.
Then it loops on initialization with
Could not cycle the Bluetooth adapter hci1 [00:A7:44:19:05:E1]: [Errno 110] Operation timed out
Closing Bluetooth adapter hci1 [00:A7:44:19:05:E1] failed: [Errno 9] Bad file descriptor

Hassio on RPi 5
Core 2024.7.4
Supervisor 2024.06.2
Operating System 12.3
Interface utilisateur 20240710.0

heibertelf · 2024-09-07T11:40:34Z

Core 2024.9.1
Supervisor 2024.08.0
Operating System 13.1
Frontend 20240906.0
Up-to-date HAOS on Intel NUC integrated BT

Still nothing. It might even work for a couple days, then it falls off and it's not clear how to get it working again.

evilpig · 2024-09-11T04:32:00Z

Having same issue on Intel N100 NUC running Ubuntu Server and Newest Home Assistant

bcutter · 2024-11-02T22:02:29Z

Some personal experiences on a Pi 4 8 GB with HA OS 13.1 now with an uptime of more than 30 days (host/HA OS and HA Core):

Host booted at 2024-09-30 18:31, last HA Core restart at 2024-10-01 18:47.
On 2024-10-29 19:15 - that's pretty much excactly 30 days after the last host restart by the way - I noticed the first bluetooth connections broken or rather not stable anymore (connection, no connection, ...). Frequent connection issues.
The last time with HA OS 12.4 after quite a similar uptime (of 24 to 34 days, see "NetworkManager not correctly configured" + unsupported state warning operating-system#3602) the whole system got hiccups and needed a full reboot to work around all those issues. Seems like either HA OS 13.x improved things here - in terms of maybe isolating Bluetooth issues in a way they don't lead to an overall host/system instability anymore - or waited long enough yet (now it's 32 days host uptime).
On 2024-11-01 00:45 I reloaded the bluetooth integration (native Pi 4 bluetooth chip). After that, the log entries in HA log immediately stopped, but the bluetooth integration was in never-ending "Initializing..." state frequently providing a "Setup failed, retrying" notice.
Interesting: If “Passive scanning” is activated in the configuration, the setup no longer fails but everything seems (! likely still bluetooth connection issues !) to work fine immediately. If you switch it off again (so that active scanning takes place), the never-ending “Initializing...” and “Setup failed, will try again” status appears again.
On 2024-11-02 22:58 I enabled passive scanning permanently. As discovered 15 minutes later in host log, there's something new now:

2024-11-02 22:00:17.457 MyHostName bluetoothd[521]: Path /org/bleak/67/546480900704 reserved for Adv Monitor app :1.136
2024-11-02 22:02:17.682 MyHostName bluetoothd[521]: Path /org/bleak/67/546480900704 removed along with Adv Monitor app :1.136
2024-11-02 22:02:17.687 MyHostName bluetoothd[521]: Path /org/bleak/67/546438084352 reserved for Adv Monitor app :1.136
2024-11-02 22:04:17.777 MyHostName bluetoothd[521]: Path /org/bleak/67/546438084352 removed along with Adv Monitor app :1.136
2024-11-02 22:04:17.782 MyHostName bluetoothd[521]: Path /org/bleak/67/546190424144 reserved for Adv Monitor app :1.136
2024-11-02 22:06:47.781 MyHostName bluetoothd[521]: Path /org/bleak/67/546190424144 removed along with Adv Monitor app :1.136
2024-11-02 22:06:47.787 MyHostName bluetoothd[521]: Path /org/bleak/67/546508394624 reserved for Adv Monitor app :1.136
2024-11-02 22:08:47.782 MyHostName bluetoothd[521]: Path /org/bleak/67/546508394624 removed along with Adv Monitor app :1.136
2024-11-02 22:08:47.784 MyHostName bluetoothd[521]: Path /org/bleak/67/545459373792 reserved for Adv Monitor app :1.136
2024-11-02 22:11:17.852 MyHostName bluetoothd[521]: Path /org/bleak/67/545459373792 removed along with Adv Monitor app :1.136
2024-11-02 22:11:17.876 MyHostName bluetoothd[521]: Path /org/bleak/67/546459832672 reserved for Adv Monitor app :1.136

Overview

1: bluetooth working fine until roughly 30 days of system uptime
2: bluetooth fails and fills HA log massively with [*1]
3: bluetooth integration still not working but not writing errors to HA log anymore

[*1]

Logger: habluetooth.scanner
Quelle: /usr/local/lib/python3.12/asyncio/events.py:88
Erstmals aufgetreten: 29. Oktober 2024 um 19:11:41 (3211 Vorkommnisse)
Zuletzt protokolliert: 1. November 2024 um 00:43:52

hci0 (XX:XX:XX:XX:XX:XX): Failed to restart Bluetooth scanner: hci0 (XX:XX:XX:XX:XX:XX): Timed out starting Bluetooth after 15 seconds; Try power cycling the Bluetooth hardware.
Traceback (most recent call last):
  File "src/habluetooth/scanner.py", line 250, in habluetooth.scanner.HaScanner._async_start
  File "/usr/local/lib/python3.12/site-packages/bleak/__init__.py", line 198, in start
    await self._backend.start()
  File "/usr/local/lib/python3.12/site-packages/bleak/backends/bluezdbus/scanner.py", line 185, in start
    self._stop = await manager.active_scan(
                 ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/bleak/backends/bluezdbus/manager.py", line 408, in active_scan
    reply = await self._bus.call(
            ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/dbus_fast/aio/message_bus.py", line 384, in call
    await future
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "src/habluetooth/scanner.py", line 249, in habluetooth.scanner.HaScanner._async_start
  File "/usr/local/lib/python3.12/asyncio/timeouts.py", line 115, in __aexit__
    raise TimeoutError from exc_val
TimeoutError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "src/habluetooth/scanner.py", line 381, in habluetooth.scanner.HaScanner._async_restart_scanner
  File "src/habluetooth/scanner.py", line 295, in _async_start
habluetooth.scanner.ScannerStartError: hci0 (XX:XX:XX:XX:XX:XX): Timed out starting Bluetooth after 15 seconds; Try power cycling the Bluetooth hardware.

So current summary for me:

a) after a rather long (but way to short) time of roughly 3 to 4 weeks, Bluetooth on the Pi 4 with HA OS goes crazy creating serious issues for at least Bluetooth connections. Overall system instabilities like with HA OS < 13.x has not been seen yet.
b) Only using active scanning triggers errors in HA log and results in a malfunctioning bluetooth integration. Using passive scanning, the integration seems to work fine.
c) In the end, this screwed up bluetooth on Pi 4 with HA OS is a major uptime breaker, rendering the whole system unreliable.

So what does a final solution look like?!?

As I only have roughly 12 hours left to decide if it's a good idea to NOT reboot the host now prior to leaving for holiday for some time, it would be very helpful to get the information if trying to let it run for a bit longer and/or gathering specific logs might be helpful and desired or not.

minmaxat · 2024-12-02T10:35:43Z

Hi +1 with HA Yellow

ColtonYYZ · 2024-12-07T19:40:14Z

Hi! I am having a similiar problem, though my issue may be a bit different just looking at the logs from others in this thread.

Below are my logs. (I've removed the mac address for privacy). The logs go on forever.. like 104,389 lines of all the same message, repeating over and over.

2024-12-07 14:30:59.022 WARNING (MainThread) [bluetooth_auto_recovery.recover] Could not determine the power state of the Bluetooth adapter hci0 [[redacted]] due to timeout after 5 seconds
2024-12-07 14:30:59.022 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Bouncing Bluetooth adapter hci0
2024-12-07 14:30:59.022 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Setting hci0 down
2024-12-07 14:30:59.523 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Setting hci0 up
2024-12-07 14:31:07.084 WARNING (MainThread) [bluetooth_auto_recovery.recover] Could not cycle the Bluetooth adapter hci0 [[redacted]]: [Errno 110] Operation timed out
2024-12-07 14:31:07.085 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding powered as type IntUL
2024-12-07 14:31:07.085 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding cmd_code as type CmdCode
2024-12-07 14:31:07.085 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding controller_idx as type Controller
2024-12-07 14:31:07.085 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding param_len as type ParamLen
2024-12-07 14:31:07.085 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2024-12-07 14:31:07.085 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2024-12-07 14:31:07.085 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2024-12-07 14:31:07.085 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding command_opcode as type CmdCode
2024-12-07 14:31:07.085 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding status as type Status
2024-12-07 14:31:07.085 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket read <event_code=CommandStatusEvent, controller_idx=0, param_len=3> <command_opcode=ReadControllerInformation, status=InvalidIndex>
2024-12-07 14:31:07.086 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth management socket connection lost: [Errno 22] Invalid argument
2024-12-07 14:31:12.086 WARNING (MainThread) [bluetooth_auto_recovery.recover] Could not reset the power state of the Bluetooth adapter hci0 [[redacted]] due to timeout after 5 seconds
2024-12-07 14:31:12.087 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Executing USB reset for Bluetooth adapter hci0
2024-12-07 14:31:13.988 WARNING (MainThread) [bluetooth_auto_recovery.recover] Closing Bluetooth adapter hci0 [[redacted]] failed: [Errno 9] Bad file descriptor
2024-12-07 14:31:13.988 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Attempting to power cycle bluetooth adapter hci0 [[redacted]]
2024-12-07 14:31:13.993 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Found adapters from hci: {0: {'dev_id': 0, 'name': 'hci0', 'bdaddr': '[redacted]', 'flags': 0, 'type': 1, 'features': <ifaddr._shared.c_ubyte_Array_8 object at 0x7f7a013866d0>, 'pkt_type': 52472, 'link_policy': 0, 'link_mode': 32768, 'acl_mtu': 1021, 'acl_pkts': 4, 'sco_mtu': 180, 'sco_pkts': 1, 'stat': <bluetooth_adapters.systems.linux_hci.hci_dev_stats object at 0x7f7a013861d0>}}
2024-12-07 14:31:13.993 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Found adapter [redacted] in hci device as 0
2024-12-07 14:31:13.993 DEBUG (MainThread) [bluetooth_auto_recovery.recover] hci0 ([redacted]) idx is 0
2024-12-07 14:31:14.000 DEBUG (MainThread) [bluetooth_auto_recovery.recover] rfkill_idx of hci0 is 19
2024-12-07 14:31:16.532 DEBUG (MainThread) [homeassistant.components.bluetooth] Rediscovered adapters: {'hci0': {'address': '[redacted]', 'sw_version': 'Unknown', 'hw_version': None, 'passive_scan': False, 'manufacturer': 'CIMSYS Inc', 'product': None, 'vendor_id': None, 'product_id': None}}
2024-12-07 14:31:16.534 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Attempting to recover bluetooth adapter hci0 with mac address [redacted]
2024-12-07 14:31:16.534 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Attempting to power cycle bluetooth adapter hci0 [[redacted]]
2024-12-07 14:31:16.539 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Found adapters from hci: {0: {'dev_id': 0, 'name': 'hci0', 'bdaddr': '[redacted]', 'flags': 0, 'type': 1, 'features': <ifaddr._shared.c_ubyte_Array_8 object at 0x7f79ed622450>, 'pkt_type': 52472, 'link_policy': 0, 'link_mode': 32768, 'acl_mtu': 1021, 'acl_pkts': 4, 'sco_mtu': 180, 'sco_pkts': 1, 'stat': <bluetooth_adapters.systems.linux_hci.hci_dev_stats object at 0x7f79ed623ed0>}}
2024-12-07 14:31:16.540 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Found adapter [redacted] in hci device as 0
2024-12-07 14:31:16.540 DEBUG (MainThread) [bluetooth_auto_recovery.recover] hci0 ([redacted]) idx is 0
2024-12-07 14:31:16.543 DEBUG (MainThread) [bluetooth_auto_recovery.recover] rfkill_idx of hci0 is 19
2024-12-07 14:31:16.544 DEBUG (MainThread) [bluetooth_auto_recovery.recover] Attempting to power cycle bluetooth adapter hci0 [[redacted]]
2024-12-07 14:31:16.544 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding cmd_code as type CmdCode
2024-12-07 14:31:16.545 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding controller_idx as type Controller
2024-12-07 14:31:16.546 DEBUG (MainThread) [btsocket.btmgmt_protocol] Encoding param_len as type ParamLen
2024-12-07 14:31:16.549 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2024-12-07 14:31:16.549 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2024-12-07 14:31:16.549 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2024-12-07 14:31:16.550 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding command_opcode as type CmdCode
2024-12-07 14:31:16.550 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding status as type Status
2024-12-07 14:31:16.551 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket read <event_code=CommandStatusEvent, controller_idx=0, param_len=3> <command_opcode=ReadControllerInformation, status=InvalidIndex>
2024-12-07 14:31:16.551 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2024-12-07 14:31:16.552 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2024-12-07 14:31:16.552 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2024-12-07 14:31:16.553 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding command_opcode as type CmdCode
2024-12-07 14:31:16.553 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding status as type Status
2024-12-07 14:31:16.553 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket read <event_code=CommandStatusEvent, controller_idx=0, param_len=3> <command_opcode=ReadControllerInformation, status=InvalidIndex>
2024-12-07 14:31:16.554 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2024-12-07 14:31:16.554 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2024-12-07 14:31:16.555 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2024-12-07 14:31:16.555 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding command_opcode as type CmdCode
2024-12-07 14:31:16.555 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding status as type Status
2024-12-07 14:31:16.556 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket read <event_code=CommandStatusEvent, controller_idx=0, param_len=3> <command_opcode=ReadControllerInformation, status=InvalidIndex>
2024-12-07 14:31:16.557 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2024-12-07 14:31:16.558 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2024-12-07 14:31:16.559 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2024-12-07 14:31:16.559 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding command_opcode as type CmdCode
2024-12-07 14:31:16.560 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding status as type Status
2024-12-07 14:31:16.560 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket read <event_code=CommandStatusEvent, controller_idx=0, param_len=3> <command_opcode=ReadControllerInformation, status=InvalidIndex>
2024-12-07 14:31:16.565 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding event_code as type EvtCode
2024-12-07 14:31:16.567 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding controller_idx as type Controller
2024-12-07 14:31:16.567 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding param_len as type ParamLen
2024-12-07 14:31:16.568 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding command_opcode as type CmdCode
2024-12-07 14:31:16.569 DEBUG (MainThread) [btsocket.btmgmt_protocol] Decoding status as type Status
2024-12-07 14:31:16.570 DEBUG (MainThread) [btsocket.btmgmt_protocol] Socket read <event_code=CommandStatusEvent, controller_idx=0, param_len=3> <command_opcode=ReadControllerInformation, status=InvalidIndex>

s-hell · 2024-12-15T19:51:33Z

I have the same Problem with my bluetooth device:

2024-12-15 20:49:49.583 WARNING (MainThread) [bluetooth_auto_recovery.recover] Could not reset the power state of the Bluetooth adapter hci0 [34:23:87:FE:8F:1C] due to timeout after 5 seconds
2024-12-15 20:49:49.585 WARNING (MainThread) [bluetooth_auto_recovery.recover] Could not cycle the Bluetooth adapter hci0 [34:23:87:FE:8F:1C]: [Errno 1] Operation not permitted
2024-12-15 20:49:49.585 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth management socket connection lost: [Errno 22] Invalid argument
2024-12-15 20:49:54.586 WARNING (MainThread) [bluetooth_auto_recovery.recover] Could not reset the power state of the Bluetooth adapter hci0 [34:23:87:FE:8F:1C] due to timeout after 5 seconds
2024-12-15 20:49:54.589 WARNING (MainThread) [bluetooth_auto_recovery.recover] Closing Bluetooth adapter hci0 [34:23:87:FE:8F:1C] failed: [Errno 9] Bad file descriptor

ColtonYYZ · 2024-12-16T09:23:02Z

Hi! I am having a similiar problem, though my issue may be a bit different just looking at the logs from others in this thread.

I forgot to follow up and say that I tried a different Bluetooth adapter and got it working effortlessly. So I think only certain adapters are compatible with Hass. Debian could see it no problem, I just couldn't get it passed through to Hass with 2 dongles I had. But thirdd time is a charm!

starsoccer · 2024-12-26T22:12:53Z

Does anyone have a list of adapters not effected?

Also Im not super clear from this thread how to confirm if this is the issue affecting me or not. Does bluetooth always fail to setup in HA? Or does it show its setup, but is just unusable?

NoLooseEnds · 2024-12-27T00:08:59Z

@starsoccer
I ended up buying an adapter with a chip with confirmed support. There is a list here: https://www.home-assistant.io/integrations/bluetooth/

starsoccer · 2024-12-27T14:50:04Z

@starsoccer I ended up buying an adapter with a chip with confirmed support. There is a list here: https://www.home-assistant.io/integrations/bluetooth/

Yeah I bought 2 different adapters on that list, but am having the same issue with both

robitsrl · 2025-01-29T06:07:54Z

Some issue with Yellow and CP4 and latest os 14.2

Cyberplan · 2025-01-30T08:16:29Z

Same Problem here

robitsrl · 2025-01-30T08:19:50Z

Fixed with full reboot

Cyberplan · 2025-01-30T08:35:43Z

Fixed with full reboot

Thanks that work also for me - HomeAssistant reboot is not Enough you must Rebbot the full System under Advanced Options

scottb721 · 2025-02-06T11:08:59Z

I'm trying an old BT Adaptor.
I get Success! Created configuration for Integrated System Solution Corp. None
but the get the Initializing loop.

A reboot didn't help.

home-assistant bot added the integration: bluetooth label May 2, 2023

home-assistant bot assigned bdraco May 2, 2023

This comment was marked as duplicate.

Sign in to view

bdraco added the waiting-for-upstream We're waiting for a change upstream label Aug 7, 2023

bdraco mentioned this issue May 4, 2024

Failed to start Bluetooth: adapter hci0 not found #114369

Closed

gmlupatelli mentioned this issue Jun 18, 2024

Airthings BLE stopped working when upgrading to 2024.5.1 #116898

Closed

BigThunderSR mentioned this issue Jun 19, 2024

Bluetooth tracker does not work with newer python - Can't run HA Core on python 3.11.2 because of dependency to pybluez==0.22 #89119

Open

Dwarfex mentioned this issue Jul 17, 2024

Bluetooth integration failing to initialize #121961

Closed

bcutter mentioned this issue Nov 2, 2024

"NetworkManager not correctly configured" + unsupported state warning home-assistant/operating-system#3602

Closed

watercrossing mentioned this issue Dec 4, 2024

Bluetooth adapter cannot be access tribut/homeassistant-docker-venv#39

Open

bluetooth integration constant state of initializing / retrying setup (bluetooth is broken with some adapters on newer linux kernels, kernel must be manually patched, workaround is to switch to ESPHome proxies instead) #92379

bluetooth integration constant state of initializing / retrying setup (bluetooth is broken with some adapters on newer linux kernels, kernel must be manually patched, workaround is to switch to ESPHome proxies instead) #92379

Comments

vlape commented May 2, 2023 • edited by bdraco Loading

Mod Issue Summary - Read First

The problem

What version of Home Assistant Core has the issue?

What was the last working version of Home Assistant Core?

What type of installation are you running?

Integration causing the issue

Link to integration documentation on our website

Diagnostics information

Example YAML snippet

Anything in the logs that might be useful for us?

Additional information

System Information

home-assistant bot commented May 2, 2023

codyc1515 commented May 4, 2023

wackla33 commented May 4, 2023

IkHier commented May 5, 2023 • edited Loading

wackla33 commented May 5, 2023

CheeseySandal commented May 5, 2023

Woersi86 commented May 5, 2023 • edited Loading

bdraco commented May 6, 2023

mukul-k commented May 6, 2023

bjorndegroot commented May 8, 2023

codyc1515 commented May 8, 2023

bjorndegroot commented May 11, 2023

St3fanBC commented May 12, 2023

dMopp commented May 12, 2023

codyc1515 commented May 12, 2023

bjorndegroot commented May 12, 2023

Automatically generated file; DO NOT EDIT.

Linux/x86 5.10.178 Kernel Configuration

dMopp commented May 12, 2023 • edited Loading

St3fanBC commented May 16, 2023

bjorndegroot commented May 26, 2023

vlape commented May 26, 2023

This comment was marked as duplicate.

This comment was marked as duplicate.

smart7324 commented Jul 24, 2023

sammcj commented Jul 31, 2023 • edited Loading

77degrees commented Aug 7, 2023

bdraco commented Aug 7, 2023

GRClark commented Aug 7, 2023

sergeolkhovik commented May 12, 2024

LAPDragnet commented May 13, 2024

sergeolkhovik commented May 13, 2024

sergeolkhovik commented May 13, 2024

bdraco commented May 29, 2024 • edited Loading

allergicapple commented Jun 6, 2024

hubertott commented Jun 14, 2024 • edited Loading

StahlTim commented Jun 15, 2024 • edited Loading

mitch1006 commented Aug 5, 2024

heibertelf commented Sep 7, 2024 • edited Loading

evilpig commented Sep 11, 2024

bcutter commented Nov 2, 2024 • edited Loading

Overview

So current summary for me:

So what does a final solution look like?!?

minmaxat commented Dec 2, 2024

ColtonYYZ commented Dec 7, 2024 • edited Loading

s-hell commented Dec 15, 2024 • edited Loading

ColtonYYZ commented Dec 16, 2024

starsoccer commented Dec 26, 2024

NoLooseEnds commented Dec 27, 2024

starsoccer commented Dec 27, 2024

robitsrl commented Jan 29, 2025

Cyberplan commented Jan 30, 2025

robitsrl commented Jan 30, 2025

Cyberplan commented Jan 30, 2025

scottb721 commented Feb 6, 2025

vlape commented May 2, 2023 •

edited by bdraco

Loading

IkHier commented May 5, 2023 •

edited

Loading

Woersi86 commented May 5, 2023 •

edited

Loading

dMopp commented May 12, 2023 •

edited

Loading

sammcj commented Jul 31, 2023 •

edited

Loading

bdraco commented May 29, 2024 •

edited

Loading

hubertott commented Jun 14, 2024 •

edited

Loading

StahlTim commented Jun 15, 2024 •

edited

Loading

heibertelf commented Sep 7, 2024 •

edited

Loading

bcutter commented Nov 2, 2024 •

edited

Loading

ColtonYYZ commented Dec 7, 2024 •

edited

Loading

s-hell commented Dec 15, 2024 •

edited

Loading