ZHA stops working when adding devices, then fails to load. universal_silabs_flasher probes for bootloaders. #115141

stiansoevik · 2024-04-07T18:39:01Z

The problem

I am in the process of setting up my Zigbee network. I recently set up Home Assistant and bought a new Zigbee stick (SMLIGHT SLZB-07). After adding some devices, the next ones did not show up, so I reloaded the integration. It cycled between "Initializing" and "Failed setup, will retry".

Multiple restarts, plugging out and in stick etc did not help, until it suddenly started working again. After adding three new devices, nothing appeared for the fourth one, and I reloaded the integration again. Then the same cycle happened.

The times it does not work, I get log entries from universal_silabs_flasher probing for bootloaders right after Failed to set up ZHA. I suspect this is interfering with the ZHA communication, but it might as well be a regular part of the ZHA integration trying to understand which stick it is communicating with?

Attached are logs from one initialization cycle, except some lines with MAC addresses removed.

What version of Home Assistant Core has the issue?

core-2024.4.1

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant Container

Integration causing the issue

Zigbee Home Automation

Link to integration documentation on our website

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

Diagnostics information

home-assistant_2024-04-07T18-06-04.492Z.log (MAC addresses masked)

Summary:
First, a lot of log entries during initialization. There are a few error messages during initialization, not sure how concerning they are:

2024-04-07 20:05:34.181 DEBUG (MainThread) [bellows.zigbee.application] Processing route error: status=EmberStatus.SOURCE_ROUTE_FAILURE, nwk=0xdc06
...
2024-04-07 20:05:34.243 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingNetworkStatusHandler: [<EmberStackError.undefined_0xa80c: 43020>, 0x00bc]
2024-04-07 20:05:34.243 DEBUG (MainThread) [bellows.zigbee.application] Received incomingNetworkStatusHandler frame with [<EmberStackError.undefined_0xa80c: 43020>, 0x00bc]
2024-04-07 20:05:34.243 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingRouteErrorHandler: [<EmberStatus.MANY_TO_ONE_ROUTE_FAILURE: 170>, 0xbca8]
2024-04-07 20:05:34.243 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteErrorHandler frame with [<EmberStatus.MANY_TO_ONE_ROUTE_FAILURE: 170>, 0xbca8]
2024-04-07 20:05:34.243 DEBUG (MainThread) [bellows.zigbee.application] Processing route error: status=EmberStatus.MANY_TO_ONE_ROUTE_FAILURE, nwk=0xbca8

Then, ZHA seems to either give up, or be interrupted, before universal_silabs_flasher does its thing:

2024-04-07 20:05:35.122 DEBUG (bellows.thread_0) [bellows.uart] Connection lost: None
2024-04-07 20:05:35.122 DEBUG (bellows.thread_0) [bellows.uart] Closed serial connection
...
2024-04-07 20:05:35.126 DEBUG (MainThread) [homeassistant.components.zha] Failed to set up ZHA
...
zigpy.exceptions.DeliveryError: Failed to enqueue message after 3 attempts: <EmberStatus.NETWORK_BUSY: 161>
2024-04-07 20:05:35.127 INFO (MainThread) [universal_silabs_flasher.flasher] Probing ApplicationType.GECKO_BOOTLOADER at 115200 baud

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

Home Assistant is running as a container in an Ubuntu VM in a Proxmox hypervisor on an Intel NUC.

The text was updated successfully, but these errors were encountered:

home-assistant · 2024-04-07T18:39:06Z

Hey there @dmulcahey, @Adminiuga, @puddly, @TheJulianJES, mind taking a look at this issue as it has been labeled with an integration (zha) you are listed as a code owner for? Thanks!

Code owner commands

Code owners of zha 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 zha Removes the current integration label and assignees on the issue, add the integration domain after the command.
@home-assistant add-label needs-more-information Add a label (needs-more-information, problem in dependency, problem in custom component) to the issue.
@home-assistant remove-label needs-more-information Remove a label (needs-more-information, problem in dependency, problem in custom component) on the issue.

_{^{(message by CodeOwnersMention)}}

zha documentation
zha source
_{^{(message by IssueLinks)}}

HarryMcGill2022 · 2024-04-07T22:23:34Z

Im getting the same problem I have purchased a new CC2531 as I thought that was the problem and now about 5 minutes ago it’s all stoped working

please help as all my house is on zigbee and some devices don’t work without it.

puddly · 2024-04-08T00:37:28Z

ZHA expects that the stick can send a startup broadcast to disable joins. This should always work. For your stick, however, it does not:

2024-04-07 20:05:33.613 DEBUG (MainThread) [bellows.zigbee.application] Request (<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>, 12) failed to enqueue, retrying in 1.5s: EmberStatus.NETWORK_BUSY

Is your stick on a USB extension cable and away from interference sources such as USB 3.0 ports, SSDs, 2.4GHz WiFi, and so on?

stiansoevik · 2024-04-08T07:43:05Z

Is your stick on a USB extension cable and away from interference sources such as USB 3.0 ports, SSDs, 2.4GHz WiFi, and so on?

Yes.

What about the universal_silabs_flasher, is it expected to query the serial device?

puddly · 2024-04-08T11:34:04Z

Yes.

Double check and make sure your antenna is screwed on. I don't think I've ever seen this error before.

is it expected to query the serial device?

In this case, yes and no.

Yes because the radio did not start up (as the flasher checks to see if you have the wrong firmware installed).

No because the radio did start and communication with the firmware did happen but it failed due to other communication reasons before ZHA was able to talk to it.

stiansoevik · 2024-04-08T17:49:40Z

To me, it seems like the Zigbee system (Home Assistant's ZHA integration + the stick) can be in two states, "working" and "not working". In the working state, everything seems normal and stable. In the not working state, it is as described above with cycling between Initializing and Failed to set up.

It also seems that I trigger the not working state when adding new devices, as this has happened three or four times. After adding a few, it won't add anymore, and if I then restart Home Assistant, I end up with the Initializing/Failed cycle. Restarting Home Assistant again does not help. Restarting the entire computer might help, I will try now.

stiansoevik · 2024-04-08T19:13:35Z

Is there a possibility that when for instance startup takes longer time than expected, the flasher starts up and interrupts ZHA initialization? Can I disable the flasher somehow?

stiansoevik · 2024-04-09T06:59:24Z

I did not find a way to get ZHA up and running by unplugging/plugging, turning off/on, restarting etc, so I let it stay in the initialization cycle over night. Now, it's up and running as normal again. Is there anything I should test in this state?

puddly · 2024-04-09T13:08:14Z

Not really, startup fails due to the broadcast error. The flasher doesn't interfere because ZHA spawns it after failure.

The startup broadcast failure is the main problem. Reposition your coordinator to see if it helps.

stiansoevik · 2024-04-09T16:33:24Z

So do you interpret that this is due to some critical commands that fail on air (due to no ACK or similar)?
Or is it the stick that does not accept/fulfill the command (due to problems with the stick/cable etc)?

In any case, I will experiment with the position, and can also try another stick if I can take a backup and restore to that one.

What should I look for in the logs to judge whether there are still critical issues? Some examples from logs:

2024-04-08 22:34:31.780 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingNetworkStatusHandler: [<EmberStackError.undefined_0x620c: 25100>, 0x0058]
2024-04-08 22:34:31.780 DEBUG (MainThread) [bellows.zigbee.application] Received incomingNetworkStatusHandler frame with [<EmberStackError.undefined_0x620c: 25100>, 0x0058]
2024-04-08 22:34:31.793 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'3024b1a9d42abfd0014d637e'
2024-04-08 22:34:31.793 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2024-04-08 22:34:31.793 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingRouteErrorHandler: [<EmberStatus.MANY_TO_ONE_ROUTE_FAILURE: 170>, 0x5862]
2024-04-08 22:34:31.793 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteErrorHandler frame with [<EmberStatus.MANY_TO_ONE_ROUTE_FAILURE: 170>, 0x5862]
2024-04-08 22:34:31.793 DEBUG (MainThread) [bellows.zigbee.application] Processing route error: status=EmberStatus.MANY_TO_ONE_ROUTE_FAILURE, nwk=0x5862
2024-04-08 22:34:31.806 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'4024b5a96b2a134fa6944a36aa559249984e272a12ce673fd47e'
2024-04-08 22:34:31.806 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2024-04-08 22:34:31.806 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received messageSentHandler: [<EmberOutgoingMessageType.OUTGOING_BROADCAST: 6>, 65533, EmberApsFrame(profileId=0, clusterId=19, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=129), 255, <EmberStatus.SUCCESS: 0>, b'']
2024-04-08 22:34:31.806 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_BROADCAST: 6>, 65533, EmberApsFrame(profileId=0, clusterId=19, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=129), 255, <EmberStatus.SUCCESS: 0>, b'']
2024-04-08 22:34:31.806 DEBUG (MainThread) [bellows.zigbee.application] Unexpected message send notification tag: (65533, 255)

2024-04-08 22:34:32.365 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'362eb5a9902a196242d0cb7e'
2024-04-08 22:34:32.365 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2024-04-08 22:34:32.365 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'462eb1a9d42abf62422d847e'
2024-04-08 22:34:32.365 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2024-04-08 22:34:32.365 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingNetworkStatusHandler: [<EmberStackError.undefined_0xd00c: 53260>, 0x001b]
2024-04-08 22:34:32.365 DEBUG (MainThread) [bellows.zigbee.application] Received incomingNetworkStatusHandler frame with [<EmberStackError.undefined_0xd00c: 53260>, 0x001b]
2024-04-08 22:34:32.366 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingRouteErrorHandler: [<EmberStatus.MANY_TO_ONE_ROUTE_FAILURE: 170>, 0x1bd0]
2024-04-08 22:34:32.366 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteErrorHandler frame with [<EmberStatus.MANY_TO_ONE_ROUTE_FAILURE: 170>, 0x1bd0]
2024-04-08 22:34:32.366 DEBUG (MainThread) [bellows.zigbee.application] Processing route error: status=EmberStatus.MANY_TO_ONE_ROUTE_FAILURE, nwk=0x1bd0

2024-04-08 22:34:34.285 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>

puddly · 2024-04-09T16:46:49Z

There are no communication issues with the stick itself, as the wire protocol has checkums and ACKs. The startup permit(0) broadcast is just failing due to "network busy". This isn't something I've seen before and usually only happens if there are a lot of broadcasts happening, but this shouldn't be the case on startup. This is why I think it's an interference issue.

Failed to set up ZHA is the only issue to worry about. This means that the stick could not complete basic initialization and ZHA cannot control it.

stiansoevik · 2024-04-09T17:29:06Z

Strange. I switched stick and restored backup (nice process!), and see the same issues - trying again and again to initialize. So at least it is not a problem with the specific stick.

I also moved it further away from other stuff (with 1 m Deltaco USB cable). Zigbee channel 25, and although I have a WiFi access point in the same room, it is on channel 1.

In general it seems to work well when it is first up and running, and struggle during startup and when adding new devices. Maybe this leads to a larger amount of messages, which triggers an issue?

Do you have a recommendation for the next steps? I have an older Deconz stick I could try (but probably have to re-add all devices), or I could try Zigbee2MQTT to see if it can be a software issue.

puddly · 2024-04-09T18:06:10Z

What stick did you switch to?

There aren't any known stability issues with the EZSP library that would cause this to happen, it's in my opinion environmental.

Maybe this leads to a larger amount of messages, which triggers an issue?

People run 300+ devices without issues, there's no real limit that would cause this problem.

I have an older Deconz stick I could try (but probably have to re-add all devices)

You can try it as long as you flash more recent firmware to it, the migration flow works with it as well.

stiansoevik · 2024-04-09T18:12:10Z

I ordered two of the SLZB-07, so I switched to the second one.

I also just moved the NUC to a different room, let's see if it changes anything.

Even though the network could initialize and I can control devices, there are occasional errors in the log, example below. Is there anything I should try in this state to narrow down the problem?

homeassistant  | 2024-04-09 20:08:19.232 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received sendUnicast: [<EmberStatus.SUCCESS: 0>, 150]
homeassistant  | 2024-04-09 20:08:19.728 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'26a6b1a96b2a134fa6944a25aa559249984e27ad12ce6768bf7e'
homeassistant  | 2024-04-09 20:08:19.729 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
homeassistant  | 2024-04-09 20:08:19.729 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received messageSentHandler: [<EmberOutgoingMessageType.OUTGOING_BROADCAST: 6>, 65533, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=6), 255, <EmberStatus.SUCCESS: 0>, b'']
homeassistant  | 2024-04-09 20:08:19.729 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_BROADCAST: 6>, 65533, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=6), 255, <EmberStatus.SUCCESS: 0>, b'']
homeassistant  | 2024-04-09 20:08:19.729 DEBUG (MainThread) [bellows.zigbee.application] Unexpected message send notification tag: (65533, 255)
homeassistant  | 2024-04-09 20:08:20.386 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'36a6b1a96b2a1572dc904b3caa5493099c4e27389ca8672ad57e'
homeassistant  | 2024-04-09 20:08:20.386 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
homeassistant  | 2024-04-09 20:08:20.386 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received messageSentHandler: [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 34240, EmberApsFrame(profileId=260, clusterId=25, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY: 64>, groupId=0, sequence=147), 113, <EmberStatus.DELIVERY_FAILED: 102>, b'']
homeassistant  | 2024-04-09 20:08:20.387 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 34240, EmberApsFrame(profileId=260, clusterId=25, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY: 64>, groupId=0, sequence=147), 113, <EmberStatus.DELIVERY_FAILED: 102>, b'']
homeassistant  | 2024-04-09 20:08:20.387 DEBUG (MainThread) [homeassistant.components.zha.core.cluster_handlers] [0x85C0:1:0x0019]: failed to get attributes '['current_file_version']' on 'ota' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
homeassistant  | 2024-04-09 20:08:20.387 DEBUG (MainThread) [homeassistant.components.zha.core.cluster_handlers] [0x85C0:1:0x0006]: 'async_initialize' stage failed: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
homeassistant  | Traceback (most recent call last):
homeassistant  |   File "/usr/src/homeassistant/homeassistant/util/async_.py", line 205, in sem_task
homeassistant  |     return await task
homeassistant  |            ^^^^^^^^^^
homeassistant  |   File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 404, in async_initialize
homeassistant  |     await self._get_attributes(
homeassistant  |   File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 514, in _get_attributes
homeassistant  |     read, _ = await self.cluster.read_attributes(
homeassistant  |               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/zcl/__init__.py", line 528, in read_attributes
homeassistant  |     result = await self.read_attributes_raw(to_read, manufacturer=manufacturer)
homeassistant  |              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/zcl/__init__.py", line 377, in request
homeassistant  |     return await self._endpoint.request(
homeassistant  |            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/endpoint.py", line 253, in request
homeassistant  |     return await self.device.request(
homeassistant  |            ^^^^^^^^^^^^^^^^^^^^^^^^^^
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/device.py", line 339, in request
homeassistant  |     await send_request()
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/application.py", line 841, in request
homeassistant  |     await self.send_packet(
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/bellows/zigbee/application.py", line 931, in send_packet
homeassistant  |     raise zigpy.exceptions.DeliveryError(
homeassistant  | zigpy.exceptions.DeliveryError: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
homeassistant  | 2024-04-09 20:08:20.388 DEBUG (MainThread) [homeassistant.components.zha.core.cluster_handlers] [0x85C0:1:0x0300]: 'async_initialize' stage failed: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
homeassistant  | Traceback (most recent call last):
homeassistant  |   File "/usr/src/homeassistant/homeassistant/util/async_.py", line 205, in sem_task
homeassistant  |     return await task
homeassistant  |            ^^^^^^^^^^
homeassistant  |   File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 404, in async_initialize
homeassistant  |     await self._get_attributes(
homeassistant  |   File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 514, in _get_attributes
homeassistant  |     read, _ = await self.cluster.read_attributes(
homeassistant  |               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/zcl/__init__.py", line 528, in read_attributes
homeassistant  |     result = await self.read_attributes_raw(to_read, manufacturer=manufacturer)
homeassistant  |              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/zcl/__init__.py", line 377, in request
homeassistant  |     return await self._endpoint.request(
homeassistant  |            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/endpoint.py", line 253, in request
homeassistant  |     return await self.device.request(
homeassistant  |            ^^^^^^^^^^^^^^^^^^^^^^^^^^
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/device.py", line 339, in request
homeassistant  |     await send_request()
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/application.py", line 841, in request
homeassistant  |     await self.send_packet(
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/bellows/zigbee/application.py", line 931, in send_packet
homeassistant  |     raise zigpy.exceptions.DeliveryError(
homeassistant  | zigpy.exceptions.DeliveryError: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
homeassistant  | 2024-04-09 20:08:20.389 DEBUG (MainThread) [homeassistant.components.zha.core.cluster_handlers] [0x85C0:1:0x0008]: 'async_initialize' stage failed: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
homeassistant  | Traceback (most recent call last):
homeassistant  |   File "/usr/src/homeassistant/homeassistant/util/async_.py", line 205, in sem_task
homeassistant  |     return await task
homeassistant  |            ^^^^^^^^^^
homeassistant  |   File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 404, in async_initialize
homeassistant  |     await self._get_attributes(
homeassistant  |   File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 514, in _get_attributes
homeassistant  |     read, _ = await self.cluster.read_attributes(
homeassistant  |               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/zcl/__init__.py", line 528, in read_attributes
homeassistant  |     result = await self.read_attributes_raw(to_read, manufacturer=manufacturer)
homeassistant  |              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/zcl/__init__.py", line 377, in request
homeassistant  |     return await self._endpoint.request(
homeassistant  |            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/endpoint.py", line 253, in request
homeassistant  |     return await self.device.request(
homeassistant  |            ^^^^^^^^^^^^^^^^^^^^^^^^^^
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/device.py", line 339, in request
homeassistant  |     await send_request()
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/application.py", line 841, in request
homeassistant  |     await self.send_packet(
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/bellows/zigbee/application.py", line 931, in send_packet
homeassistant  |     raise zigpy.exceptions.DeliveryError(
homeassistant  | zigpy.exceptions.DeliveryError: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
homeassistant  | 2024-04-09 20:08:20.391 DEBUG (MainThread) [homeassistant.components.zha.core.cluster_handlers] [0x85C0:1:0x0000]: 'async_initialize' stage succeeded
homeassistant  | 2024-04-09 20:08:20.391 DEBUG (MainThread) [homeassistant.components.zha.core.cluster_handlers] [0x85C0:1:0x0003]: 'async_initialize' stage succeeded
homeassistant  | 2024-04-09 20:08:20.391 DEBUG (MainThread) [homeassistant.components.zha.core.cluster_handlers] [0x85C0:1:0x1000]: 'async_initialize' stage succeeded
homeassistant  | 2024-04-09 20:08:20.391 DEBUG (MainThread) [homeassistant.components.zha.core.cluster_handlers] [0x85C0:1:0x0019]: 'async_initialize' stage failed: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
homeassistant  | Traceback (most recent call last):
homeassistant  |   File "/usr/src/homeassistant/homeassistant/util/async_.py", line 205, in sem_task
homeassistant  |     return await task
homeassistant  |            ^^^^^^^^^^
homeassistant  |   File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 395, in async_initialize
homeassistant  |     await self._get_attributes(
homeassistant  |   File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 514, in _get_attributes
homeassistant  |     read, _ = await self.cluster.read_attributes(
homeassistant  |               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/zcl/__init__.py", line 528, in read_attributes
homeassistant  |     result = await self.read_attributes_raw(to_read, manufacturer=manufacturer)
homeassistant  |              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/zcl/__init__.py", line 377, in request
homeassistant  |     return await self._endpoint.request(
homeassistant  |            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/endpoint.py", line 253, in request
homeassistant  |     return await self.device.request(
homeassistant  |            ^^^^^^^^^^^^^^^^^^^^^^^^^^
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/device.py", line 339, in request
homeassistant  |     await send_request()
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/application.py", line 841, in request
homeassistant  |     await self.send_packet(
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/bellows/zigbee/application.py", line 931, in send_packet
homeassistant  |     raise zigpy.exceptions.DeliveryError(
homeassistant  | zigpy.exceptions.DeliveryError: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
homeassistant  | 2024-04-09 20:08:20.392 DEBUG (MainThread) [homeassistant.components.zha.core.cluster_handlers] [0x85C0:1:0x0019]: 'async_initialize' stage failed: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
homeassistant  | Traceback (most recent call last):
homeassistant  |   File "/usr/src/homeassistant/homeassistant/util/async_.py", line 205, in sem_task
homeassistant  |     return await task
homeassistant  |            ^^^^^^^^^^
homeassistant  |   File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 395, in async_initialize
homeassistant  |     await self._get_attributes(
homeassistant  |   File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 514, in _get_attributes
homeassistant  |     read, _ = await self.cluster.read_attributes(
homeassistant  |               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/zcl/__init__.py", line 528, in read_attributes
homeassistant  |     result = await self.read_attributes_raw(to_read, manufacturer=manufacturer)
homeassistant  |              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/zcl/__init__.py", line 377, in request
homeassistant  |     return await self._endpoint.request(
homeassistant  |            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/endpoint.py", line 253, in request
homeassistant  |     return await self.device.request(
homeassistant  |            ^^^^^^^^^^^^^^^^^^^^^^^^^^
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/device.py", line 339, in request
homeassistant  |     await send_request()
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/zigpy/application.py", line 841, in request
homeassistant  |     await self.send_packet(
homeassistant  |   File "/usr/local/lib/python3.12/site-packages/bellows/zigbee/application.py", line 931, in send_packet
homeassistant  |     raise zigpy.exceptions.DeliveryError(
homeassistant  | zigpy.exceptions.DeliveryError: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
homeassistant  | 2024-04-09 20:08:20.393 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x85C0](TRADFRIbulbE27WSglobeopal1055lm): power source: Mains
homeassistant  | 2024-04-09 20:08:20.393 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x85C0](TRADFRIbulbE27WSglobeopal1055lm): completed initialization
homeassistant  | 2024-04-09 20:08:20.503 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'46a6b1a96b2a15fc01904b23aa5e99099c4e273f9fa86717d57e'
homeassistant  | 2024-04-09 20:08:20.503 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
homeassistant  | 2024-04-09 20:08:20.505 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received messageSentHandler: [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 22606, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=11, destinationEndpoint=11, options=<EmberApsOption.APS_OPTION_RETRY: 64>, groupId=0, sequence=148), 114, <EmberStatus.DELIVERY_FAILED: 102>, b'']
homeassistant  | 2024-04-09 20:08:20.505 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 22606, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=11, destinationEndpoint=11, options=<EmberApsOption.APS_OPTION_RETRY: 64>, groupId=0, sequence=148), 114, <EmberStatus.DELIVERY_FAILED: 102>, b'']
homeassistant  | 2024-04-09 20:08:20.505 DEBUG (MainThread) [homeassistant.components.zha.core.cluster_handlers] [0x584E:11:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
homeassistant  | 2024-04-09 20:08:20.505 DEBUG (MainThread) [homeassistant.components.zha.core.cluster_handlers] [0x584E:11:0x0300]: initializing cluster handler: from_cache: False
homeassistant  | 2024-04-09 20:08:20.505 DEBUG (MainThread) [homeassistant.components.zha.core.cluster_handlers] [0x584E:11:0x0300]: initializing cached cluster handler attributes: ['color_temp_physical_min', 'color_temp_physical_max', 'color_capabilities', 'start_up_color_temperature', 'options']
homeassistant  | 2024-04-09 20:08:20.505 DEBUG (MainThread) [homeassistant.components.zha.core.cluster_handlers] [0x584E:11:0x0300]: Reading attributes in chunks: ['color_temp_physical_min', 'color_temp_physical_max', 'color_capabilities', 'start_up_color_temperature', 'options']
homeassistant  | 2024-04-09 20:08:20.505 DEBUG (MainThread) [homeassistant.components.zha.core.cluster_handlers] [0x584E:11:0x0300]: initializing uncached cluster handler attributes: ['color_mode', 'color_loop_active', 'enhanced_current_hue', 'current_x', 'current_y', 'current_hue', 'current_saturation', 'color_temperature'] - from cache[False]
homeassistant  | 2024-04-09 20:08:20.505 DEBUG (MainThread) [homeassistant.components.zha.core.cluster_handlers] [0x584E:11:0x0300]: Reading attributes in chunks: ['color_mode', 'color_loop_active', 'enhanced_current_hue', 'current_x', 'current_y']
homeassistant  | 2024-04-09 20:08:20.506 DEBUG (MainThread) [zigpy.zcl] [0x584E:11:0x0300] Sending request header: ZCLHeader(frame_control=FrameControl<0x00>(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Client_to_Server: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=2, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Client_to_Server: 0>)
homeassistant  | 2024-04-09 20:08:20.506 DEBUG (MainThread) [zigpy.zcl] [0x584E:11:0x0300] Sending request: Read_Attributes(attribute_ids=[8, 16386, 16384, 3, 4])
homeassistant  | 2024-04-09 20:08:20.506 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(timestamp=datetime.datetime(2024, 4, 9, 18, 8, 20, 506668, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=11, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x584E), dst_ep=11, source_route=None, extended_timeout=False, tsn=2, profile_id=260, cluster_id=768, data=Serialized[b'\x00\x02\x00\x08\x00\x02@\x00@\x03\x00\x04\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
homeassistant  | 2024-04-09 20:08:20.506 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x584e, EmberApsFrame(profileId=260, clusterId=768, sourceEndpoint=11, destinationEndpoint=11, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=2), 117, b'\x00\x02\x00\x08\x00\x02@\x00@\x03\x00\x04\x00')
homeassistant  | 2024-04-09 20:08:20.507 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'65a721a9602a15fc01904b25a95e99099d4e27a998c36789fdce638bbc7d5e7fa4ebc9de848c7e'
homeassistant  | 2024-04-09 20:08:20.518 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'57a7a1a9602a1525570d7e'
homeassistant  | 2024-04-09 20:08:20.518 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
homeassistant  | 2024-04-09 20:08:20.519 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received sendUnicast: [<EmberStatus.SUCCESS: 0>, 151]

stiansoevik · 2024-04-09T20:37:41Z

I upgraded to the latest firmware of the ConBee, but I was not able to restore settings from backup. So, either I need to set up the entire network on that one to see if it can be a problem with the stick firmware/driver etc, or set up the network in Zigbee2MQTT to see if that can give any more information.

Or do you have other suggestions to narrow down the cause?

puddly · 2024-04-09T21:14:21Z

Can you upload a full debug log of ZHA starting up and not failing with your original coordinator? It'll include more info.

stiansoevik · 2024-04-10T11:56:21Z

I think you are on to something, even when it initializes successfully there are some errors.

The full log is over hundred MB, so I'll first try with an excerpt if that is OK. I'll start from the two last cycles of trying to initialize, and then some minutes from "regular operation".

home-assistant_2024-04-09T06-20-51.826Z-2-excerpt.log

home-assistant bot added the integration: zha label Apr 7, 2024

home-assistant bot assigned dmulcahey, Adminiuga, puddly and TheJulianJES Apr 7, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

ZHA stops working when adding devices, then fails to load. universal_silabs_flasher probes for bootloaders. #115141

ZHA stops working when adding devices, then fails to load. universal_silabs_flasher probes for bootloaders. #115141

stiansoevik commented Apr 7, 2024

home-assistant bot commented Apr 7, 2024

HarryMcGill2022 commented Apr 7, 2024 •

edited

puddly commented Apr 8, 2024

stiansoevik commented Apr 8, 2024 •

edited

puddly commented Apr 8, 2024

stiansoevik commented Apr 8, 2024

stiansoevik commented Apr 8, 2024

stiansoevik commented Apr 9, 2024

puddly commented Apr 9, 2024

stiansoevik commented Apr 9, 2024

puddly commented Apr 9, 2024

stiansoevik commented Apr 9, 2024

puddly commented Apr 9, 2024

stiansoevik commented Apr 9, 2024

stiansoevik commented Apr 9, 2024

puddly commented Apr 9, 2024

stiansoevik commented Apr 10, 2024

ZHA stops working when adding devices, then fails to load. universal_silabs_flasher probes for bootloaders. #115141

ZHA stops working when adding devices, then fails to load. universal_silabs_flasher probes for bootloaders. #115141

Comments

stiansoevik commented Apr 7, 2024

The problem

What version of Home Assistant Core has the issue?

What was the last working version of Home Assistant Core?

What type of installation are you running?

Integration causing the issue

Link to integration documentation on our website

Diagnostics information

Example YAML snippet

Anything in the logs that might be useful for us?

Additional information

home-assistant bot commented Apr 7, 2024

HarryMcGill2022 commented Apr 7, 2024 • edited

puddly commented Apr 8, 2024

stiansoevik commented Apr 8, 2024 • edited

puddly commented Apr 8, 2024

stiansoevik commented Apr 8, 2024

stiansoevik commented Apr 8, 2024

stiansoevik commented Apr 9, 2024

puddly commented Apr 9, 2024

stiansoevik commented Apr 9, 2024

puddly commented Apr 9, 2024

stiansoevik commented Apr 9, 2024

puddly commented Apr 9, 2024

stiansoevik commented Apr 9, 2024

stiansoevik commented Apr 9, 2024

puddly commented Apr 9, 2024

stiansoevik commented Apr 10, 2024

HarryMcGill2022 commented Apr 7, 2024 •

edited

stiansoevik commented Apr 8, 2024 •

edited