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
71.11k stars 29.79k forks source link

Zigbee Network Huge Degradation #78163

Closed broyuken closed 1 year ago

broyuken commented 2 years ago

The problem

Zigbee network has gotten super slow since 2022.9.1. Used to be fast, now it takes upwards of 30 seconds to turn a light on or off if it works at all.

What version of Home Assistant Core has the issue?

2022.9.1

What was the last working version of Home Assistant Core?

2022.9.0

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Zha

Link to integration documentation on our website

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

Diagnostics information

No response

Example YAML snippet

N/A

Anything in the logs that might be useful for us?

Logger: homeassistant
Source: /usr/src/homeassistant/homeassistant/runner.py:96 
First occurred: 5:14:26 PM (2 occurrences) 
Last logged: 5:23:00 PM

Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/zigpy_znp/api.py", line 1025, in request_callback_rsp
    return await callback_rsp
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/zigpy_znp/api.py", line 1022, in request_callback_rsp
    async with async_timeout.timeout(timeout):
  File "/usr/local/lib/python3.10/site-packages/async_timeout/__init__.py", line 129, in __aexit__
    self._do_exit(exc_type)
  File "/usr/local/lib/python3.10/site-packages/async_timeout/__init__.py", line 212, in _do_exit
    raise asyncio.TimeoutError
asyncio.exceptions.TimeoutError

Additional information

I am using the zzh stick

probot-home-assistant[bot] commented 2 years ago

Hey there @dmulcahey, @adminiuga, @puddly, 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! (message by CodeOwnersMention)

zha documentation zha source (message by IssueLinks)

broyuken commented 2 years ago

I went back to 2022.9.0 and it’s working normally. This is only broken with .1

dmulcahey commented 2 years ago

We don't have any changes in .1

broyuken commented 2 years ago

Well it works in .0 and not in .1 so something changed.

puddly commented 2 years ago

Please include debug logs: https://www.home-assistant.io/integrations/zha/#debug-logging

Absolutely nothing changed between .0 and .1 related to ZHA or any of its indirect dependencies, you can see for yourself: https://github.com/home-assistant/core/compare/2022.9.0...2022.9.1.

If your network indeed breaks again after you upgrade to 2022.9.1 and is fixed again by you downgrading to 2022.9.0, we can check it out. Until then, the only change is you resetting your adapter by restarting HA.

Ming-A commented 2 years ago

Noticing a big delay too with my network after upgrading to 2022.9.1,

I'll place some of my logs:

Logger: homeassistant.components.zha.core.channels.base
Source: components/zha/core/channels/base.py:486
Integration: Zigbee Home Automation (documentation, issues)
First occurred: 1:10:34 AM (13 occurrences)
Last logged: 1:11:01 AM

[0xF8FE:1:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>')]
[0xF8FE:4:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>')]
[0xF8FE:2:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>')]
[0xB64D:2:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>')]
[0xB64D:1:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>')]
Logger: homeassistant.components.websocket_api.http.connection
Source: components/zha/api.py:594
Integration: Home Assistant WebSocket API (documentation, issues)
First occurred: 1:09:57 AM (1 occurrences)
Last logged: 1:09:57 AM

[140446099876896] Error handling message: Unknown error (unknown_error)
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/decorators.py", line 27, in _handle_async_response
    await func(hass, connection, msg)
  File "/usr/src/homeassistant/homeassistant/components/zha/api.py", line 594, in websocket_reconfigure_node
    assert device
AssertionError
bousch commented 2 years ago

Same issue here. Since upgrading to 2022.9.1, delay in zigbee devices is huge. I upgraded from 2022.8.7 which did not have these issues. Restarting the Home Assistant device does not help.

Logger: homeassistant.components.zha.core.channels.base
Source: components/zha/core/channels/base.py:486
Integration: Zigbee Home Automation ([documentation](https://www.home-assistant.io/integrations/zha), [issues](https://github.com/home-assistant/home-assistant/issues?q=is%3Aissue+is%3Aopen+label%3A%22integration%3A+zha%22))
First occurred: 21:56:26 (4 occurrences)
Last logged: 21:57:18

[0x7878:1:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Request failed after 5 attempts: <Status.MAC_NO_ACK: 233>'), DeliveryError('Request failed after 5 attempts: <Status.MAC_NO_ACK: 233>'), DeliveryError('Request failed after 5 attempts: <Status.MAC_NO_ACK: 233>'), DeliveryError('Request failed after 5 attempts: <Status.MAC_NO_ACK: 233>')]
[0x7878:1:0x0008]: async_initialize: all attempts have failed: [DeliveryError('Request failed after 5 attempts: <Status.MAC_NO_ACK: 233>'), DeliveryError('Request failed after 5 attempts: <Status.MAC_NO_ACK: 233>'), DeliveryError('Request failed after 5 attempts: <Status.MAC_NO_ACK: 233>'), DeliveryError('Request failed after 5 attempts: <Status.MAC_NO_ACK: 233>')]
[0x7878:1:0x0300]: async_initialize: all attempts have failed: [DeliveryError('Request failed after 5 attempts: <Status.MAC_NO_ACK: 233>'), DeliveryError('Request failed after 5 attempts: <Status.MAC_NO_ACK: 233>'), DeliveryError('Request failed after 5 attempts: <Status.MAC_NO_ACK: 233>'), DeliveryError('Request failed after 5 attempts: <Status.MAC_NO_ACK: 233>')]
[0xBCE8:1:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>')]

Many (or all) requests are delayed

2022-09-10 22:09:00.087 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 0.50 seconds
2022-09-10 22:09:00.378 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 0.79 seconds
2022-09-10 22:09:11.998 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 12.40 seconds
2022-09-10 22:09:12.617 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 13.02 seconds
2022-09-10 22:09:13.768 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 14.16 seconds
2022-09-10 22:09:16.511 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 16.90 seconds
2022-09-10 22:09:16.584 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 16.97 seconds
2022-09-10 22:09:17.285 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 17.67 seconds
2022-09-10 22:09:21.793 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 22.17 seconds
2022-09-10 22:09:21.859 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 22.23 seconds
2022-09-10 22:09:25.649 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 26.02 seconds
2022-09-10 22:09:44.917 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 45.29 seconds
2022-09-10 22:09:59.287 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 59.65 seconds
2022-09-10 22:09:59.379 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 59.74 seconds
2022-09-10 22:09:59.478 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 59.83 seconds
2022-09-10 22:09:59.887 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 60.24 seconds
2022-09-10 22:09:59.972 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 60.32 seconds
2022-09-10 22:10:00.043 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 60.39 seconds
2022-09-10 22:10:18.582 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 78.92 seconds
2022-09-10 22:10:22.530 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 82.87 seconds
2022-09-10 22:10:52.227 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 99.58 seconds
2022-09-10 22:10:52.283 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 95.67 seconds
2022-09-10 22:10:52.352 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 89.66 seconds
2022-09-10 22:10:56.189 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 93.14 seconds
2022-09-10 22:10:56.198 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 89.46 seconds
2022-09-10 22:11:00.091 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 74.38 seconds
2022-09-10 22:11:00.104 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 60.01 seconds
2022-09-10 22:11:00.192 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 60.04 seconds
2022-09-10 22:11:33.779 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 87.41 seconds
2022-09-10 22:11:33.818 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 86.48 seconds
2022-09-10 22:11:38.493 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 81.07 seconds
2022-09-10 22:11:38.612 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 78.84 seconds
2022-09-10 22:12:07.473 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 103.83 seconds
2022-09-10 22:12:12.287 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 95.15 seconds
2022-09-10 22:12:12.314 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 95.06 seconds
2022-09-10 22:12:12.339 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 78.87 seconds
2022-09-10 22:12:41.114 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 104.01 seconds
2022-09-10 22:12:45.994 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 108.59 seconds
2022-09-10 22:12:49.828 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 108.64 seconds
2022-09-10 22:12:53.677 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 112.44 seconds
2022-09-10 22:12:57.515 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 112.33 seconds
2022-09-10 22:12:57.630 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 112.44 seconds
2022-09-10 22:12:57.757 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 104.39 seconds
2022-09-10 22:13:01.559 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 106.22 seconds
2022-09-10 22:13:14.801 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 100.01 seconds
2022-09-10 22:13:35.229 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 120.22 seconds
2022-09-10 22:13:48.458 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 95.40 seconds
2022-09-10 22:14:08.896 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 86.59 seconds
2022-09-10 22:14:22.118 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 95.12 seconds
2022-09-10 22:14:42.568 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 110.15 seconds
2022-09-10 22:14:46.410 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 110.28 seconds
2022-09-10 22:14:50.262 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 112.61 seconds
2022-09-10 22:14:50.289 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 112.51 seconds
2022-09-10 22:14:50.314 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 109.56 seconds
2022-09-10 22:14:54.165 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 98.30 seconds
2022-09-10 22:14:55.790 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 63.97 seconds
2022-09-10 22:15:27.810 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 75.78 seconds
2022-09-10 22:15:29.444 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 64.83 seconds
2022-09-10 22:16:01.482 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 76.48 seconds
2022-09-10 22:16:03.080 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 64.10 seconds
2022-09-10 22:16:35.125 DEBUG (MainThread) [zigpy_znp.zigbee.application] Previously delayed request is now running, delayed by 64.57 seconds
puddly commented 2 years ago

Does downgrading to 2022.8.7 help?

bousch commented 2 years ago

I have not downgraded but I have disabled the bluetooth integration. Somehow the zigbee delays have disappeared now.

broyuken commented 2 years ago

Downgrading to 2022.9.0 helps

broyuken commented 2 years ago

There were some Bluetooth changes in .1 so maybe one of them interferes with the zigbee integration.

puddly commented 2 years ago

Can you provide complete debug logs from both versions?

broyuken commented 2 years ago

I won’t be able to for a bit, hopefully one of the others having this problem is able to sooner.

Adminiuga commented 2 years ago

Bluetooth and ZigBee are both 2.4GHz, activating Bluetooth could impact ZigBee?

broyuken commented 2 years ago

This seems to be fixed on 2022.9.2. I saw there were some zigbee fixes in that one, as well as some bluetooth changes so something unbroke itself...

I'll wait to see if other people are still having issues before I close the ticket.

Crypto90 commented 2 years ago

I can't add a zigbee gateway with the last 2? versions. Im currently on 2022.9.2. I see the incoming connection on the gateway which instantly closes and on the home assistant side, it fails to add the gateway. 2022-09-12_20-55-03

It always "failes to connect".

Gateway looks like this: 2022-09-12_20-56-18

I can't see any other error or logging for this on the home assistant side.

Any help?

broyuken commented 2 years ago

open a new issue for that, seems unrelated to this one.

broyuken commented 1 year ago

closing, as nobody has said that the issue persists after .2

Ming-A commented 1 year ago

It's really be on and off for me, it was working fine for one day, then decides to stop working another day.

Logs:

Logger: homeassistant.components.zha.core.channels.base
Source: components/zha/core/channels/base.py:486
Integration: Zigbee Home Automation (documentation, issues)
First occurred: 9:26:51 AM (2 occurrences)
Last logged: 9:26:51 AM

[0xB64D:1:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>')]
[0xB64D:2:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>')]
broyuken commented 1 year ago

Reopening as it’s off and on for me too. Upgraded to .4 and the issue seems to be back.

TheJulianJES commented 1 year ago

Can you provide some debug logs when the issue is occurring? (Also, is the Zigbee stick on an extension cord? Is the stick next to a WiFi AP? Is it next to a Bluetooth dongle? Are you using an SSD or other devices attached via USB 3.0?)

broyuken commented 1 year ago

It’s very intermittent, but I’ll try to grab logs. For the other questions, yes my zigbee stick is off an extension cable, not near any AP’s and I have a Bluetooth adapter plugged into a usb hub with a 2 ft cable off another usb port. All the ports are usb3.0 though.

HA is running on a nuc.

Ming-A commented 1 year ago

Before the update, I didn't have much problems as I have currently, where sometimes the zigbee network would have connection issues. I was on .2 and have updated to .4 with the same problem, I have to keep restarting or reloading until I'm lucky that things start to work again. Also, my coordinator is a tubeszb-cc2652-eth and there's no Bluetooth or ap nearby it.

Log from today:

Logger: homeassistant.components.zha.core.channels.base
Source: components/zha/core/channels/base.py:486
Integration: Zigbee Home Automation (documentation, issues)
First occurred: 6:27:40 PM (19 occurrences)
Last logged: 6:28:50 PM

[0x1247:2:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Request failed after 5 attempts: <Status.NWK_INVALID_REQUEST: 194>'), TimeoutError(), DeliveryError('Request failed after 5 attempts: <Status.NWK_INVALID_REQUEST: 194>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_INVALID_REQUEST: 194>')]
[0x1247:1:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Request failed after 5 attempts: <Status.NWK_INVALID_REQUEST: 194>'), TimeoutError(), DeliveryError('Request failed after 5 attempts: <Status.NWK_INVALID_REQUEST: 194>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_INVALID_REQUEST: 194>')]
[0x1247:3:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Request failed after 5 attempts: <Status.NWK_INVALID_REQUEST: 194>'), TimeoutError(), DeliveryError('Request failed after 5 attempts: <Status.NWK_INVALID_REQUEST: 194>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_INVALID_REQUEST: 194>')]
[0x1247:4:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Request failed after 5 attempts: <Status.NWK_INVALID_REQUEST: 194>'), TimeoutError(), DeliveryError('Request failed after 5 attempts: <Status.NWK_INVALID_REQUEST: 194>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_INVALID_REQUEST: 194>')]
[0xA6AA:1:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Request failed after 5 attempts: <Status.APS_NO_ACK: 183>'), TimeoutError(), DeliveryError('Request failed after 5 attempts: <Status.APS_NO_ACK: 183>'), DeliveryError('Request failed after 5 attempts: <Status.APS_NO_ACK: 183>')]
Ming-A commented 1 year ago

So far the only way to get it working again would be to restart the whole HA a few times, reloading ZHA alone doesn't seem to work.

Edit: (after updating this time to 0.4, its quite bad that after restarting a few times I still have an unstable connection to all my devices, even rebooted the coordinator and accessible routers didn't seem to work. (after an hour of restarting and reloading constantly, ZHA really is broken for me, even the closest device to the coordinator is not working

More logs:

Logger: homeassistant.components.websocket_api.http.connection
Source: components/zha/core/channels/base.py:78
Integration: Home Assistant WebSocket API (documentation, issues)
First occurred: 8:00:00 PM (3 occurrences)
Last logged: 8:01:20 PM

[140289626562976] 'NoneType' object has no attribute 'request_callback_rsp'
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 200, in handle_call_service
    await hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1738, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1775, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 204, in handle_service
    await service.entity_service_call(
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 676, in entity_service_call
    future.result()  # pop exception if have
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 931, in async_request_call
    await coro
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 713, in _handle_entity_call
    await result
  File "/usr/src/homeassistant/homeassistant/components/light/__init__.py", line 544, in async_handle_light_off_service
    await light.async_turn_off(**filter_turn_off_params(light, params))
  File "/usr/src/homeassistant/homeassistant/components/zha/light.py", line 413, in async_turn_off
    result = await self._on_off_channel.off()
  File "/usr/src/homeassistant/homeassistant/components/zha/core/channels/base.py", line 78, in wrapper
    result = await command(*args, **kwds)
  File "/usr/local/lib/python3.10/site-packages/zigpy/device.py", line 291, in request
    radio_result, msg = await self._application.request(
  File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 302, in request
    return await self._send_request(
  File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 1161, in _send_request
    response = await self._send_request_raw(
  File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 1047, in _send_request_raw
    self._znp.request_callback_rsp(
AttributeError: 'NoneType' object has no attribute 'request_callback_rsp'
Logger: homeassistant.components.zha.core.channels.base
Source: components/zha/core/channels/base.py:486
Integration: Zigbee Home Automation (documentation, issues)
First occurred: 7:57:28 PM (67 occurrences)
Last logged: 8:03:57 PM

[0xF8FE:3:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>')]
[0xF8FE:4:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>')]
[0xF8FE:1:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>')]
[0xAC22:1:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>')]
[0xAC22:2:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>'), DeliveryError('Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>')]
Ming-A commented 1 year ago

Here are the diagnostics from the coordinator. Even the coordinator itself shows as unavailable under LQI. Thinking of reverting back to 9.2.

Edit: I reverted back to 9.2, and it seems like ZHA really is not working for me, I reverted it from the backup and restore option. Going to try a fresh install and restore from there.

{
  "home_assistant": {
    "installation_type": "Home Assistant OS",
    "version": "2022.9.4",
    "dev": false,
    "hassio": true,
    "virtualenv": false,
    "python_version": "3.10.5",
    "docker": true,
    "arch": "x86_64",
    "timezone": "Asia/Kuala_Lumpur",
    "os_name": "Linux",
    "os_version": "5.15.67",
    "supervisor": "2022.08.6",
    "host_os": "Home Assistant OS 9.0",
    "docker_version": "20.10.17",
    "chassis": "vm",
    "run_as_root": true
  },
  "custom_components": {
    "sonoff": {
      "version": "3.2.0",
      "requirements": [
        "pycryptodome>=3.6.6"
      ]
    },
    "browser_mod": {
      "version": "1.3.1",
      "requirements": []
    },
    "frigate": {
      "version": "2.3",
      "requirements": []
    },
    "smartir": {
      "version": "1.17.6",
      "requirements": [
        "aiofiles==0.6.0"
      ]
    },
    "webrtc": {
      "version": "v2.3.1",
      "requirements": []
    },
    "watchman": {
      "version": "0.5.1",
      "requirements": [
        "prettytable==3.0.0"
      ]
    },
    "hacs": {
      "version": "1.27.2",
      "requirements": [
        "aiogithubapi>=22.2.4"
      ]
    },
    "xiaomi_miot": {
      "version": "0.6.11",
      "requirements": [
        "construct==2.10.56",
        "python-miio>=0.5.6",
        "micloud>=0.3"
      ]
    },
    "localtuya": {
      "version": "4.1.0",
      "requirements": []
    }
  },
  "integration_manifest": {
    "domain": "zha",
    "name": "Zigbee Home Automation",
    "config_flow": true,
    "documentation": "https://www.home-assistant.io/integrations/zha",
    "requirements": [
      "bellows==0.33.1",
      "pyserial==3.5",
      "pyserial-asyncio==0.6",
      "zha-quirks==0.0.79",
      "zigpy-deconz==0.18.1",
      "zigpy==0.50.3",
      "zigpy-xbee==0.15.0",
      "zigpy-zigate==0.9.2",
      "zigpy-znp==0.8.2"
    ],
    "usb": [
      {
        "vid": "10C4",
        "pid": "EA60",
        "description": "*2652*",
        "known_devices": [
          "slae.sh cc2652rb stick"
        ]
      },
      {
        "vid": "1A86",
        "pid": "55D4",
        "description": "*sonoff*plus*",
        "known_devices": [
          "sonoff zigbee dongle plus v2"
        ]
      },
      {
        "vid": "10C4",
        "pid": "EA60",
        "description": "*sonoff*plus*",
        "known_devices": [
          "sonoff zigbee dongle plus"
        ]
      },
      {
        "vid": "10C4",
        "pid": "EA60",
        "description": "*tubeszb*",
        "known_devices": [
          "TubesZB Coordinator"
        ]
      },
      {
        "vid": "1A86",
        "pid": "7523",
        "description": "*tubeszb*",
        "known_devices": [
          "TubesZB Coordinator"
        ]
      },
      {
        "vid": "1A86",
        "pid": "7523",
        "description": "*zigstar*",
        "known_devices": [
          "ZigStar Coordinators"
        ]
      },
      {
        "vid": "1CF1",
        "pid": "0030",
        "description": "*conbee*",
        "known_devices": [
          "Conbee II"
        ]
      },
      {
        "vid": "10C4",
        "pid": "8A2A",
        "description": "*zigbee*",
        "known_devices": [
          "Nortek HUSBZB-1"
        ]
      },
      {
        "vid": "0403",
        "pid": "6015",
        "description": "*zigate*",
        "known_devices": [
          "ZiGate+"
        ]
      },
      {
        "vid": "10C4",
        "pid": "EA60",
        "description": "*zigate*",
        "known_devices": [
          "ZiGate"
        ]
      },
      {
        "vid": "10C4",
        "pid": "8B34",
        "description": "*bv 2010/10*",
        "known_devices": [
          "Bitron Video AV2010/10"
        ]
      }
    ],
    "codeowners": [
      "@dmulcahey",
      "@adminiuga",
      "@puddly"
    ],
    "zeroconf": [
      {
        "type": "_esphomelib._tcp.local.",
        "name": "tube*"
      },
      {
        "type": "_zigate-zigbee-gateway._tcp.local.",
        "name": "*zigate*"
      }
    ],
    "dependencies": [
      "file_upload"
    ],
    "after_dependencies": [
      "onboarding",
      "usb",
      "zeroconf"
    ],
    "iot_class": "local_polling",
    "loggers": [
      "aiosqlite",
      "bellows",
      "crccheck",
      "pure_pcapy3",
      "zhaquirks",
      "zigpy",
      "zigpy_deconz",
      "zigpy_xbee",
      "zigpy_zigate",
      "zigpy_znp"
    ],
    "is_built_in": true
  },
  "data": {
    "ieee": "**REDACTED**",
    "nwk": 0,
    "manufacturer": "Texas Instruments",
    "model": "CC1352/CC2652, Z-Stack 3.30+ (build 20220219)",
    "name": "Texas Instruments CC1352/CC2652, Z-Stack 3.30+ (build 20220219)",
    "quirk_applied": false,
    "quirk_class": "zigpy_znp.zigbee.device.ZNPCoordinator",
    "manufacturer_code": 0,
    "power_source": "Mains",
    "lqi": null,
    "rssi": null,
    "last_seen": "2022-09-15T21:08:35",
    "available": true,
    "device_type": "Coordinator",
    "signature": {
      "node_descriptor": "NodeDescriptor(logical_type=<LogicalType.Coordinator: 0>, complex_descriptor_available=0, user_descriptor_available=0, reserved=0, aps_flags=0, frequency_band=<FrequencyBand.Freq2400MHz: 8>, mac_capability_flags=<MACCapabilityFlags.AllocateAddress|RxOnWhenIdle|MainsPowered|FullFunctionDevice|AlternatePanCoordinator: 143>, manufacturer_code=0, maximum_buffer_size=80, maximum_incoming_transfer_size=160, server_mask=11265, maximum_outgoing_transfer_size=160, descriptor_capability_field=<DescriptorCapability.NONE: 0>, *allocate_address=True, *is_alternate_pan_coordinator=True, *is_coordinator=True, *is_end_device=False, *is_full_function_device=True, *is_mains_powered=True, *is_receiver_on_when_idle=True, *is_router=False, *is_security_capable=False)",
      "endpoints": {
        "1": {
          "profile_id": 260,
          "device_type": "0x0400",
          "in_clusters": [
            "0x0000",
            "0x0006",
            "0x000a",
            "0x0019",
            "0x0501"
          ],
          "out_clusters": [
            "0x0001",
            "0x0020",
            "0x0500",
            "0x0502"
          ]
        },
        "2": {
          "profile_id": 49246,
          "device_type": "0x0820",
          "in_clusters": [
            "0x0000"
          ],
          "out_clusters": []
        }
      }
    },
    "active_coordinator": true,
    "entities": [],
    "neighbors": [],
    "endpoint_names": [
      {
        "name": "CONTROLLER"
      },
      {
        "name": "IAS_CONTROL"
      }
    ],
    "user_given_name": null,
    "device_reg_id": "b8604c9a385b98c478f85ddc081a1988",
    "area_id": null,
    "cluster_details": {
      "2": {
        "device_type": {
          "name": "CONTROLLER",
          "id": 2080
        },
        "profile_id": 49246,
        "in_clusters": {
          "0x0000": {
            "endpoint_attribute": "basic",
            "attributes": {},
            "unsupported_attributes": {}
          }
        },
        "out_clusters": {}
      },
      "1": {
        "device_type": {
          "name": "IAS_CONTROL",
          "id": 1024
        },
        "profile_id": 260,
        "in_clusters": {
          "0x0000": {
            "endpoint_attribute": "basic",
            "attributes": {},
            "unsupported_attributes": {}
          },
          "0x0006": {
            "endpoint_attribute": "on_off",
            "attributes": {},
            "unsupported_attributes": {}
          },
          "0x000a": {
            "endpoint_attribute": "time",
            "attributes": {},
            "unsupported_attributes": {}
          },
          "0x0019": {
            "endpoint_attribute": "ota",
            "attributes": {},
            "unsupported_attributes": {}
          },
          "0x0501": {
            "endpoint_attribute": "ias_ace",
            "attributes": {},
            "unsupported_attributes": {}
          }
        },
        "out_clusters": {
          "0x0001": {
            "endpoint_attribute": "power",
            "attributes": {},
            "unsupported_attributes": {}
          },
          "0x0020": {
            "endpoint_attribute": "poll_control",
            "attributes": {},
            "unsupported_attributes": {}
          },
          "0x0500": {
            "endpoint_attribute": "ias_zone",
            "attributes": {},
            "unsupported_attributes": {}
          },
          "0x0502": {
            "endpoint_attribute": "ias_wd",
            "attributes": {},
            "unsupported_attributes": {}
          }
        }
      }
    }
  }
}
Ming-A commented 1 year ago

So i have reverted back to 8.0 and i think its not a 9.0 issue anymore, probably a coincidence that something happened to the coordinator, been trying to google around to check on how to diagnose and see if its the coordinator that's causing errors but that's not related to this issue anymore.

Logs from 2022.8.0:

Logger: homeassistant.components.zha.core.channels.base
Source: components/zha/core/channels/base.py:486
Integration: Zigbee Home Automation (documentation, issues)
First occurred: 1:04:20 AM (22 occurrences)
Last logged: 1:05:02 AM

[0x37FC:1:0x0006]: 'async_initialize' stage failed: 'NoneType' object has no attribute 'request_callback_rsp'
[0xE42F:2:0x0006]: 'async_initialize' stage failed: 'NoneType' object has no attribute 'request_callback_rsp'
[0xE42F:1:0x0006]: 'async_initialize' stage failed: 'NoneType' object has no attribute 'request_callback_rsp'
[0xE42F:3:0x0006]: 'async_initialize' stage failed: 'NoneType' object has no attribute 'request_callback_rsp'
[0xF8FE:1:0x0006]: 'async_initialize' stage failed: 'NoneType' object has no attribute 'request_callback_rsp'
puddly commented 1 year ago

The only time the above error can occur is if the coordinator is physically disconnected. If you're seeing it happen 22 times, something is very broken. Can you post or email me your entire home-assistant.log with ZHA debug logging enabled?

Ming-A commented 1 year ago

The only time the above error can occur is if the coordinator is physically disconnected. If you're seeing it happen 22 times, something is very broken. Can you post or email me your entire home-assistant.log with ZHA debug logging enabled?

I will be emailing you my log file, its really weird since usually a reload or reboot would fix the issue but i have spent the past 6 hours trying to get this up and working with no luck... Thank you for helping out.

It started at around 4-5pm here when my zigbee devices were acting weird and losing connections, but it got worst when I restarted it and every single device has stopped working, even the devices that are nearby the coordinator, I have still yet to find out if the coordinator has decided to break on me or if its something else causing the issue

puddly commented 1 year ago

Got it. Do you happen to have a Home Assistant backup from a few weeks ago, from some 2022.8.x release? If you do, could you also email me your /config/zigbee.db file from it?

Ming-A commented 1 year ago

Got it. Do you happen to have a Home Assistant backup from a few weeks ago, from some 2022.8.x release? If you do, could you also email me your /config/zigbee.db file from it?

I have a backup of 2022.8.0 from last month but when I booted into it, ZHA was also broken with all devices not connected/unknown state. I will load back into it and grab the zigbee.db (I'll also include the one from 9.2 if it might help)

puddly commented 1 year ago

Restoring the backup and then booting into it will cause the zigbee.db file to be updated, which may pull in invalid state from your coordinator (if that is indeed the problem). If you can, extract the Tar archive and pull the file out offline.

Ming-A commented 1 year ago

Restoring the backup and then booting into it will cause the zigbee.db file to be updated, which may pull in invalid state from your coordinator (if that is indeed the problem). If you can, extract the Tar archive and pull the file out offline.

that's a problem actually... the only backup I had was a clone I made of the VM and I booted directly from it as a last resort since all backup before 9.1 is gone from my storage. But I can include the zigbee.db from the tar file from 9.1 few days ago while it was still working (with occasional disconnections)

puddly commented 1 year ago

I'm seeing nothing in the databases that would indicate any problem with the network settings, they're consistent. Have you tried physically power cycling your routing devices (i.e. turn the lights off at the switch for 5-10s)?

Ming-A commented 1 year ago

I'm seeing nothing in the databases that would indicate any problem with the network settings, they're consistent. Have you tried physically power cycling your routing devices (i.e. turn the lights off at the switch for 5-10s)?

I have not actually, most of the devices that are closest to the coordinator are all end devices while the routers are slightly further. I will try turning the lights off on the end devices along with router devices/switches then turn them on after a few seconds to see if it makes a difference.

Edit: I have turned the lights off for at least a min and have also tried to repair the motion sensor in the same room as the coordinator but it seems to not be picking up the device when i click on add devices. Besides that i have also turned off and powered a router back on

Ming-A commented 1 year ago

So I have some hope that it's not the coordinator that's down/broken, I have found one device that seems to be working, which is my office lumi.sensor_switch, which is a button and its able to detect that a button has been pressed. It has an LQI of '123' and its in the same room as the coordinator. Whats weird is that i cant re pair devices like the motion sensor or temperature sensor in the same room.

javicalle commented 1 year ago

Could be related with an OS update (not the core)? Or maybe some kind of combination core / OS?

Ming-A commented 1 year ago

After reflashing the coordinator and restarting HA twice along with reloading ZHA a few times, some end devices like temperature sensors are showing their battery, getting somewhere I guess. I'm really not sure if it's related to the OS or core, or it was just a coincidence for my own zigbee network.

Edit: I can finally go to sleep, not everything is back and working but my light switches and some end devices are working again after reflashing the coordinator.

Edit 2: My zigbee network is up again, my fix was just reflashing the coordinator

Rishi-Maze commented 1 year ago

Got the same problem with upgrading to 9.4. I went from 8.0 to 9.4 and my Zigbee-Network was broken (very long response times if at all). Downgrading to 8.0 fixed the Zigbee-Network issue.

I am running HA on a Raspberry Pi 3 B with a Raspbee II Zigbee Gateway.

I can try to provide some logs. Please let me know which ones you need.

broyuken commented 1 year ago

More logs (edited 5000 times because code blocks on mobile are a nightmare 😂)

Logger: homeassistant.util.logging
Source: util/logging.py:153 
First occurred: 9:03:46 PM (27 occurrences) 
Last logged: 9:03:46 PM

Exception in _maybe_force_refresh when dispatching 'zha_light_group_state_changed': ({'entity_ids': ['light.kitchen_ceiling_light_1', 'light.kitchen_ceiling_light_2', 'light.kitchen_ceiling_light_3', 'light.kitchen_ceiling_light_4']},) Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/zha/light.py", line 872, in _maybe_force_refresh await self.async_get_state() File "/usr/src/homeassistant/homeassistant/components/zha/light.py", line 804, in async_get_state results = await self._color_channel.get_attributes( File "/usr/src/homeassistant/homeassistant/components/zha/core/channels/base.py", line 460, in _get_attributes read, _ = await self.cluster.read_attributes( File "/usr/local/lib/python3.10/site-packages/zigpy/zcl/__init__.py", line 482, in read_attributes result = await self.read_attributes_raw(to_read, manufacturer=manufacturer) File "/usr/local/lib/python3.10/site-packages/zigpy/device.py", line 291, in request radio_result, msg = await self._application.request( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 302, in request return await self._send_request( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 1161, in _send_request response = await self._send_request_raw( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 1047, in _send_request_raw self._znp.request_callback_rsp( AttributeError: 'NoneType' object has no attribute 'request_callback_rsp'
Exception in _maybe_force_refresh when dispatching 'zha_light_group_state_changed': ({'entity_ids': ['light.living_room_bookshelf_right_2', 'light.living_room_bookshelf_right_1', 'light.living_room_bookshelf_right_3', 'light.living_room_bookshelf_left_2', 'light.living_room_bookshelf_left_1', 'light.living_room_bookshelf_left_3']},) Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/zha/light.py", line 872, in _maybe_force_refresh await self.async_get_state() File "/usr/src/homeassistant/homeassistant/components/zha/light.py", line 804, in async_get_state results = await self._color_channel.get_attributes( File "/usr/src/homeassistant/homeassistant/components/zha/core/channels/base.py", line 460, in _get_attributes read, _ = await self.cluster.read_attributes( File "/usr/local/lib/python3.10/site-packages/zigpy/zcl/__init__.py", line 482, in read_attributes result = await self.read_attributes_raw(to_read, manufacturer=manufacturer) File "/usr/local/lib/python3.10/site-packages/zigpy/device.py", line 291, in request radio_result, msg = await self._application.request( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 302, in request return await self._send_request( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 1161, in _send_request response = await self._send_request_raw( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 1047, in _send_request_raw self._znp.request_callback_rsp( AttributeError: 'NoneType' object has no attribute 'request_callback_rsp'
Exception in _maybe_force_refresh when dispatching 'zha_light_group_state_changed': ({'entity_ids': ['light.living_room_lamp_right', 'light.living_room_lamp_left']},) Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/zha/light.py", line 872, in _maybe_force_refresh await self.async_get_state() File "/usr/src/homeassistant/homeassistant/components/zha/light.py", line 804, in async_get_state results = await self._color_channel.get_attributes( File "/usr/src/homeassistant/homeassistant/components/zha/core/channels/base.py", line 460, in _get_attributes read, _ = await self.cluster.read_attributes( File "/usr/local/lib/python3.10/site-packages/zigpy/zcl/__init__.py", line 482, in read_attributes result = await self.read_attributes_raw(to_read, manufacturer=manufacturer) File "/usr/local/lib/python3.10/site-packages/zigpy/device.py", line 291, in request radio_result, msg = await self._application.request( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 302, in request return await self._send_request( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 1161, in _send_request response = await self._send_request_raw( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 1047, in _send_request_raw self._znp.request_callback_rsp( AttributeError: 'NoneType' object has no attribute 'request_callback_rsp'
Exception in _maybe_force_refresh when dispatching 'zha_light_group_state_changed': ({'entity_ids': ['light.entryway_ceiling_light_1', 'light.entryway_ceiling_light_3', 'light.entryway_ceiling_light_2']},) Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/zha/light.py", line 872, in _maybe_force_refresh await self.async_get_state() File "/usr/src/homeassistant/homeassistant/components/zha/light.py", line 804, in async_get_state results = await self._color_channel.get_attributes( File "/usr/src/homeassistant/homeassistant/components/zha/core/channels/base.py", line 460, in _get_attributes read, _ = await self.cluster.read_attributes( File "/usr/local/lib/python3.10/site-packages/zigpy/zcl/__init__.py", line 482, in read_attributes result = await self.read_attributes_raw(to_read, manufacturer=manufacturer) File "/usr/local/lib/python3.10/site-packages/zigpy/device.py", line 291, in request radio_result, msg = await self._application.request( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 302, in request return await self._send_request( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 1161, in _send_request response = await self._send_request_raw( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 1047, in _send_request_raw self._znp.request_callback_rsp( AttributeError: 'NoneType' object has no attribute 'request_callback_rsp'
Logger: zigpy.zcl
Source: runner.py:119 
First occurred: 9:03:46 PM (55 occurrences) 
Last logged: 9:03:46 PM

[0x3345:1:0x0300] Traceback (most recent call last): File "/usr/local/lib/python3.10/site-packages/zigpy/device.py", line 291, in request radio_result, msg = await self._application.request( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 302, in request return await self._send_request( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 1161, in _send_request response = await self._send_request_raw( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 1047, in _send_request_raw self._znp.request_callback_rsp( AttributeError: 'NoneType' object has no attribute 'request_callback_rsp'
[0x1DB8:1:0x0006] Traceback (most recent call last): File "/usr/local/lib/python3.10/site-packages/zigpy/device.py", line 291, in request radio_result, msg = await self._application.request( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 302, in request return await self._send_request( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 1161, in _send_request response = await self._send_request_raw( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 1047, in _send_request_raw self._znp.request_callback_rsp( AttributeError: 'NoneType' object has no attribute 'request_callback_rsp'
[0x6D37:1:0x0006] Traceback (most recent call last): File "/usr/local/lib/python3.10/site-packages/zigpy/device.py", line 291, in request radio_result, msg = await self._application.request( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 302, in request return await self._send_request( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 1161, in _send_request response = await self._send_request_raw( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 1047, in _send_request_raw self._znp.request_callback_rsp( AttributeError: 'NoneType' object has no attribute 'request_callback_rsp'
[0x2C37:11:0x0300] Traceback (most recent call last): File "/usr/local/lib/python3.10/site-packages/zigpy/device.py", line 291, in request radio_result, msg = await self._application.request( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 302, in request return await self._send_request( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 1161, in _send_request response = await self._send_request_raw( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 1047, in _send_request_raw self._znp.request_callback_rsp( AttributeError: 'NoneType' object has no attribute 'request_callback_rsp'
[0x3345:1:0x0008] Traceback (most recent call last): File "/usr/local/lib/python3.10/site-packages/zigpy/device.py", line 291, in request radio_result, msg = await self._application.request( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 302, in request return await self._send_request( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 1161, in _send_request response = await self._send_request_raw( File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 1047, in _send_request_raw self._znp.request_callback_rsp( AttributeError: 'NoneType' object has no attribute 'request_callback_rsp'
Logger: homeassistant
Source: /usr/src/homeassistant/homeassistant/runner.py:96 
First occurred: 9:03:46 PM (1 occurrences) 
Last logged: 9:03:46 PM

Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/zigpy/topology.py", line 63, in scan
    await self._scan_task
  File "/usr/local/lib/python3.10/site-packages/zigpy/topology.py", line 86, in _scan
    await device.neighbors.scan()
  File "/usr/local/lib/python3.10/site-packages/zigpy/neighbor.py", line 96, in scan
    return await self._scan()
  File "/usr/local/lib/python3.10/site-packages/zigpy/neighbor.py", line 107, in _scan
    status, rsp = await self._device.zdo.Mgmt_Lqi_req(idx, tries=3, delay=1)
  File "/usr/local/lib/python3.10/site-packages/zigpy/util.py", line 130, in retry
    r = await func()
  File "/usr/local/lib/python3.10/site-packages/zigpy/device.py", line 291, in request
    radio_result, msg = await self._application.request(
  File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 302, in request
    return await self._send_request(
  File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 1161, in _send_request
    response = await self._send_request_raw(
  File "/usr/local/lib/python3.10/site-packages/zigpy_znp/zigbee/application.py", line 1039, in _send_request_raw
    response = await self._znp.request(
AttributeError: 'NoneType' object has no attribute 'request'
puddly commented 1 year ago

These errors are logged only if the the connection between ZHA and the stick is broken. What kind of coordinator are you using and how is it connected to your server? Can you post or e-mail me the entire /config/home-assistant.log after this problem happens again, with ZHA debug logging enabled?

broyuken commented 1 year ago

I’m using the zzh stick directly plugged into my nuc via a 2ft usb extension cable. And what’s your email?

broyuken commented 1 year ago

Another odd thing to note is that this only seems to affect my lights. My motion and door sensors seem to be fine and update instantly.

All different types of lights too. Sengled and sylvania bulbs, gledopto light strips, ewelight candelabras, I don’t have any lights not affected, but non lights are fine.

puddly commented 1 year ago

And what’s your email?

It's in my GitHub profile (puddly3@gmail.com).

Another odd thing to note is that this only seems to affect my lights.

The error you posted above is a complete breakdown of serial communication. Nothing would be working until zigpy-znp reconnects to your radio. If this happens constantly (55 occurrences), I'd expect most lights to be unresponsive during those reconnect periods, since the serial port is disconnected.

broyuken commented 1 year ago

I can walk into a room with a zigbee motion sensor and see it trigger in HA, but the light that is supposed to turn on does not come on, it’s completely unresponsive. Best case it comes on a minute later.

broyuken commented 1 year ago

I know you’re saying these logs only happen if the serial connection isn’t working but that can’t be the case here. Zigbee lights are the only thing broken here, everything else seems to be working fine with 0 delay even at the same time that lights are not responding to commends

broyuken commented 1 year ago

Could in be that there’s a back log of commands that need to be sent to the lights? I can issue a command and the light sometimes responds after a couple of minutes, sometimes upwards of 5 mins later.

primalmotion commented 1 year ago

I have to say that I just updated to latest everything (having HaOS on rpi 4 with a raspbee 2 shield) and I'm having the exact same symptoms as @broyuken

broyuken commented 1 year ago

I have to say that I just updated to latest everything (having HaOS on rpi 4 with a raspbee 2 shield) and I'm having the exact same symptoms as @broyuken

Are you by any chance using the adaptive lighting or circadian lighting custom integrations?

Rishi-Maze commented 1 year ago

I have to say that I just updated to latest everything (having HaOS on rpi 4 with a raspbee 2 shield) and I'm having the exact same symptoms as @broyuken

Are you by any chance using the adaptive lighting or circadian lighting custom integrations?

I'm not using any of those custom integrations. Got the same issue with network lags and interruptions.

primalmotion commented 1 year ago

I have to say that I just updated to latest everything (having HaOS on rpi 4 with a raspbee 2 shield) and I'm having the exact same symptoms as @broyuken

Are you by any chance using the adaptive lighting or circadian lighting custom integrations?

Nope