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
72.22k stars 30.24k forks source link

[Matter] (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter: #112521

Closed jvmahon closed 5 months ago

jvmahon commented 7 months ago

The problem

I'm getting long streams of errors of the pattern shown below. Is there any way to figure out if this relates to a specific device? Any idea what is happening / how to fix?

Thanks.

2024-03-06 13:27:25 (Dummy-2) CHIP_ERROR [chip.native.DMG] Time out! failed to receive report data from Exchange: 44979i
2024-03-06 13:27:25 (MainThread) ERROR [matter_server.server.client_handler] [549276608400] SDK Error during handling message: read_attribute: Chip Stack Error 50
2024-03-06 13:29:22 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:149983651 on exchange 45092i sendCount: 4 max retries: 4
2024-03-06 13:29:22 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:149983652 on exchange 45093i sendCount: 4 max retries: 4
2024-03-06 13:29:22 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:149983649 on exchange 45090i sendCount: 4 max retries: 4
2024-03-06 13:29:22 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:149983650 on exchange 45091i sendCount: 4 max retries: 4
2024-03-06 13:29:25 (Dummy-2) CHIP_ERROR [chip.native.DMG] Time out! failed to receive report data from Exchange: 45090i
2024-03-06 13:29:25 (MainThread) ERROR [matter_server.server.client_handler] [549276608400] SDK Error during handling message: read_attribute: Chip Stack Error 50
2024-03-06 13:29:25 (Dummy-2) CHIP_ERROR [chip.native.DMG] Time out! failed to receive report data from Exchange: 45091i
2024-03-06 13:29:25 (MainThread) ERROR [matter_server.server.client_handler] [549276608400] SDK Error during handling message: read_attribute: Chip Stack Error 50
2024-03-06 13:29:25 (Dummy-2) CHIP_ERROR [chip.native.DMG] Time out! failed to receive report data from Exchange: 45092i
2024-03-06 13:29:25 (Dummy-2) CHIP_ERROR [chip.native.DMG] Time out! failed to receive report data from Exchange: 45093i
2024-03-06 13:29:25 (MainThread) ERROR [matter_server.server.client_handler] [549276608400] SDK Error during handling message: read_attribute: Chip Stack Error 50
2024-03-06 13:29:25 (MainThread) ERROR [matter_server.server.client_handler] [549276608400] SDK Error during handling message: read_attribute: Chip Stack Error 50
2024-03-06 13:30:51 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:40214833 on exchange 45180i sendCount: 4 max retries: 4
2024-03-06 13:30:52 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:40214835 on exchange 45182i sendCount: 4 max retries: 4
2024-03-06 13:30:52 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:40214834 on exchange 45181i sendCount: 4 max retries: 4
2024-03-06 13:30:55 (Dummy-2) CHIP_ERROR [chip.native.DMG] Time out! failed to receive report data from Exchange: 45180i
2024-03-06 13:30:55 (Dummy-2) CHIP_ERROR [chip.native.DMG] Time out! failed to receive report data from Exchange: 45181i
2024-03-06 13:30:55 (MainThread) ERROR [matter_server.server.client_handler] [549276608400] SDK Error during handling message: read_attribute: Chip Stack Error 50
2024-03-06 13:30:55 (Dummy-2) CHIP_ERROR [chip.native.DMG] Time out! failed to receive report data from Exchange: 45182i
2024-03-06 13:30:55 (MainThread) ERROR [matter_server.server.client_handler] [549276608400] SDK Error during handling message: read_attribute: Chip Stack Error 50
2024-03-06 13:30:55 (MainThread) ERROR [matter_server.server.client_handler] [549276608400] SDK Error during handling message: read_attribute: Chip Stack Error 50

What version of Home Assistant Core has the issue?

2024.2.5

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

Matter

Link to integration documentation on our website

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

Diagnostics information

config_entry-matter-ca32ae982ffa19f48f6b84dc1a1e89be.json

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

home-assistant[bot] commented 7 months ago

Hey there @home-assistant/matter, mind taking a look at this issue as it has been labeled with an integration (matter) you are listed as a code owner for? Thanks!

Code owner commands Code owners of `matter` 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 matter` 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)


matter documentation matter source (message by IssueLinks)

marcelveldt commented 7 months ago

Unfortunately at the moment the node id is not logged in the SDK logging. This should come in future update. These messages are indications of connectivity issues on your Thread network, its basically overloaded

marcelveldt commented 7 months ago

BTW: In the next Matter server version (just been released) we already added a bit extra logging, so you can at least track to which nodes the "read_attribute" command is failing. These are most probably Eve Energy devices.

jvmahon commented 7 months ago

These are most probably Eve Energy devices. Thank you. I do have seven Eve Energy devices, so perhaps they are the problem.

Maybe this is related to power reporting? I wonder if the subscription timing has a low minimum reporting time, are these devices reporting every tiny voltage fluctuation and continually sending wattage use reports. If that might be the case, is it possible to increase the subscription minimum reporting time for the power reporting cluster?

Otherwise, do you know if there is a Eve attribute that can be set to turn off power reporting or to change how often they report? I know you can't do that from HomeAssistant right now, but I also have them paired to Hubitat, so I could send a command to them from Hubitat to change power reporting if that is possible.

Thank you.

marcelveldt commented 7 months ago

Power attributes are custom attributes, updated every 30 seconds.

jvmahon commented 7 months ago

BTW: In the next Matter server version (just been released) we already added a bit extra logging, so you can at least track to which nodes the "read_attribute" command is failing. These are most probably Eve Energy devices.

You were correct - using the node identifier that is now in the logged messages, it was clear that the cause of this problem was my Eve Energy devices.

It seems very strange to me that a small number of devices can overwhelm the Thread network this way. Is there any kind of fix that you know of? I assume the answer is "no". My guess is that part of the problem may be that Eve Energy firmware uses old Matter/Thread SDKs (firmware 3.2.1 was certified in June 2023 so that means that they are on Matter 1.1 and older version of the thread SDK - before all the bug fixes and improvements added in Matter 1.2.1 and the October 2023 release of thread).

marcelveldt commented 5 months ago

This issue will be fixed for good once the Eve energy plugs are updated to Matter 1.3 which incorporates the Energy monitoring so the devices do not have to be polled anymore. As a temporary measure we're going to make some adjustments server-side in the next release (not this one but the next month) to let the server decide if the network is silent enough to allow a poll. Other than that its safe to ignore these logs. They dont hurt

jvmahon commented 5 months ago

I ended up removing all 15 of my Eve Home devices from my network.

Has Eve confirmed they are doing a Matter 1.3 update? That would be fantastic!

Thanks!

marcelveldt commented 1 month ago

I ended up removing all 15 of my Eve Home devices from my network.

Has Eve confirmed they are doing a Matter 1.3 update? That would be fantastic!

Thanks!

That is a bit overkill - we have optimized the polling so much that this will not cause any issues any more. And yes Eve will publish a new firmware at some point that includes the new Matter native measurements