Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

bluetooth 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

Open
vlape opened this issue May 2, 2023 · 87 comments
Assignees
Labels
integration: bluetooth waiting-for-upstream We're waiting for a change upstream

Comments

@vlape
Copy link

vlape commented May 2, 2023

Mod Issue Summary - Read First

See https://lore.kernel.org/linux-bluetooth/0de3f0d0d5eb6d83cfc8d90cbb2b1ba1@agner.ch/T/#mb094e06d495879436ce9a8722ad7ad87527ea74b

A summary:


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
Copy link

home-assistant bot commented May 2, 2023

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
Copy link
Contributor

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
Copy link

wackla33 commented May 4, 2023

I've been having the same problem for a week

@IkHier
Copy link

IkHier commented May 5, 2023

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

@wackla33
Copy link

wackla33 commented May 5, 2023

The solution for me was BLUETOOTH LOW ENERGY MONITOR

@CheeseySandal
Copy link

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
Copy link

Woersi86 commented May 5, 2023

+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
Copy link
Member

bdraco commented May 6, 2023

@mukul-k
Copy link

mukul-k commented May 6, 2023

Same issue on my Home Assistant Yellow after updating.

@bjorndegroot
Copy link

Same issue here.

@codyc1515
Copy link
Contributor

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

@bjorndegroot
Copy link

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
Copy link

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

@dMopp
Copy link

dMopp commented May 12, 2023

Same :( HA Supervised

@codyc1515
Copy link
Contributor

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
Copy link

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.

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
Copy link

dMopp commented May 12, 2023

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
Copy link

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

@bjorndegroot
Copy link

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

@vlape
Copy link
Author

vlape commented May 26, 2023

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>

@GRClark

This comment was marked as duplicate.

@plastbox

This comment was marked as duplicate.

@smart7324
Copy link

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
Copy link

sammcj commented Jul 31, 2023

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
Copy link

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
Copy link
Member

bdraco commented Aug 7, 2023

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
Copy link

GRClark commented Aug 7, 2023

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.

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

Does that version has any refering fixes for this issue?

https://github.com/home-assistant/operating-system/releases

So no?

@angainor
Copy link

Does that version has any refering fixes for this issue?

https://github.com/home-assistant/operating-system/releases

So no?

Dunno, didn't read the changelog. But it works now, so I'm happy.

@avandorp
Copy link

avandorp commented Feb 23, 2024

Running HA OS as a VM on Debian 12: Bluetooth works flawlessly on the host, but haos 11.5 and 12.0.rc1 always report Bluetooth: hci0: command 0xfc05 tx timeout and

Could not cycle the Bluetooth adapter hci0 [00:00:00:00:00:00]: [Errno 110] Operation timed out
Closing Bluetooth adapter hci0 [00:00:00:00:00:00] failed: [Errno 9] Bad file descriptor
There are no BT controllers present in the system!
hciNone [00:00:00:00:00:00] seems not to exist (anymore), check BT interface mac address in your settings; Available adapters: {}

Using 11.5 supervised on Debian 12 works when installing bluez (making the installation unhealthy).
This is all with an Intel on board BT device.

EDIT: Got it running by blacklisting btintel and btusb on the host machine.

@bobbravo2
Copy link

Adding how I was finally able to get HA Yellow running HAOS to correctly use the on-board bluetooth.

  1. Shutdown the Yellow.
  2. Remove USB stick for Root Access.
  3. Restart the yellow.
  4. Re-Add the newly discovered Bluetooth adapter with a MAC address in the UI.

Okay I think I solved my own version of this issue, startup bluetoothctl and try and run scan le.
❯ bluetoothctl
hci0 new_settings: bondable ssp br/edr le secure-conn
Agent registered
[CHG] Controller 08:BE:AC:35:85:44 Pairable: yes
[bluetooth]# scan le
Discovery started
[CHG] Controller 08:BE:AC:35:85:44 Discovering: yes
[NEW] Device 58:93:D8:8A:EA:D3 58-93-D8-8A-EA-D3
[NEW] Device 49:06:87:AC:7D:EF 49-06-87-AC-7D-EF


And whadya know, Home assistant is happy again.

Props / thanks to @hughobrien for the above. While my specific issue was not directly fixed in the same way, it was useful to be able to log in via SSH, and bluetoothctl to get observability into that layer of the stack, and seeing the fix resolve! Cheers!

@bearhntr
Copy link

BL

Please elaborate...what is this "BLUETOOTH LOW ENERGY MONITOR" ??

@soadzoor
Copy link

I used my usb bluetooth dongle for almost 2 years happily on my odroid c2 with home assistant os. I always upgrade to the latest available version, when it notifies me. I started having this BT issue 1-2 month ago. If I go to devices and hit the 3 dots menu on the bluetooth device, and select "reload", then it usually works again for 6-15 hours, but eventually my BT adapter shuts down again. So I always have to reload manually daily.

I thought it's a hardware issue (it's an old asus dongle), so I bought another BT dongle (realtek), but I'm having the same issue with the new one as well, so I'm pretty sure it's not the dongle's fault.

Any workarounds/fixes on the corner?

@soadzoor
Copy link

I used my usb bluetooth dongle for almost 2 years happily on my odroid c2 with home assistant os. I always upgrade to the latest available version, when it notifies me. I started having this BT issue 1-2 month ago. If I go to devices and hit the 3 dots menu on the bluetooth device, and select "reload", then it usually works again for 6-15 hours, but eventually my BT adapter shuts down again. So I always have to reload manually daily.

I thought it's a hardware issue (it's an old asus dongle), so I bought another BT dongle (realtek), but I'm having the same issue with the new one as well, so I'm pretty sure it's not the dongle's fault.

Any workarounds/fixes on the corner?

For the record, it seems the issue was hardware related afterall, the USB ports on my odroid c2 were disconnecting more and more frequently... I ended up buying a new rPi 5, and all these problems are gone now for me

@romanad
Copy link

romanad commented Apr 30, 2024

The solution for me was BLUETOOTH LOW ENERGY MONITOR

Could you please explain a little more about BLUETOOTH LOW ENERGY MONITOR - should I turn it on or off and how exactly do I do it?

@LAPDragnet
Copy link

I have tried with the built-in (older) BT device as well as a brand new BT 5.0 USB device. Same problem with both.
Really annoying.
(Generic x86)

@sergeolkhovik
Copy link

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
Copy link

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
Copy link

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
Copy link

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
Copy link
Member

bdraco commented May 29, 2024

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
Copy link

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
Copy link

hubertott commented Jun 14, 2024

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
Copy link

StahlTim commented Jun 15, 2024

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
Copy link

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
Copy link

heibertelf commented Sep 7, 2024

Core 2024.9.1
Supervisor 2024.08.0
Operating System 13.1
Frontend 20240906.0
Up-to-date HAOS on Intel NUC integrated BT
image
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
Copy link

evilpig commented Sep 11, 2024

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

@bcutter
Copy link

bcutter commented Nov 2, 2024

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):

  1. Host booted at 2024-09-30 18:31, last HA Core restart at 2024-10-01 18:47.

  2. 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.

  3. 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).

  4. 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.

  5. 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.

  6. 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

grafik
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.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
integration: bluetooth waiting-for-upstream We're waiting for a change upstream
Projects
None yet
Development

No branches or pull requests