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.13k stars 29.81k forks source link

Log book is filling up with "Attribute Updated event was fired" messages #113567

Closed TrackGeeks closed 5 months ago

TrackGeeks commented 6 months ago

The problem

I have 3 separate systems and all 3 are having the same issue. One system is a HA Yellow and the other two are RPi4 setups. This started after upgrading to 2024.03.0. This wasn't happening with 2024.02.xx versions.

Core 2024.3.1 Supervisor 2024.03.0 Operating System 12.1 Frontend 20240307.0

image

What version of Home Assistant Core has the issue?

2024.3.1

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Zigbee

Link to integration documentation on our website

No response

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

Home Assistant Core
2024-03-14 14:54:47.357 WARNING (SyncWorker_1) [homeassistant.loader] We found a custom integration nodered which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2024-03-14 14:54:47.360 WARNING (SyncWorker_1) [homeassistant.loader] We found a custom integration hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2024-03-14 14:54:57.513 ERROR (MainThread) [homeassistant.components.automation] Automation with alias 'Away, Turn on lights at dusk' failed to setup actions and has been disabled: Unknown entity '1c008d74b34ca8d1c20c5032c45dffd3'
2024-03-14 14:54:57.518 ERROR (MainThread) [homeassistant.components.automation] Automation with alias 'Away, Turn off light' failed to setup actions and has been disabled: Unknown entity '1c008d74b34ca8d1c20c5032c45dffd3'
2024-03-14 14:55:01.888 WARNING (MainThread) [homeassistant.helpers.frame] Detected that custom integration 'hacs' accesses hass.components.frontend. This is deprecated and will stop working in Home Assistant 2024.9, it should be updated to import functions used from frontend directly at custom_components/hacs/frontend.py, line 68: hass.components.frontend.async_register_built_in_panel(, please create a bug report at https://github.com/hacs/integration/issues
2024-03-14 14:55:11.130 WARNING (MainThread) [zigpy.application] Zigbee channel 25 utilization is 80.38%!
2024-03-14 14:55:11.130 WARNING (MainThread) [zigpy.application] If you are having problems joining new devices, are missing sensor updates, or have issues keeping devices joined, ensure your coordinator is away from interference sources such as USB 3.0 devices, SSDs, WiFi routers, etc.
2024-03-14 14:55:17.591 WARNING (MainThread) [homeassistant.components.media_player] Updating dlna_dmr media_player took longer than the scheduled update interval 0:00:10
2024-03-14 14:55:17.591 WARNING (MainThread) [homeassistant.helpers.entity] Update of media_player.samsung_qn85cd_85_2 is taking over 10 seconds
2024-03-14 15:06:11.138 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xBD6C)
2024-03-14 15:06:11.177 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xBD6C)
2024-03-14 15:06:12.131 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xBD6C)
2024-03-14 15:06:12.169 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xBD6C)
2024-03-14 15:06:12.203 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xBD6C)
2024-03-14 15:13:30.570 ERROR (MainThread) [frontend.js.latest.202403070] Uncaught error from Safari 16.6 on Mac OS 10.15.7
Script error.
null
@:0:0
2024-03-14 15:32:57.285 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xBD6C)
2024-03-14 15:32:57.341 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xBD6C)
2024-03-14 15:32:57.372 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xBD6C)
2024-03-14 15:36:11.306 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xBD6C)
2024-03-14 15:36:12.314 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xBD6C)
2024-03-14 15:36:24.306 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xBD6C)
2024-03-14 15:36:24.341 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xBD6C)
2024-03-14 15:36:24.383 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xBD6C)
2024-03-14 16:06:11.554 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xBD6C)
2024-03-14 16:06:11.586 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xBD6C)
2024-03-14 16:06:11.624 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xBD6C)
2024-03-14 16:06:12.372 WARNING (MainThread) [bellows.zigbee.application] NWK conflict is reported for 0xbd6c
2024-03-14 16:06:12.542 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x85E0)
2024-03-14 16:06:12.581 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x85E0)
2024-03-14 16:06:12.626 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x85E0)
2024-03-14 16:06:31.911 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x85F9)
2024-03-14 16:06:31.960 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x85F9)
2024-03-14 16:06:32.032 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x85F9)
2024-03-14 16:06:51.946 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x85F9)
2024-03-14 16:06:52.010 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x85F9)
2024-03-14 16:06:52.041 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x85F9)
2024-03-14 16:06:53.395 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
File "/usr/local/lib/python3.12/site-packages/zigpy/device.py", line 342, 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 63, in wrap_zigpy_exceptions
yield
File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 83, in wrapper
return await RETRYABLE_REQUEST_DECORATOR(func)(*args, **kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

Additional information

No response

home-assistant[bot] commented 6 months ago

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)

TrackGeeks commented 6 months ago

Quick update, I was able to stop the behavior on one of the systems by deleting the smart switches and adding them back to the network. That does still leave me wondering why this happened.

I'll see if this works on the other systems.

TrackGeeks commented 6 months ago

Deleting and adding back the devices worked for about an hour then the messages started again.

SteadEXE commented 5 months ago

Same issue here, mostly Philipps Hue devices spamming log with update events

Jeapsey commented 5 months ago

Same issue with my zigbee blind motors. I've rolled back to the previous HA core version now and it's cured it. So it's deffo something to do with the latest release.

TheJulianJES commented 5 months ago

Yes, this is a known issue. Zigpy/ZHA now occasionally query the devices for their currently installed firmware version. As the current_file_version attribute is updated in zigpy attribute cache, this message is also shown in the logbook.

I think we either want to remove that message entirely for attribute updates, just hide it for the firmware version, or only show that message if the attribute actually differs.

loeffen commented 5 months ago

same issue in log with "Attribute Updated event" messages every few minutes. home assistant 2024.3.2

ptrtech1 commented 5 months ago

Samjin (SmartThings) multi-purpose sensors send many of these events with no details. I originally installed Zigbee2MQTT to get rid of these messages, but I have since reverted to ZHA for the preferred experience. I did this via a second dongle (to also validate it wasn't the dongle), and migrated, but when I tried to re-add the multi-purpose sensor to validate it was still a ZHA issue, these were the logs (thus the deleted device is now unknown). I am now running all of my devices on ZHA and only the Multipurpose sensors on Z2M. This is not optimal. zha-update-event

jhstatewide commented 5 months ago

Same issue with 3RSP02028BZ Smart Plugs by Third Reality, Inc. I have a variety of other smart plugs and these alone are spamming the logbook. I have a 2 count of them and they give this message every few seconds.

jhstatewide commented 5 months ago

Yes, this is a known issue. Zigpy/ZHA now occasionally query the devices for their currently installed firmware version. As the current_file_version attribute is updated in zigpy attribute cache, this message is also shown in the logbook.

I think we either want to remove that message entirely for attribute updates, just hide it for the firmware version, or only show that message if the attribute actually differs.

Are you aware of any workarounds to suppress this behavior while it is patched out?

Jeapsey commented 5 months ago

I resolved it for now by dropping core version back to 2024.2.3

Sent from Outlook for Androidhttps://aka.ms/AAb9ysg


From: Joshua Harding @.> Sent: Tuesday, March 26, 2024 9:06:29 PM To: home-assistant/core @.> Cc: Jeapsey @.>; Comment @.> Subject: Re: [home-assistant/core] Log book is filling up with "Attribute Updated event was fired" messages (Issue #113567)

Yes, this is a known issue. Zigpy/ZHA now occasionally query the devices for their currently installed firmware version. As the current_file_version attribute is updated in zigpy attribute cache, this message is also shown in the logbook.

I think we either want to remove that message entirely for attribute updates, just hide it for the firmware version, or only show that message if the attribute actually differs.

Are you aware of any workarounds to suppress this behavior while it is patched out?

— Reply to this email directly, view it on GitHubhttps://github.com/home-assistant/core/issues/113567#issuecomment-2021474686, or unsubscribehttps://github.com/notifications/unsubscribe-auth/BGAWCCNVLBWJ7CKPDLM7XB3Y2HPNLAVCNFSM6AAAAABEY2BBFOVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDAMRRGQ3TINRYGY. You are receiving this because you commented.Message ID: @.***>

ptrtech1 commented 5 months ago

The only workaround for me was migrating to a second dongle on Z2M, which does not report these errors.

TheJulianJES commented 5 months ago

Are you aware of any workarounds to suppress this behavior while it is patched out?

No. We'll improve which events are shown in the logbook in a future version.

which does not report these errors.

They are not errors at all. It's expected behavior at the moment, but subject to change.

TheJulianJES commented 5 months ago

As a workaround, you should be able to change the broadcast_interval (in seconds) in your configuration.yaml OR completely disable the OTA image notify broadcast commands by setting broadcast_enabled to false (under zha, zigpy_config, ota keys). Only do this if you know what you're doing though. If you have it, it'll cause a negative impact on OTA functionality until removed.

ikruglov commented 5 months ago

As a workaround, you should be able to change the broadcast_interval (in seconds) in your configuration.yaml OR completely disable the OTA image notify broadcast commands by setting broadcast_enabled to false (under zha, zigpy_config, ota keys). Only do this if you know what you're doing though. If you have it, it'll cause a negative impact on OTA functionality until removed.

This didn't work for me (see below). I keep seeing flooded logbook with "Attribute Updated event was fired"

zha:
  zigpy_config:
    ota:
      # workaround https://github.com/home-assistant/core/issues/113567
      broadcast_enabled: false

I also rolled back from 2024.3.3 to 2024.2.5.

ptrtech1 commented 5 months ago

This attribute update event appears to persist.
Core: 2024.4.1 Supervisor: 2024.03.1 Operating System: 12.1 Frontend: 20240404.1 image

puddly commented 5 months ago

@ptrtech1 please open a separate issue, fill out the issue template, and attach a debug log containing about 5 minutes of these events.