ZHA Setup fails and crashes Home Assistant

tonylweil · August 30, 2024, 6:36pm

I have a brand new empty instance of Home Assistant (OS 13.1, Core 2024.8.3) running on VirtualBox 7.20 (with Extension Pack) on Windows 10.

I have tried to load the ZHA Integration with the Sonoff Zigbee 3.0 USB Dongle Plus. Home Assistant crashes just after I begin the installation. The same thing happens when I try to use a Home Assistant Connect ZBT-1 dongle. This seems like it should be such a simple operation. Here are the details:

I install the dongle into a USB port with a USB extension cable.
I capture the USB port in VirtualBox and can see the Dongle in the Home Assistant Settings>Devices and services and in the VM Settings.
In Settings>Hardware>All Hardware>USB, I see: ttyUSB0/dev/serial/by-id/usb-ITead_Sonoff_Zigbee_3.0_USB_Dongle_Plus_9cc386a031fded119f4c0b65024206e6-if00-port0
I select Add Integration and select Zigbee Home Automation.
I select the discovered Sonoff Zigbee dongle and press “Submit” in the dialog box that says for "Do you want to setup the “Sonoff Zigbee 3.0 USB Dongle Plus”
I select “Erase network settings and create new network” in the Network Formation dialog box. (I have also tried the “Keep radio network settings” with the same results.)
The dialog box says “loading next step for zha” and the icon just spins for 5-10 minutes. At the same time, the cursor in the Home Assistant CLI stops blinking. I can no longer ping the Home Assistant IP address and the VM becomes unresponsive
Eventually the dialog box says ERROR. At the bottom it says "Connection lost. Reconnecting.
I cannot shut down the VM gracefully and have to kill VirtualBox with Windows Task Manager
I restart the VirtualBox and the Home Assistant VM.
I check all the logs in Settings>System>Logs. I search for zha, sonoff and usb, but there is nothing helpful there.

obliojim · August 31, 2024, 10:52pm

Same problem here. OS/X, Virtual Box, similar circumstances, same device.

nickrout · August 31, 2024, 11:13pm

There will be nothing in the current log because the log file starts again when ha restarts. Look instead at home-assistant.log.1

tonylweil · September 1, 2024, 12:00pm

I gave up and installed zigbee2mqtt which is working perfectly. It was a little harder to configure, but there are great YouTube tutorials.

I did figure out how to enable zha debug logs and saw a ton of info in log1 but decided to try the other path.

Gibber · September 4, 2024, 7:16pm

Exact same setup and same problem! I just installed core 2024.9.0. No help.

home-assistant.log.1 only shows:

2024-09-04 12:56:51.849 WARNING (Recorder) [homeassistant.components.recorder.migration] The database is about to upgrade from schema version 45 to 47
2024-09-04 12:56:51.953 WARNING (Recorder) [homeassistant.components.recorder.migration] Upgrade to version 46 done
2024-09-04 12:56:51.961 WARNING (Recorder) [homeassistant.components.recorder.migration] Upgrade to version 47 done

Supervisor log had more details but no errors and no mention of ZigBee or Sonoff.

Gibber · September 4, 2024, 7:43pm

With log level set to debug the core log shows:
2024-09-04 13:35:18.812 INFO (SyncWorker_3) [homeassistant.loader] Loaded zha from homeassistant.components.zha

2024-09-04 13:35:20.803 DEBUG (MainThread) [homeassistant.loader] Importing platforms for zha executor=[‘config_flow’] loop= took 1.98s

LinqLover · January 19, 2025, 10:44pm

I’m observing something similar with a Qivicon Telegesis stick. For me, Home Assistant already crashes when pressing “Submit” in the dialog box. Running HAOS in a VirtualBox VM, full hang, even the text caret in the VM window stops blinking. Remarkably, also VirtualBox itself crashes (“is not responding”) when hitting the close box, meaning that I could not shut down the VM by closing the window but I had to kill the VM process.

Logs (set default level in logger to debug, here is a hopefully relevant excerpt):

2025-01-19 23:20:16.413 DEBUG (MainThread) [homeassistant.components.homeassistant_hardware] Add-on store info: {'detached': False, 'apparmor': 'default', 'auth_api': False, 'docker_api': False, 'full_access': False, 'homeassistant_api': False, 'host_network': True, 'host_pid': False, 'ingress': False, 'long_description': '# Home Assistant Add-on: SiliconLabs Zigbee/OpenThread Multiprotocol Add-on\n\nZigbee/OpenThread Multiprotocol container for Silicon Labs based radios such as\nHome Assistant Yellow, Home Assistant SkyConnect, and Home Assistant Connect ZBT-1.\n\n![Supports armv7 Architecture][armv7-shield]\n![Supports aarch64 Architecture][aarch64-shield]\n![Supports amd64 Architecture][amd64-shield]\n\n## About\n\nThis add-on allows you to use Zigbee and OpenThread protocol simultaneous on a\nsingle Silicon Labs based radio. The radio needs the RCP Multi-PAN firmware\ninstalled to support multiple IEEE 802.15.4 Personal Area Networks (PAN). The\naddon has been tested with EFR32 Series 2 based radios.\n\n[armv7-shield]: https://img.shields.io/badge/armv7-yes-green.svg\n[aarch64-shield]: https://img.shields.io/badge/aarch64-yes-green.svg\n[amd64-shield]: https://img.shields.io/badge/amd64-yes-green.svg\n', 'rating': 3, 'signed': False, 'supervisor_api': True, 'supervisor_role': 'default', 'arch': ['armv7', 'aarch64', 'amd64'], 'documentation': True, 'advanced': False, 'available': True, 'build': False, 'description': 'Zigbee and OpenThread multiprotocol add-on', 'homeassistant': '2024.1.0', 'icon': True, 'logo': True, 'name': 'Silicon Labs Multiprotocol', 'repository': 'core', 'slug': 'core_silabs_multiprotocol', 'stage': 'experimental', 'update_available': False, 'url': 'https://github.com/home-assistant/addons/tree/master/silabs-multiprotocol\n', 'version_latest': '2.4.5', 'version': None, 'installed': False}
2025-01-19 23:20:16.413 DEBUG (MainThread) [homeassistant.components.zha.radio_manager] Attempting to probe radio type RadioType.ezsp
2025-01-19 23:20:16.415 DEBUG (MainThread) [zigpy.ota] Registering new OTA provider: Ledvance(url='https://api.update.ledvance.com/v1/zigbee/firmwares', manufacturer_ids=(4489, 4364))
2025-01-19 23:20:16.416 DEBUG (MainThread) [zigpy.ota] Registering new OTA provider: Sonoff(url=None, manufacturer_ids=(4742,))
2025-01-19 23:20:16.417 DEBUG (MainThread) [zigpy.ota] Registering new OTA provider: Inovelli(url=None, manufacturer_ids=(4655,))
2025-01-19 23:20:16.417 DEBUG (MainThread) [zigpy.ota] Registering new OTA provider: ThirdReality(url=None, manufacturer_ids=(4659, 4877, 5127))
2025-01-19 23:20:16.419 DEBUG (bellows.thread_0) [asyncio] Using selector: EpollSelector
2025-01-19 23:20:16.421 DEBUG (bellows.thread_0) [zigpy.serial] Opening a serial connection to '/dev/ttyUSB0' (baudrate=115200, xonxoff=True, rtscts=False)
2025-01-19 23:20:16.496 DEBUG (bellows.thread_0) [zigpy.serial] Connection made: <bellows.ash.AshProtocol object at 0x7f0c5a1caba0>
2025-01-19 23:20:16.497 DEBUG (MainThread) [bellows.ezsp] Resetting EZSP
2025-01-19 23:20:16.498 DEBUG (bellows.thread_0) [bellows.uart] Resetting ASH
2025-01-19 23:20:16.499 DEBUG (bellows.thread_0) [bellows.ash] Sending frame CANCEL + RstFrame() + FLAG
2025-01-19 23:20:16.499 DEBUG (bellows.thread_0) [bellows.ash] Sending data  1ac038bc7e

2025-01-19 23:20:21.622 DEBUG (bellows.thread_0) [zigpy.serial] Waiting for serial port to close
2025-01-19 23:20:21.629 DEBUG (bellows.thread_0) [zigpy.serial] Connection lost: None
2025-01-19 23:20:21.630 DEBUG (bellows.thread_0) [bellows.uart] Connection lost: None
2025-01-19 23:20:21.630 DEBUG (MainThread) [zigpy.application] Connection to the radio has been lost: None
2025-01-19 23:20:21.632 DEBUG (MainThread) [zigpy.application] Failed to probe with config {'path': '/dev/ttyUSB0', 'baudrate': 115200, 'flow_control': None}
Traceback (most recent call last):
  File "/usr/local/lib/python3.13/site-packages/bellows/uart.py", line 109, in reset
    return await self._reset_future
           ^^^^^^^^^^^^^^^^^^^^^^^^
asyncio.exceptions.CancelledError

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

Traceback (most recent call last):
  File "/usr/local/lib/python3.13/site-packages/zigpy/application.py", line 627, in probe
    await app.connect()
  File "/usr/local/lib/python3.13/site-packages/bellows/zigbee/application.py", line 150, in connect
    await self._ezsp.connect(use_thread=self.config[CONF_USE_THREAD])
  File "/usr/local/lib/python3.13/site-packages/bellows/ezsp/__init__.py", line 138, in connect
    await self.startup_reset()
  File "/usr/local/lib/python3.13/site-packages/bellows/ezsp/__init__.py", line 127, in startup_reset
    await self.reset()
  File "/usr/local/lib/python3.13/site-packages/bellows/ezsp/__init__.py", line 146, in reset
    await self._gw.reset()
  File "/usr/local/lib/python3.13/site-packages/bellows/uart.py", line 108, in reset
    async with asyncio_timeout(RESET_TIMEOUT):
               ~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/asyncio/timeouts.py", line 116, in __aexit__
    raise TimeoutError from exc_val
TimeoutError
2025-01-19 23:20:21.645 DEBUG (MainThread) [zigpy.ota] Registering new OTA provider: Ledvance(url='https://api.update.ledvance.com/v1/zigbee/firmwares', manufacturer_ids=(4489, 4364))
2025-01-19 23:20:21.645 DEBUG (MainThread) [zigpy.ota] Registering new OTA provider: Sonoff(url=None, manufacturer_ids=(4742,))
2025-01-19 23:20:21.645 DEBUG (MainThread) [zigpy.ota] Registering new OTA provider: Inovelli(url=None, manufacturer_ids=(4655,))
2025-01-19 23:20:21.645 DEBUG (MainThread) [zigpy.ota] Registering new OTA provider: ThirdReality(url=None, manufacturer_ids=(4659, 4877, 5127))
2025-01-19 23:20:21.646 DEBUG (bellows.thread_0) [asyncio] Using selector: EpollSelector
2025-01-19 23:20:21.648 DEBUG (bellows.thread_0) [zigpy.serial] Opening a serial connection to '/dev/ttyUSB0' (baudrate=57600, xonxoff=True, rtscts=False)

2025-01-19 23:20:22.646 WARNING (bellows.thread_0) [homeassistant.util.executor] Thread[SyncWorker_0] is still running at shutdown: File "/usr/local/lib/python3.13/threading.py", line 1012, in _bootstrap
    self._bootstrap_inner()
  File "/usr/local/lib/python3.13/threading.py", line 1041, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.13/threading.py", line 992, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.13/concurrent/futures/thread.py", line 93, in _worker
    work_item.run()
  File "/usr/local/lib/python3.13/concurrent/futures/thread.py", line 59, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.13/site-packages/serial/serialposix.py", line 533, in close
    os.close(self.fd)
2025-01-19 23:20:23.545 WARNING (bellows.thread_0) [homeassistant.util.executor] Thread[SyncWorker_0] is still running at shutdown: File "/usr/local/lib/python3.13/threading.py", line 1012, in _bootstrap
    self._bootstrap_inner()
  File "/usr/local/lib/python3.13/threading.py", line 1041, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.13/threading.py", line 992, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.13/concurrent/futures/thread.py", line 93, in _worker
    work_item.run()
  File "/usr/local/lib/python3.13/concurrent/futures/thread.py", line 59, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.13/site-packages/serial/serialposix.py", line 533, in close
    os.close(self.fd)

What else can we do to debug this issue?