I have newly installed Home Assistant, and added ~26 Zigbee devices today. First, it seemed to go well, but after a while, I was not able to add more devices until I restarted the computer. After another reset, the ZHA integration was stuck in an “Initializing” / “Failed setup, will retry” loop. I tried deleting and adding the integration again, with the same result.
Setup:
- Intel NUC with Proxmox
- Ubuntu VM with Aeotec Z Stick 7 (Z-Wave) and SMLIGHT SLZB-07 (Zigbee) attached to that VM (Note: They use the same USB-serial converter, and might be confused by auto probing software?)
- Home Assistant 2024.4.1 in Docker in Ubuntu VM
- Zigbee runs in ZHA, Z-Wave in separate zwave-js
Based on the logs, it seems that it starts initializing the network, but at some point it gets interrupted by universal_silabs_flasher
probing for bootloaders.
Below is a partial excerpt from the logs.
# I guess this is regular Zigbee stuff during initialization
2024-04-06 18:34:31.612 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'6430a1a9602a15be6eb07e'
2024-04-06 18:34:31.612 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2024-04-06 18:34:31.612 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received sendUnicast: [<EmberStatus.SUCCESS: 0>, 12]
2024-04-06 18:34:31.641 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'7430b1a9702a77eaa8f27fdb55c01c959c4dec8d37a47e'
2024-04-06 18:34:31.641 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2024-04-06 18:34:31.642 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received trustCenterJoinHandler: [0x5862, dc:8e:95:ff:fe:35:66:f1, <EmberDeviceUpdate.STANDARD_SECURITY_SECURED_REJOIN: 0>, <EmberJoinDecision.NO_ACTION: 3>, 0x26cb]
2024-04-06 18:34:31.642 DEBUG (MainThread) [bellows.zigbee.application] Received trustCenterJoinHandler frame with [0x5862, dc:8e:95:ff:fe:35:66:f1, <EmberDeviceUpdate.STANDARD_SECURITY_SECURED_REJOIN: 0>, <EmberJoinDecision.NO_ACTION: 3>, 0x26cb]
2024-04-06 18:34:31.642 INFO (MainThread) [zigpy.application] Device 0x5862 (dc:8e:95:ff:fe:35:66:f1) joined the network
2024-04-06 18:34:31.642 DEBUG (MainThread) [zigpy.device] [0x5862] Cancelling old group rescan
2024-04-06 18:34:31.642 DEBUG (MainThread) [zigpy.zcl] [0x5862:1:0x0004] Sending request header: ZCLHeader(frame_control=FrameControl<0x01>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=False, direction=<Direction.Client_to_Server: 0>, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=3, command_id=2, *direction=<Direction.Client_to_Server: 0>)
2024-04-06 18:34:31.642 DEBUG (MainThread) [zigpy.zcl] [0x5862:1:0x0004] Sending request: get_membership(groups=[])
2024-04-06 18:34:31.643 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(timestamp=datetime.datetime(2024, 4, 6, 18, 34, 31, 643027, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x5862), dst_ep=1, source_route=None, extended_timeout=False, tsn=3, profile_id=260, cluster_id=4, data=Serialized[b'\x01\x03\x02\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2024-04-06 18:34:31.643 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x5862, EmberApsFrame(profileId=260, clusterId=4, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=3), 27, b'\x01\x03\x02\x00')
2024-04-06 18:34:31.643 DEBUG (Thread-112) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7e77978e2110>, 'UPDATE devices_v12\n SET last_seen=:ts\n WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1712428471.642384, 'ieee': dc:8e:95:ff:fe:35:66:f1, 'min_update_delta': 30.0})
2024-04-06 18:34:31.643 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'403121a9602a15d001904b21aa5493099d4e27a8f6ca6688ffc6e50f7e'
2024-04-06 18:34:31.643 DEBUG (Thread-112) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7e77978e2110>, 'UPDATE devices_v12\n SET last_seen=:ts\n WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1712428471.642384, 'ieee': dc:8e:95:ff:fe:35:66:f1, 'min_update_delta': 30.0}) completed
2024-04-06 18:34:31.644 DEBUG (Thread-112) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7e77978e2110>)
2024-04-06 18:34:31.644 DEBUG (Thread-112) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7e77978e2110>) completed
2024-04-06 18:34:31.652 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'0531a1a9602a15bf0c9b7e'
2024-04-06 18:34:31.652 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2024-04-06 18:34:31.652 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received sendUnicast: [<EmberStatus.SUCCESS: 0>, 13]
2024-04-06 18:34:31.741 DEBUG (Thread-112) [aiosqlite] executing functools.partial(<function PersistingListener._set_isolation_level.<locals>.<lambda> at 0x7e779462d940>)
2024-04-06 18:34:31.741 DEBUG (Thread-112) [aiosqlite] operation functools.partial(<function PersistingListener._set_isolation_level.<locals>.<lambda> at 0x7e779462d940>) completed
2024-04-06 18:34:31.741 DEBUG (Thread-112) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7e77978e2110>, 'PRAGMA wal_checkpoint;', [])
# Suddenly, serial port closed
2024-04-06 18:34:31.742 DEBUG (bellows.thread_0) [bellows.uart] Connection lost: None
2024-04-06 18:34:31.742 DEBUG (bellows.thread_0) [bellows.uart] Closed serial connection
2024-04-06 18:34:31.745 DEBUG (Thread-112) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7e77978e2110>, 'PRAGMA wal_checkpoint;', []) completed
2024-04-06 18:34:31.745 DEBUG (Thread-112) [aiosqlite] executing functools.partial(<function PersistingListener._set_isolation_level.<locals>.<lambda> at 0x7e779652b560>)
2024-04-06 18:34:31.745 DEBUG (Thread-112) [aiosqlite] operation functools.partial(<function PersistingListener._set_isolation_level.<locals>.<lambda> at 0x7e779652b560>) completed
2024-04-06 18:34:31.745 DEBUG (Thread-112) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Connection object at 0x7e77978e2110>)
2024-04-06 18:34:31.746 DEBUG (Thread-112) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Connection object at 0x7e77978e2110>) completed
# Failed to set up
2024-04-06 18:34:31.746 DEBUG (MainThread) [homeassistant.components.zha] Failed to set up ZHA
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/components/zha/__init__.py", line 153, in async_setup_entry
zha_gateway = await ZHAGateway.async_from_config(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/components/zha/core/gateway.py", line 197, in async_from_config
await instance.async_initialize()
File "/usr/src/homeassistant/homeassistant/components/zha/core/gateway.py", line 215, in async_initialize
await app.startup(auto_form=True)
File "/usr/local/lib/python3.12/site-packages/zigpy/application.py", line 234, in startup
await self.initialize(auto_form=auto_form)
File "/usr/local/lib/python3.12/site-packages/zigpy/application.py", line 180, in initialize
await self.permit(0)
File "/usr/local/lib/python3.12/site-packages/bellows/zigbee/application.py", line 938, in permit
await super().permit(time_s, node)
File "/usr/local/lib/python3.12/site-packages/zigpy/application.py", line 1254, in permit
await zigpy.zdo.broadcast(
File "/usr/local/lib/python3.12/site-packages/zigpy/device.py", line 688, in broadcast
return await app.broadcast(
^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.12/site-packages/zigpy/application.py", line 929, in broadcast
await self.send_packet(
File "/usr/local/lib/python3.12/site-packages/bellows/zigbee/application.py", line 912, in send_packet
raise zigpy.exceptions.DeliveryError(
zigpy.exceptions.DeliveryError: Failed to enqueue message after 3 attempts: <EmberStatus.NETWORK_BUSY: 161>
# Something seems to be probing the serial ports for bootloaders??
2024-04-06 18:34:31.749 INFO (MainThread) [universal_silabs_flasher.flasher] Probing ApplicationType.GECKO_BOOTLOADER at 115200 baud
# This is the serial port of my Zigbee stick
2024-04-06 18:34:31.749 DEBUG (MainThread) [zigpy.serial] Opening a serial connection to '/dev/ttyUSB0' (115200 baudrate)
2024-04-06 18:34:31.751 DEBUG (MainThread) [universal_silabs_flasher.common] Connection made: SerialTransport(<_UnixSelectorEventLoop running=True closed=False debug=False>, <universal_silabs_flasher.gecko_bootloader.GeckoBootloaderProtocol object at 0x7e778ed3d580>, Serial<id=0x7e7791b31f90, open=True>(port='/dev/ttyUSB0', baudrate=115200, bytesize=8, parity='N', stopbits=1, timeout=0, xonxoff=False, rtscts=False, dsrdtr=False))
2024-04-06 18:34:31.752 DEBUG (MainThread) [universal_silabs_flasher.common] Sending data b'\n'
2024-04-06 18:34:31.752 DEBUG (MainThread) [universal_silabs_flasher.common] Sending data b'3'
2024-04-06 18:34:31.806 DEBUG (MainThread) [universal_silabs_flasher.common] Received data b'\x151\xb1\xa9\r*\xf2\x90\xb8\xaco\xdbU\xc0\x1c\x95\xd0\xe1\'"\xd0~'
2024-04-06 18:34:31.807 DEBUG (MainThread) [universal_silabs_flasher.gecko_bootloader] Parsing State.WAITING_FOR_MENU: bytearray(b'\x151\xb1\xa9\r*\xf2\x90\xb8\xaco\xdbU\xc0\x1c\x95\xd0\xe1\'"\xd0~')