Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ZHA started throwing a lot of errors #98735

Closed
rasmusbe opened this issue Aug 21, 2023 · 15 comments
Closed

ZHA started throwing a lot of errors #98735

rasmusbe opened this issue Aug 21, 2023 · 15 comments

Comments

@rasmusbe
Copy link
Contributor

The problem

ZHA is filling the log with the following error.

What version of Home Assistant Core has the issue?

core-2023.8.3

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_zha_2023-08-21T06-00-46.578Z.log.zip

Example YAML snippet

No response

Anything in the logs that might be useful for us?

Logger: zigpy.zcl
Source: runner.py:179
First occurred: 19 August 2023 at 04:49:57 (153241 occurrences)
Last logged: 07:55:00

[0x439F:1:0x0020] Traceback (most recent call last): File "/usr/local/lib/python3.11/site-packages/zigpy/device.py", line 310, in request return await req.result ^^^^^^^^^^^^^^^^ asyncio.exceptions.CancelledError The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/usr/local/lib/python3.11/site-packages/zigpy/device.py", line 309, in request async with asyncio_timeout(timeout): File "/usr/local/lib/python3.11/asyncio/timeouts.py", line 111, in __aexit__ raise TimeoutError from exc_val TimeoutError The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/general.py", line 538, in check_in_response await self.checkin_response(True, self.CHECKIN_FAST_POLL_TIMEOUT, tsn=tsn) File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 66, in wrapper raise HomeAssistantError( homeassistant.exceptions.HomeAssistantError: Failed to send request: device did not respond
[0x439F:1:0x0020] AssertionError The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/usr/local/lib/python3.11/site-packages/zigpy/device.py", line 292, in request with self._pending.new(sequence) as req: ^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/zigpy/util.py", line 291, in new raise ControllerException(f"duplicate {sequence} TSN") from AssertionError zigpy.exceptions.ControllerException: duplicate 28 TSN The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/general.py", line 538, in check_in_response await self.checkin_response(True, self.CHECKIN_FAST_POLL_TIMEOUT, tsn=tsn) File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 75, in wrapper raise HomeAssistantError(message) from exc homeassistant.exceptions.HomeAssistantError: Failed to send request: duplicate 28 TSN
[0x439F:1:0x0020] AssertionError The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/usr/local/lib/python3.11/site-packages/zigpy/device.py", line 292, in request with self._pending.new(sequence) as req: ^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/zigpy/util.py", line 291, in new raise ControllerException(f"duplicate {sequence} TSN") from AssertionError zigpy.exceptions.ControllerException: duplicate 21 TSN The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/general.py", line 541, in check_in_response await self.fast_poll_stop() File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 75, in wrapper raise HomeAssistantError(message) from exc homeassistant.exceptions.HomeAssistantError: Failed to send request: duplicate 21 TSN
[0x439F:1:0x0020] AssertionError The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/usr/local/lib/python3.11/site-packages/zigpy/device.py", line 292, in request with self._pending.new(sequence) as req: ^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/zigpy/util.py", line 291, in new raise ControllerException(f"duplicate {sequence} TSN") from AssertionError zigpy.exceptions.ControllerException: duplicate 37 TSN The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/general.py", line 538, in check_in_response await self.checkin_response(True, self.CHECKIN_FAST_POLL_TIMEOUT, tsn=tsn) File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 75, in wrapper raise HomeAssistantError(message) from exc homeassistant.exceptions.HomeAssistantError: Failed to send request: duplicate 37 TSN
[0x439F:1:0x0020] AssertionError The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/usr/local/lib/python3.11/site-packages/zigpy/device.py", line 292, in request with self._pending.new(sequence) as req: ^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/zigpy/util.py", line 291, in new raise ControllerException(f"duplicate {sequence} TSN") from AssertionError zigpy.exceptions.ControllerException: duplicate 36 TSN The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/general.py", line 538, in check_in_response await self.checkin_response(True, self.CHECKIN_FAST_POLL_TIMEOUT, tsn=tsn) File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 75, in wrapper raise HomeAssistantError(message) from exc homeassistant.exceptions.HomeAssistantError: Failed to send request: duplicate 36 TSN


### Additional information

_No response_
@home-assistant
Copy link

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!

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.

(message by CodeOwnersMention)


zha documentation
zha source
(message by IssueLinks)

@rasmusbe
Copy link
Contributor Author

rasmusbe commented Aug 21, 2023

After some debugging, it might have something to do with the open/close remote to my IKEA blinds
image

This is my most recent device in the network, and when I removed it the error-bombing stopped. When I added it again it returned.

UPDATE
I removed the remote again and it still throws the error. Must have been a fluke before

@puddly
Copy link
Contributor

puddly commented Aug 21, 2023

Could you enable ZHA debug logging (https://www.home-assistant.io/integrations/zha/#debug-logging) and post a debug log? This definitely shouldn't be happening.

@rasmusbe
Copy link
Contributor Author

rasmusbe commented Aug 21, 2023

I attached a zip file with the debug log in my initial report. But only with debug activated in the GUI. I had to turn it off after a while due to the disk becoming full due to gigantic log files 😔

I can try to enable it via yaml with all the sub-packages as well later today or tomorrow.

@puddly
Copy link
Contributor

puddly commented Aug 21, 2023

It looks like your IKEA remote is seemingly stuck in a loop: it keeps rapidly checking in with ZHA, ZHA asks it to stop, the remote doesn't stop and keeps checking in. The error is because 255 pending requests to this specific device have been created and no more will be accepted. Not really a failure case I expected.

What happens if you remove the remote's battery to fully reset it? This seems like a glitch with the remote. Also, is your coordinator on a USB extension cable and away from interference sources (2.4GHz WiFi, USB 3.0 devices, SSDs, etc.)? Is the device as well? That might explain why the response isn't being seen.

@rasmusbe
Copy link
Contributor Author

I activated debug logging for a while and thanks to your input I found what devices that made multiple checkins.
It wasn't the remote, it was both my Ikea Tredansen Blinds at the same time. Just removing the battery and put it in again did not help, but after I did a factory reset both and re-add them to HA it seems to have stopped.

Here's the debug log, the devices are:
IEEE: cc:86:ec:ff:fe:f9:f6:d2
Nwk: 0x439f
and
IEEE: b4:e3:f9:ff:fe:c9:87:df
Nwk: 0xda69

home-assistant_2023-08-21T16-50-39.203Z.log

@Anto79-ops
Copy link

don't want to hijack this thread...(I guess I just did) but I get the same logs with my Heiman Smoke detector, although less than a few dozen when it does have a temper tantrum.

Is this a device error or ZHA (multi-pan) issue?

@orbelico
Copy link

Can add one more occurence here: I have an automation which updates the light level every minute, in order to implement a circadian ligh cycle. For that, it calls the light.turn_on service.

One of the lights is sometimes switched of via wall switch, so it looses Zigbee connection. The automation only calls light.turn_on if the light is available, however, whenver it goes offline it will take a couple of minutes for ZHA to detect that. In that meantime, I get the same error, but only since a recent update of HA, the automation worked without errors in the past. It would be nice to get rid of it, since it really spams the log.

2023-08-28 23:21:15.315 ERROR (MainThread) [homeassistant.core] Error executing service: <ServiceCall light.turn_on (c:01H8Z0AXK2CZR08N4P2G77R6ZG): entity_id=['light.bathroom_lamp'], params=transition=2.0, brightness=105>
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/zigpy/device.py", line 310, in request
    return await req.result
           ^^^^^^^^^^^^^^^^
asyncio.exceptions.CancelledError
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 64, in wrapper
    return await RETRYABLE_REQUEST_DECORATOR(func)(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/zigpy/util.py", line 132, in retry
    return await func()
           ^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/zigpy/zcl/__init__.py", line 375, in request
    return await self._endpoint.request(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/zigpy/endpoint.py", line 253, in request
    return await self.device.request(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/zigpy/device.py", line 309, in request
    async with asyncio_timeout(timeout):
  File "/usr/local/lib/python3.11/asyncio/timeouts.py", line 111, in __aexit__
    raise TimeoutError from exc_val
TimeoutError
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/core.py", line 1990, in _run_service_call_catch_exceptions
    await coro_or_task
  File "/usr/src/homeassistant/homeassistant/core.py", line 2011, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 235, in handle_service
    return await service.entity_service_call(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 870, in entity_service_call
    response_data = await _handle_entity_call(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 942, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/light/__init__.py", line 580, in async_handle_light_on_service
    await light.async_turn_on(**filter_turn_on_params(light, params))
  File "/usr/src/homeassistant/homeassistant/components/zha/light.py", line 336, in async_turn_on
    result = await self._level_cluster_handler.move_to_level_with_on_off(
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 66, in wrapper
    raise HomeAssistantError(
homeassistant.exceptions.HomeAssistantError: Failed to send request: device did not respond

@rwarner
Copy link

rwarner commented Sep 4, 2023

I'm also getting these errors randomly starting with 2023.8

[0x0B5D:1:0x0020] AssertionError The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/srv/homeassistant/homeassistant_venv_3.11.4/lib/python3.11/site-packages/zigpy/device.py", line 292, in request with self._pending.new(sequence) as req: ^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/srv/homeassistant/homeassistant_venv_3.11.4/lib/python3.11/site-packages/zigpy/util.py", line 291, in new raise ControllerException(f"duplicate {sequence} TSN") from AssertionError zigpy.exceptions.ControllerException: duplicate 111 TSN The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/srv/homeassistant/homeassistant_venv_3.11.4/lib/python3.11/site-packages/homeassistant/components/zha/core/cluster_handlers/general.py", line 538, in check_in_response await self.checkin_response(True, self.CHECKIN_FAST_POLL_TIMEOUT, tsn=tsn) File "/srv/homeassistant/homeassistant_venv_3.11.4/lib/python3.11/site-packages/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 75, in wrapper raise HomeAssistantError(message) from exc homeassistant.exceptions.HomeAssistantError: Failed to send request: duplicate 111 TSN
[0x7DE5:1:0x0020] AssertionError The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/srv/homeassistant/homeassistant_venv_3.11.4/lib/python3.11/site-packages/zigpy/device.py", line 292, in request with self._pending.new(sequence) as req: ^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/srv/homeassistant/homeassistant_venv_3.11.4/lib/python3.11/site-packages/zigpy/util.py", line 291, in new raise ControllerException(f"duplicate {sequence} TSN") from AssertionError zigpy.exceptions.ControllerException: duplicate 22 TSN The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/srv/homeassistant/homeassistant_venv_3.11.4/lib/python3.11/site-packages/homeassistant/components/zha/core/cluster_handlers/general.py", line 538, in check_in_response await self.checkin_response(True, self.CHECKIN_FAST_POLL_TIMEOUT, tsn=tsn) File "/srv/homeassistant/homeassistant_venv_3.11.4/lib/python3.11/site-packages/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 75, in wrapper raise HomeAssistantError(message) from exc homeassistant.exceptions.HomeAssistantError: Failed to send request: duplicate 22 TSN
[0xA886:1:0x0020] AssertionError The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/srv/homeassistant/homeassistant_venv_3.11.4/lib/python3.11/site-packages/zigpy/device.py", line 292, in request with self._pending.new(sequence) as req: ^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/srv/homeassistant/homeassistant_venv_3.11.4/lib/python3.11/site-packages/zigpy/util.py", line 291, in new raise ControllerException(f"duplicate {sequence} TSN") from AssertionError zigpy.exceptions.ControllerException: duplicate 94 TSN The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/srv/homeassistant/homeassistant_venv_3.11.4/lib/python3.11/site-packages/homeassistant/components/zha/core/cluster_handlers/general.py", line 538, in check_in_response await self.checkin_response(True, self.CHECKIN_FAST_POLL_TIMEOUT, tsn=tsn) File "/srv/homeassistant/homeassistant_venv_3.11.4/lib/python3.11/site-packages/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 75, in wrapper raise HomeAssistantError(message) from exc homeassistant.exceptions.HomeAssistantError: Failed to send request: duplicate 94 TSN

@issue-triage-workflows
Copy link

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates.
Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍
This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

@perjury
Copy link

perjury commented Dec 3, 2023

Still an issue for me on latest release

@github-actions github-actions bot removed the stale label Dec 3, 2023
@rwarner
Copy link

rwarner commented Dec 6, 2023

I haven't been getting the original errors I posted in this thread, but I am still getting:

Failed to send request: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>

On 2023.11.3

@issue-triage-workflows
Copy link

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates.
Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍
This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

@rwarner
Copy link

rwarner commented Mar 5, 2024

I am still getting these ember status issues, but can understand closing this and keeping: #97662

Open if that is preferred

@issue-triage-workflows
Copy link

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates.
Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍
This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

@issue-triage-workflows issue-triage-workflows bot closed this as not planned Won't fix, can't repro, duplicate, stale Jun 10, 2024
@github-actions github-actions bot locked and limited conversation to collaborators Jul 10, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

8 participants