search

home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
72.18k stars 30.21k forks source link

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 1 year ago

vlape commented 1 year ago

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[bot] commented 1 year ago

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 commented 1 year ago

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 commented 1 year ago

I've been having the same problem for a week

IkHier commented 1 year ago

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

wackla33 commented 1 year ago

The solution for me was BLUETOOTH LOW ENERGY MONITOR

CheeseySandal commented 1 year ago

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 commented 1 year ago

+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 commented 1 year ago

Please see https://github.com/home-assistant/operating-system/issues/2485 https://github.com/home-assistant/operating-system/issues/2535

mukul-k commented 1 year ago

Same issue on my Home Assistant Yellow after updating.

bjorndegroot commented 1 year ago

Same issue here.

codyc1515 commented 1 year ago

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

bjorndegroot commented 1 year ago

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 commented 1 year ago

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

dMopp commented 1 year ago

Same :( HA Supervised

codyc1515 commented 1 year ago

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 commented 1 year ago

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 commented 1 year ago 

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 commented 1 year ago

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

bjorndegroot commented 1 year ago

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

vlape commented 1 year ago

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 commented 1 year ago

Running 2023.6.2 and still seeing this issue. Constantly initializing and retrying setup but never actually finishing/working.

plastbox commented 1 year ago

Just to add my voice to the choir: I've been seeing this since I set up my Yellow about two months ago with the goal of replacing my older RasPi HA setup. Always stay up to date with releases, and this has been a near constant companion.

smart7324 commented 1 year ago

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 commented 1 year ago

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 commented 1 year ago

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 commented 1 year ago

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 commented 1 year ago

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.

amoshydra commented 1 year ago

I can confirm ESP32 Bluetooth Proxy to be a workable solution for me.

For those who wonder how this is done:

  1. I purchase an ESP32 Development Board
  2. Install driver
  3. Flash the board with https://esphome.github.io/bluetooth-proxies/
  4. Follow the steps in esphome - Add to home assistant
  5. Update to HA OS 10.4, Core 2023.8.2
  6. Reboot Intel NUC
  7. (At this point my bluetooth devices are still connected, but hci0 is still unavailable)
  8. Remove existing Bluetooth device integration
  9. (Bluetooth device is still working)
orebla85 commented 1 year ago

I have the same problem. HA Core 2023.8.0 su Docker su Linux Debian. Bluetooth adaptor: ZEXMTE The bluetooth works for a couple of days then this error:

Logger: bluetooth_auto_recovery.recover Source: components/bluetooth/util.py:78 First occurred: 26 agosto 2023 alle ore 07:12:19 (9856 occurrences) Last logged: 20:40:51

Could not reset the power state of the Bluetooth adapter hci0 [8C:88:2B:61:2E:3A] due to timeout after 5 seconds Could not cycle the Bluetooth adapter hci0 [8C:88:2B:61:2E:3A]: [Errno 1] Operation not permitted Bluetooth adapter hci0 [8C:88:2B:61:2E:3A] could not be reset: Closing Bluetooth adapter hci0 [8C:88:2B:61:2E:3A] failed: [Errno 9] Bad file descriptor

SkyWalkerIcarus commented 1 year ago

question

The integrated Bluetooth on the Intel network card is used. When installing HAOS in VMware Workstation Pro in Windows, the HA prompts that a new device has been found, and an error occurs after clicking Configure.

log

Logger: bluetooth_auto_recovery.recover Source: runner.py:186 First occurred: 12:53:30 (31 occurrences) Last logged: 13:28:15

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

Logger: bluetooth_auto_recovery.recover Source: components/bluetooth/util.py:78 First occurred: 12:53:28 (124 occurrences) Last logged: 13:28:22

Could not determine the power state of the Bluetooth adapter hci0 [48:F1:7F:65:18:77] due to timeout after 5 seconds Could not cycle the Bluetooth adapter hci0 [48:F1:7F:65:18:77]: [Errno 38] Function not implemented Bluetooth adapter hci0 [48:F1:7F:65:18:77] could not be reset: Closing Bluetooth adapter hci0 [48:F1:7F:65:18:77] failed: [Errno 9] Bad file descriptor

Sep 27 05:20:19 homeassistant systemd[1]: run-docker-runtime\x2drunc-moby-0796d9651f82cbbc4dd7b671837c1afab34aa352a067130b074e6b0afc187146-runc.Nav9wC.mount: Deactivated successfully. Sep 27 05:20:20 homeassistant kernel: debugfs: File 'dut_mode' in directory 'hci0' already present! Sep 27 05:20:20 homeassistant kernel: Bluetooth: hci0: unexpected cc 0x0c12 length: 2 < 3 Sep 27 05:20:20 homeassistant kernel: Bluetooth: hci0: Opcode 0x c12 failed: -38 Sep 27 05:20:25 homeassistant systemd[1]: Stopped target Bluetooth Support. Sep 27 05:20:26 homeassistant kernel: usb 2-2.1: reset full-speed USB device number 4 using uhci_hcd Sep 27 05:20:26 homeassistant systemd[1]: Reached target Bluetooth Support. Sep 27 05:20:26 homeassistant kernel: Bluetooth: hci0: unexpected cc 0x0c12 length: 2 < 3 Sep 27 05:20:26 homeassistant kernel: Bluetooth: hci0: Opcode 0x c12 failed: -38 Sep 27 05:21:49 homeassistant systemd[1]: run-docker-runtime\x2drunc-moby-0796d9651f82cbbc4dd7b671837c1afab34aa352a067130b074e6b0afc187146-runc.AoS8eU.mount: Deactivated successfully. Sep 27 05:21:55 homeassistant kernel: debugfs: File 'dut_mode' in directory 'hci0' already present! Sep 27 05:21:55 homeassistant kernel: Bluetooth: hci0: unexpected cc 0x0c12 length: 2 < 3 Sep 27 05:21:55 homeassistant kernel: Bluetooth: hci0: Opcode 0x c12 failed: -38 Sep 27 05:22:00 homeassistant systemd[1]: Stopped target Bluetooth Support. Sep 27 05:22:01 homeassistant kernel: usb 2-2.1: reset full-speed USB device number 4 using uhci_hcd Sep 27 05:22:01 homeassistant systemd[1]: Reached target Bluetooth Support. Sep 27 05:22:01 homeassistant kernel: Bluetooth: hci0: unexpected cc 0x0c12 length: 2 < 3 Sep 27 05:22:01 homeassistant kernel: Bluetooth: hci0: Opcode 0x c12 failed: -38 Sep 27 05:22:20 homeassistant systemd[1]: run-docker-runtime\x2drunc-moby-0796d9651f82cbbc4dd7b671837c1afab34aa352a067130b074e6b0afc187146-runc.f8Ld6L.mount: Deactivated successfully. Sep 27 05:22:44 homeassistant systemd[1]: run-docker-runtime\x2drunc-moby-9dc6014d7dd4ba6a5d5f48c3dbf210fbd577a2e4a6fa171e13906bd1f5924490-runc.LrE36m.mount: Deactivated successfully. Sep 27 05:23:30 homeassistant kernel: debugfs: File 'dut_mode' in directory 'hci0' already present! Sep 27 05:23:30 homeassistant kernel: Bluetooth: hci0: unexpected cc 0x0c12 length: 2 < 3 Sep 27 05:23:30 homeassistant kernel: Bluetooth: hci0: Opcode 0x c12 failed: -38 Sep 27 05:23:35 homeassistant systemd[1]: Stopped target Bluetooth Support. Sep 27 05:23:36 homeassistant kernel: usb 2-2.1: reset full-speed USB device number 4 using uhci_hcd Sep 27 05:23:36 homeassistant systemd[1]: Reached target Bluetooth Support. Sep 27 05:23:36 homeassistant kernel: Bluetooth: hci0: unexpected cc 0x0c12 length: 2 < 3 Sep 27 05:23:36 homeassistant kernel: Bluetooth: hci0: Opcode 0x c12 failed: -38 Sep 27 05:23:50 homeassistant systemd[1]: run-docker-runtime\x2drunc-moby-0796d9651f82cbbc4dd7b671837c1afab34aa352a067130b074e6b0afc187146-runc.WjDqnN.mount: Deactivated successfully.

Testmangh commented 11 months ago

Same here - HA Core 2023.11.1 - Beelink mini S12 -

ssbarnea commented 10 months ago

I am having the the problem with Bluetooth on a MacMini from 2012 (core duo 2), fails to initialize. Here is some log that might be useful https://gist.github.com/ssbarnea/eb647871942af5a38fe1e17aa7f32ced - the interesting part is " BleakError while starting bluetooth; attempt: (2/3): [org.bluez.Error.InProgress] Operation already in progress"

dkebler commented 9 months ago

Kernel 6.6 is now LTS. I have lots of hardware bought in the last few months that have issue with various subsystems with anything less that 6.6. Now that 6.6 is LTS hassos should be upgraded (maybe a major upgrade).

https://github.com/home-assistant/operating-system/issues/2535#issuecomment-1868588689

https://github.com/home-assistant/operating-system/discussions/3020#discussion-5995726

# ha host logs -t kernel -n 1000000 -b 0 | grep Bluetooth | head -n 100
Dec 24 01:39:20 homeassistant kernel: Bluetooth: Core ver 2.22
Dec 24 01:39:20 homeassistant kernel: Bluetooth: HCI device and connection manager initialized
Dec 24 01:39:20 homeassistant kernel: Bluetooth: HCI socket layer initialized
Dec 24 01:39:20 homeassistant kernel: Bluetooth: L2CAP socket layer initialized
Dec 24 01:39:20 homeassistant kernel: Bluetooth: SCO socket layer initialized
Dec 24 01:39:35 homeassistant kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3
Dec 24 01:39:35 homeassistant kernel: Bluetooth: BNEP filters: protocol multicast
Dec 24 01:39:35 homeassistant kernel: Bluetooth: BNEP socket layer initialized
Dec 24 01:39:35 homeassistant kernel: Bluetooth: MGMT ver 1.22
Dec 24 01:39:14 homeassistant kernel: Bluetooth: RFCOMM TTY layer initialized
Dec 24 01:39:14 homeassistant kernel: Bluetooth: RFCOMM socket layer initialized
Dec 24 01:39:14 homeassistant kernel: Bluetooth: RFCOMM ver 1.11
Dec 24 01:43:30 homeassistant kernel: Bluetooth: hci0: unexpected event for opcode 0x2005
Dec 24 01:43:41 homeassistant kernel: Bluetooth: hci0: unexpected event for opcode 0x2005
prwood commented 8 months ago

I am having the the problem with Bluetooth on a MacMini from 2012 (core duo 2), fails to initialize. Here is some log that might be useful https://gist.github.com/ssbarnea/eb647871942af5a38fe1e17aa7f32ced - the interesting part is " BleakError while starting bluetooth; attempt: (2/3): [org.bluez.Error.InProgress] Operation already in progress"

Similar errors - running HA 2024.1.3 in a Docker container with the host being a MacMini5,1 running Debian Linux 12 with kernel 6.1.0-17. HA is able to access the Bluetooth device on initial boot of the host OS, and is able to discover and make some initial polls of some bluetooth sensors throughout the house, but shortly thereafter it fails, and only works again upon reboot. Here are some samples from the log:

hci0 (28:CF:DA:06:A0:B4): Failed to restart Bluetooth scanner: hci0 (28:CF:DA:06:A0:B4): Failed to start Bluetooth: [org.bluez.Error.NotReady] Resource Not Ready
10:20:21 PM – (ERROR) /usr/local/lib/python3.11/asyncio/events.py - message first occurred at 10:14:21 PM and shows up 13 times
Unexpected error while attempting USB reset of hci0: [Errno 25] Not a tty
10:20:21 PM – (ERROR) /usr/local/lib/python3.11/site-packages/bluetooth_auto_recovery/recover.py - message first occurred at 10:14:21 PM and shows up 25 times
Bluetooth adapter hci0 [28:CF:DA:06:A0:B4] could not be reset:
10:20:21 PM – (WARNING) runner.py - message first occurred at 10:14:21 PM and shows up 49 times
mill1000 commented 8 months ago

Similar errors - running HA 2024.1.3 in a Docker container with the host being a MacMini5,1 running Debian Linux 12 with kernel 6.1.0-17.

Have you updated your kernel to the latest? I've found that my Bluetooth issues went away with 6.1.69-1.

adamcornforth commented 8 months ago

Core 2024.1.3 fixed this issue for me 👍

prwood commented 8 months ago

Similar errors - running HA 2024.1.3 in a Docker container with the host being a MacMini5,1 running Debian Linux 12 with kernel 6.1.0-17.

Have you updated your kernel to the latest? I've found that my Bluetooth issues went away with 6.1.69-1.

I believe I am running the latest version of the kernel available on Debian 12 "Bookworm". If I do uname -r I get 6.1.0-17-amd64. However if I do cat /proc/version, the full string includes 6.1.69-1 which you mentioned. I am not sure which one is the Linux kernel version.

That being said, I have also tried this on Debian unstable/sid which is currently on kernel 6.6.11, and it has the same issue.

Clasper101 commented 8 months ago

I am also having this issue with Bluetooth on Home Assistant Operating system. image I am using Core 2024.1.3 Supervisor 2023.12.1 Operating System 11.4 Frontend 20240104.0 But it started before 2024.1.3, but I can't remember which version. It happened in 2023 too but then went away.

antz29 commented 8 months ago

Also having an issue with Bluetooth, since I upgraded to 2024.1.4 (the issue is still present in 2024.1.5).

I'm on a Rasberry Pi 4

Core 2024.1.5 Supervisor 2023.12.1 Operating System 11.4 Frontend 20240104.0

CleanShot 2024-01-20 at 23 32 32

CleanShot 2024-01-20 at 23 32 16

ZSamuels28 commented 8 months ago

This issue just recently started happening for me as well. Was fine for a while, but now experiencing it.

Running HA on a Raspberry Pi 5 in Docker

Core 2024.1.5 Frontend 20240104.0

recse commented 8 months ago

Me too, same issue in last Core/Frontend docker container.

codyc1515 commented 8 months ago

Seems like most people here facing issues are using Docker - I was too.

My issues went away when I moved to HA OS. There are a significant number of tweaks behind the scenes that make Bluetooth perform better in the OS. I have not seen this issue for some months now subsequent.

hughobrien commented 8 months ago

I'm experiencing this on NixOS with no Docker in sight so I don't think that's related.

Jan 21 12:45:09 acer hass[1195]: 2024-01-21 12:45:09.029 WARNING (MainThread) [homeassistant.components.bluetooth_le_tracker.device_tracker] No Bluetooth LE devices to track!
Jan 21 12:45:09 acer hass[1195]: 2024-01-21 12:45:09.029 ERROR (MainThread) [homeassistant.components.device_tracker] Error setting up platform legacy bluetooth_le_tracker
Jan 21 12:45:09 acer hass[1195]: 2024-01-21 12:45:09.033 ERROR (SyncWorker_8) [homeassistant.components.bluetooth_tracker.device_tracker] Couldn't discover bluetooth devices: [Errno 19] No such device
Jan 21 12:45:09 acer hass[1195]: 2024-01-21 12:45:09.057 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Jan 21 12:45:09 acer hass[1195]: Traceback (most recent call last):
Jan 21 12:45:09 acer hass[1195]:   File "/nix/store/nwv61zxks3a5354ia2l0x12n91i33261-python3.11-pybluez-unstable-2022-01-28/lib/python3.11/site-packages/bluetooth/bluez.py", line 322, in _gethcisock
Jan 21 12:45:09 acer hass[1195]:     sock = _bt.hci_open_dev (device_id)
Jan 21 12:45:09 acer hass[1195]:            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 21 12:45:09 acer hass[1195]: _bluetooth.error: no available bluetoot devices
Jan 21 12:45:09 acer hass[1195]: During handling of the above exception, another exception occurred:
Jan 21 12:45:09 acer hass[1195]: Traceback (most recent call last):
Jan 21 12:45:09 acer hass[1195]:   File "/nix/store/gx2n17v083h4p8jf34cibp0qz4mrwxph-homeassistant-2024.1.3/lib/python3.11/site-packages/homeassistant/components/bluetooth_tracker/device_tracker.py", line 201, in update_bluetooth
Jan 21 12:45:09 acer hass[1195]:     await perform_bluetooth_update()
Jan 21 12:45:09 acer hass[1195]:   File "/nix/store/gx2n17v083h4p8jf34cibp0qz4mrwxph-homeassistant-2024.1.3/lib/python3.11/site-packages/homeassistant/components/bluetooth_tracker/device_tracker.py", line 164, in perform_bluetooth_update
Jan 21 12:45:09 acer hass[1195]:     friendly_name = await hass.async_add_executor_job(lookup_name, mac)
Jan 21 12:45:09 acer hass[1195]:                     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 21 12:45:09 acer hass[1195]:   File "/nix/store/asiphbpiy2gmidfm3xbwcikayhs66289-python3-3.11.7/lib/python3.11/concurrent/futures/thread.py", line 58, in run
Jan 21 12:45:09 acer hass[1195]:     result = self.fn(*self.args, **self.kwargs)
Jan 21 12:45:09 acer hass[1195]:              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 21 12:45:09 acer hass[1195]:   File "/nix/store/gx2n17v083h4p8jf34cibp0qz4mrwxph-homeassistant-2024.1.3/lib/python3.11/site-packages/homeassistant/components/bluetooth_tracker/device_tracker.py", line 124, in lookup_name
Jan 21 12:45:09 acer hass[1195]:     return bluetooth.lookup_name(mac, timeout=5)  # type: ignore[no-any-return]
Jan 21 12:45:09 acer hass[1195]:            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 21 12:45:09 acer hass[1195]:   File "/nix/store/nwv61zxks3a5354ia2l0x12n91i33261-python3.11-pybluez-unstable-2022-01-28/lib/python3.11/site-packages/bluetooth/bluez.py", line 84, in lookup_name
Jan 21 12:45:09 acer hass[1195]:     sock = _gethcisock ()
Jan 21 12:45:09 acer hass[1195]:            ^^^^^^^^^^^^^^
Jan 21 12:45:09 acer hass[1195]:   File "/nix/store/nwv61zxks3a5354ia2l0x12n91i33261-python3.11-pybluez-unstable-2022-01-28/lib/python3.11/site-packages/bluetooth/bluez.py", line 325, in _gethcisock
Jan 21 12:45:09 acer hass[1195]:     e.args[1])
Jan 21 12:45:09 acer hass[1195]:     ~~~~~~^^^
Jan 21 12:45:09 acer hass[1195]: IndexError: tuple index out of range
Jan 21 12:45:12 acer hass[1195]: 2024-01-21 12:45:12.185 WARNING (MainThread) [homeassistant.setup] Setup of tplink is taking over 10 seconds.
Jan 21 12:45:21 acer hass[1195]: 2024-01-21 12:45:21.026 ERROR (SyncWorker_1) [homeassistant.components.bluetooth_tracker.device_tracker] Couldn't discover bluetooth devices: [Errno 19] No such device
Jan 21 12:45:21 acer hass[1195]: 2024-01-21 12:45:21.029 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Jan 21 12:45:21 acer hass[1195]: Traceback (most recent call last):
Jan 21 12:45:21 acer hass[1195]:   File "/nix/store/nwv61zxks3a5354ia2l0x12n91i33261-python3.11-pybluez-unstable-2022-01-28/lib/python3.11/site-packages/bluetooth/bluez.py", line 322, in _gethcisock
Jan 21 12:45:21 acer hass[1195]:     sock = _bt.hci_open_dev (device_id)
Jan 21 12:45:21 acer hass[1195]:            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 21 12:45:21 acer hass[1195]: _bluetooth.error: no available bluetoot devices
Jan 21 12:45:21 acer hass[1195]: During handling of the above exception, another exception occurred:
Jan 21 12:45:21 acer hass[1195]: Traceback (most recent call last):
Jan 21 12:45:21 acer hass[1195]:   File "/nix/store/gx2n17v083h4p8jf34cibp0qz4mrwxph-homeassistant-2024.1.3/lib/python3.11/site-packages/homeassistant/components/bluetooth_tracker/device_tracker.py", line 201, in update_bluetooth
Jan 21 12:45:21 acer hass[1195]:     await perform_bluetooth_update()
Jan 21 12:45:21 acer hass[1195]:   File "/nix/store/gx2n17v083h4p8jf34cibp0qz4mrwxph-homeassistant-2024.1.3/lib/python3.11/site-packages/homeassistant/components/bluetooth_tracker/device_tracker.py", line 164, in perform_bluetooth_update
Jan 21 12:45:21 acer hass[1195]:     friendly_name = await hass.async_add_executor_job(lookup_name, mac)
Jan 21 12:45:21 acer hass[1195]:                     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 21 12:45:21 acer hass[1195]:   File "/nix/store/asiphbpiy2gmidfm3xbwcikayhs66289-python3-3.11.7/lib/python3.11/concurrent/futures/thread.py", line 58, in run
Jan 21 12:45:21 acer hass[1195]:     result = self.fn(*self.args, **self.kwargs)
Jan 21 12:45:21 acer hass[1195]:              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 21 12:45:21 acer hass[1195]:   File "/nix/store/gx2n17v083h4p8jf34cibp0qz4mrwxph-homeassistant-2024.1.3/lib/python3.11/site-packages/homeassistant/components/bluetooth_tracker/device_tracker.py", line 124, in lookup_name
Jan 21 12:45:21 acer hass[1195]:     return bluetooth.lookup_name(mac, timeout=5)  # type: ignore[no-any-return]
Jan 21 12:45:21 acer hass[1195]:            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 21 12:45:21 acer hass[1195]:   File "/nix/store/nwv61zxks3a5354ia2l0x12n91i33261-python3.11-pybluez-unstable-2022-01-28/lib/python3.11/site-packages/bluetooth/bluez.py", line 84, in lookup_name
Jan 21 12:45:21 acer hass[1195]:     sock = _gethcisock ()
Jan 21 12:45:21 acer hass[1195]:            ^^^^^^^^^^^^^^
Jan 21 12:45:21 acer hass[1195]:   File "/nix/store/nwv61zxks3a5354ia2l0x12n91i33261-python3.11-pybluez-unstable-2022-01-28/lib/python3.11/site-packages/bluetooth/bluez.py", line 325, in _gethcisock
Jan 21 12:45:21 acer hass[1195]:     e.args[1])
Jan 21 12:45:21 acer hass[1195]:     ~~~~~~^^^
Jan 21 12:45:21 acer hass[1195]: IndexError: tuple index out of range
Jan 21 12:45:24 acer hass[1195]: 2024-01-21 12:45:24.808 WARNING (MainThread) [bluetooth_auto_recovery.recover] Could not cycle the Bluetooth adapter hci0 [08:BE:AC:35:85:44]: bind(): bad family
Jan 21 12:45:29 acer hass[1195]: 2024-01-21 12:45:29.810 WARNING (MainThread) [bluetooth_auto_recovery.recover] Bluetooth adapter hci0 [08:BE:AC:35:85:44] could not be reset:
Jan 21 12:45:33 acer hass[1195]: 2024-01-21 12:45:33.028 ERROR (SyncWorker_10) [homeassistant.components.bluetooth_tracker.device_tracker] Couldn't discover bluetooth devices: [Errno 19] No such device
hughobrien commented 8 months ago

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
Failed to start discovery: org.bluez.Error.NotReady

I was getting org.bluez.Error.NotReady. A quick search suggested rfkill.

hugh@asus ~ 25s
❯ rfkill list                                                                      
0: hci0: Bluetooth
    Soft blocked: yes
    Hard blocked: no
1: asus-wlan: Wireless LAN
    Soft blocked: yes
    Hard blocked: no
2: asus-bluetooth: Bluetooth
    Soft blocked: yes
    Hard blocked: no

This system has an onboard BT and WiFi that I don't want to use, (ethernet and the BT is non-LE), so I had added an Edimax USB BT device (Bus 001 Device 002: ID 7392:c611 Edimax Technology Co., Ltd Edimax Bluetooth Adapter).

But that shouldn't be rfkilled. 

hugh@asus ~
❯ sudo rfkill unblock 0 
❯ 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.

vmicahbray commented 8 months ago

I am experiencing this issue as well on a Home Assistant Yellow with an RPi CM4.

Core 2024.1.5 Supervisor 2023.12.1 Operating System 11.4 Frontend 20240104.0

image

dennis3484 commented 8 months ago

Same here on a Raspberry Pi 4. The issue started with the upgrade to Core 2024.1.2.

To recover the Bluetooth functionality, I have to reboot the system. It usually works then for a few days, before entering the "Failed setup, will retry" state (which requires another reboot).

Core: 2024.1.5 Supervisor: 2023.12.1 Operating System: 11.4 Frontend: 20240104.0

ZSamuels28 commented 8 months ago

Rebooting fixed the issue for me. Will see if it reoccurs like some other users have stated.

Fontie1 commented 8 months ago

Clicking on the 3 dots then configuration ticking passive scanning solved it for me

LAPDragnet commented 8 months ago

Clicking on the 3 dots then configuration ticking passive scanning solved it for me

Does not work for me.

I have ordered an USB BLE 5.0 adapter to see if that would work better than the built-in one.

GitHubGoody commented 8 months ago

Clicking on the 3 dots then configuration ticking passive scanning solved it for me

Same for me after updating to 2024.1.? (currently 2024.1.6). Raspberry Pi 4 integrated Bluetooth.