Frequent & long disconnection of matter Aqara Door and Window Sensor P2

[jkporter]

The problem

I've had the Aqara Door and Window Sensor P2 working with home assistant for months. From what I recall I would get frequent unavailable statuses; however, they would last less than a minute or two. In the last month or month and a half the unavailable statuses last started to get much longer like 20, 30 minutes or longer. Despite this only Home Assistant shows the sensor as unavailable while Google Home & Aqara report otherwise. The device can be successfully pinged even when it's unavailable in Home Assistant and restarting the Matter server seems to always restore connectivity on initial boot until reverting to consistently going to unavailable again.

What version of Home Assistant Core has the issue?

core-2024.5.3

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

matter-cdc87af14e809e74d2e330e34a854dbc-Aqara Door and Window Sensor P2-8fccfa3cf1b73654331f629839403cdb.json

Example YAML snippet

No response

Anything in the logs that might be useful for us?

2024-05-13 14:52:12.867 (MainThread) INFO [matter_server.server.device_controller.node_6] Previous subscription failed with Error: 50, re-subscribing in 0 ms...
2024-05-13 14:53:18.114 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:264333345 on exchange 56740i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-13 14:53:29.797 (Dummy-2) CHIP_ERROR [chip.native.SC] CASESession timed out while waiting for a response from the peer. Current state was 4
2024-05-13 14:54:37.959 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:264333346 on exchange 56741i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-13 14:54:43.330 (MainThread) DEBUG [matter_server.server.device_controller] Attempting to resolve node 6... (attempt 1 of 2)
2024-05-13 14:54:43.334 (MainThread) DEBUG [matter_server.server.device_controller] Attempting to resolve node 6... (attempt 1 of 2)
2024-05-13 14:54:46.529 (Dummy-2) CHIP_ERROR [chip.native.SC] CASESession timed out while waiting for a response from the peer. Current state was 4
2024-05-13 14:54:46.530 (Dummy-2) CHIP_ERROR [chip.native.DMG] Failed to establish CASE for re-subscription with error 'src/protocols/secure_channel/CASESession.cpp:560: CHIP Error 0x00000032: Timeout'
2024-05-13 14:54:46.532 (MainThread) INFO [matter_server.server.device_controller.node_6] Previous subscription failed with Error: 50, re-subscribing in 7019 ms...
2024-05-13 14:54:49.535 (MainThread) INFO [matter_server.server.device_controller] Attempting to resolve node 6... (attempt 2 of 2)
2024-05-13 14:55:00.877 (MainThread) DEBUG [matter_server.server.device_controller] Attempting to resolve node 5... (attempt 1 of 2)
2024-05-13 14:55:00.879 (MainThread) DEBUG [matter_server.server.device_controller] Resolving node 5 took 0 seconds
2024-05-13 14:55:00.907 (MainThread) DEBUG [matter_server.server.device_controller] Attempting to resolve node 5... (attempt 1 of 2)
2024-05-13 14:55:00.909 (MainThread) DEBUG [matter_server.server.device_controller] Resolving node 5 took 0 seconds
2024-05-13 14:55:23.467 (MainThread) DEBUG [matter_server.server.device_controller] Attempting to resolve node 5... (attempt 1 of 2)
2024-05-13 14:55:23.470 (MainThread) DEBUG [matter_server.server.device_controller] Resolving node 5 took 0 seconds
2024-05-13 14:55:23.481 (MainThread) DEBUG [matter_server.server.device_controller] Attempting to resolve node 5... (attempt 1 of 2)
2024-05-13 14:55:23.483 (MainThread) DEBUG [matter_server.server.device_controller] Resolving node 5 took 0 seconds
2024-05-13 14:55:39.433 (MainThread) DEBUG [matter_server.server.device_controller] Attempting to resolve node 5... (attempt 1 of 2)
2024-05-13 14:55:39.435 (MainThread) DEBUG [matter_server.server.device_controller] Resolving node 5 took 0 seconds
2024-05-13 14:55:52.676 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:264333347 on exchange 56742i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-13 14:55:58.795 (MainThread) DEBUG [matter_server.server.device_controller] Attempting to resolve node 6... (attempt 1 of 2)
2024-05-13 14:55:58.797 (MainThread) DEBUG [matter_server.server.device_controller] Attempting to resolve node 6... (attempt 1 of 2)
2024-05-13 14:56:03.467 (Dummy-2) CHIP_ERROR [chip.native.SC] CASESession timed out while waiting for a response from the peer. Current state was 4
2024-05-13 14:56:04.116 (MainThread) DEBUG [matter_server.server.device_controller] Attempting to resolve node 6... (attempt 1 of 2)
2024-05-13 14:56:04.118 (MainThread) DEBUG [matter_server.server.device_controller] Attempting to resolve node 6... (attempt 1 of 2)
2024-05-13 14:57:00.896 (ThreadPoolExecutor-0_0) DEBUG [matter_server.server.storage] Saved data to persistent storage
2024-05-13 14:57:02.343 (MainThread) DEBUG [matter_server.server.device_controller] Attempting to resolve node 5... (attempt 1 of 2)
2024-05-13 14:57:02.346 (MainThread) DEBUG [matter_server.server.device_controller] Resolving node 5 took 0 seconds
2024-05-13 14:57:02.357 (MainThread) DEBUG [matter_server.server.device_controller] Attempting to resolve node 5... (attempt 1 of 2)
2024-05-13 14:57:02.361 (MainThread) DEBUG [matter_server.server.device_controller] Resolving node 5 took 0 seconds
2024-05-13 14:57:10.921 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:264333348 on exchange 56748i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-13 14:57:13.457 (MainThread) DEBUG [matter_server.server.device_controller] Attempting to resolve node 3... (attempt 1 of 2)
2024-05-13 14:57:13.459 (MainThread) DEBUG [matter_server.server.device_controller] Resolving node 3 took 0 seconds
2024-05-13 14:57:13.463 (MainThread) DEBUG [matter_server.server.device_controller] Attempting to resolve node 3... (attempt 1 of 2)
2024-05-13 14:57:13.476 (MainThread) DEBUG [matter_server.server.device_controller] Resolving node 3 took 0 seconds
2024-05-13 14:57:20.193 (Dummy-2) CHIP_ERROR [chip.native.SC] CASESession timed out while waiting for a response from the peer. Current state was 4
2024-05-13 14:57:20.194 (Dummy-2) CHIP_ERROR [chip.native.DMG] Failed to establish CASE for re-subscription with error 'src/protocols/secure_channel/CASESession.cpp:560: CHIP Error 0x00000032: Timeout'
2024-05-13 14:57:20.196 (MainThread) INFO [matter_server.server.device_controller.node_6] Previous subscription failed with Error: 50, re-subscribing in 3567 ms...
2024-05-13 14:57:20.197 (MainThread) INFO [matter_server.server.device_controller] Marked node 6 as unavailable
2024-05-13 14:57:23.199 (MainThread) INFO [matter_server.server.device_controller] Attempting to resolve node 6... (attempt 2 of 2)
2024-05-13 14:58:16.974 (MainThread) DEBUG [matter_server.server.device_controller.node_6] Pinging address fd24:c82a:f591:1:aab8:bb94:4ac8:8816
[Detaching after vfork from child process 253]
[New Thread 0x7fea0fc1e0 (LWP 255)]
[Thread 0x7fea0fc1e0 (LWP 255) exited]
2024-05-13 14:58:26.119 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:264333349 on exchange 56753i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-13 14:58:37.126 (Dummy-2) CHIP_ERROR [chip.native.SC] CASESession timed out while waiting for a response from the peer. Current state was 4
2024-05-13 14:59:13.481 (ThreadPoolExecutor-0_0) DEBUG [matter_server.server.storage] Saved data to persistent storage
2024-05-13 14:59:41.355 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:264333350 on exchange 56754i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-13 14:59:53.858 (Dummy-2) CHIP_ERROR [chip.native.SC] CASESession timed out while waiting for a response from the peer. Current state was 4
2024-05-13 14:59:53.859 (Dummy-2) CHIP_ERROR [chip.native.DMG] Failed to establish CASE for re-subscription with error 'src/protocols/secure_channel/CASESession.cpp:560: CHIP Error 0x00000032: Timeout'
2024-05-13 14:59:53.862 (MainThread) INFO [matter_server.server.device_controller.node_6] Previous subscription failed with Error: 50, re-subscribing in 15050 ms...
2024-05-13 14:59:53.862 (MainThread) DEBUG [matter_server.server.device_controller] Resolving node 6 took 304 seconds
2024-05-13 14:59:53.863 (MainThread) DEBUG [matter_server.server.device_controller] Resolving node 6 took 310 seconds
2024-05-13 14:59:53.863 (MainThread) ERROR [matter_server.server.client_handler] [549391037840] Error while handling: read_attribute (node 6): Unable to resolve Node 6
2024-05-13 15:01:02.657 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:264333351 on exchange 56755i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-13 15:01:10.788 (Dummy-2) CHIP_ERROR [chip.native.SC] CASESession timed out while waiting for a response from the peer. Current state was 4
2024-05-13 15:02:17.172 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:264333352 on exchange 56756i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-13 15:02:27.515 (Dummy-2) CHIP_ERROR [chip.native.SC] CASESession timed out while waiting for a response from the peer. Current state was 4
2024-05-13 15:02:27.516 (Dummy-2) CHIP_ERROR [chip.native.DMG] Failed to establish CASE for re-subscription with error 'src/protocols/secure_channel/CASESession.cpp:560: CHIP Error 0x00000032: Timeout'
2024-05-13 15:02:27.518 (MainThread) INFO [matter_server.server.device_controller.node_6] Previous subscription failed with Error: 50, re-subscribing in 16151 ms...
2024-05-13 15:02:30.520 (MainThread) INFO [matter_server.server.device_controller] Attempting to resolve node 6... (attempt 2 of 2)
2024-05-13 15:03:38.089 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:264333353 on exchange 56757i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-13 15:03:44.450 (Dummy-2) CHIP_ERROR [chip.native.SC] CASESession timed out while waiting for a response from the peer. Current state was 4
2024-05-13 15:04:50.188 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:264333354 on exchange 56758i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-13 15:05:01.181 (Dummy-2) CHIP_ERROR [chip.native.SC] CASESession timed out while waiting for a response from the peer. Current state was 4
2024-05-13 15:05:01.182 (Dummy-2) CHIP_ERROR [chip.native.DMG] Failed to establish CASE for re-subscription with error 'src/protocols/secure_channel/CASESession.cpp:560: CHIP Error 0x00000032: Timeout'
2024-05-13 15:05:01.184 (MainThread) INFO [matter_server.server.device_controller.node_6] Previous subscription failed with Error: 50, re-subscribing in 36336 ms...
2024-05-13 15:05:04.186 (MainThread) INFO [matter_server.server.device_controller] Attempting to resolve node 6... (attempt 2 of 2)
2024-05-13 15:06:06.730 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:264333355 on exchange 56759i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-13 15:06:18.115 (Dummy-2) CHIP_ERROR [chip.native.SC] CASESession timed out while waiting for a response from the peer. Current state was 4
2024-05-13 15:07:23.308 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:264333356 on exchange 56760i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-13 15:07:34.843 (Dummy-2) CHIP_ERROR [chip.native.SC] CASESession timed out while waiting for a response from the peer. Current state was 4
2024-05-13 15:07:34.844 (Dummy-2) CHIP_ERROR [chip.native.DMG] Failed to establish CASE for re-subscription with error 'src/protocols/secure_channel/CASESession.cpp:560: CHIP Error 0x00000032: Timeout'
2024-05-13 15:07:34.845 (MainThread) INFO [matter_server.server.device_controller.node_6] Previous subscription failed with Error: 50, re-subscribing in 45412 ms...
2024-05-13 15:07:37.850 (MainThread) INFO [matter_server.server.device_controller] Attempting to resolve node 6... (attempt 2 of 2)
2024-05-13 15:08:45.757 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:264333357 on exchange 56761i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-13 15:08:51.774 (Dummy-2) CHIP_ERROR [chip.native.SC] CASESession timed out while waiting for a response from the peer. Current state was 4
2024-05-13 15:10:01.886 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:264333358 on exchange 56762i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-13 15:10:08.505 (Dummy-2) CHIP_ERROR [chip.native.SC] CASESession timed out while waiting for a response from the peer. Current state was 4
2024-05-13 15:10:08.507 (Dummy-2) CHIP_ERROR [chip.native.DMG] Failed to establish CASE for re-subscription with error 'src/protocols/secure_channel/CASESession.cpp:560: CHIP Error 0x00000032: Timeout'
2024-05-13 15:10:08.510 (MainThread) INFO [matter_server.server.device_controller.node_6] Previous subscription failed with Error: 50, re-subscribing in 114563 ms...
2024-05-13 15:10:11.511 (MainThread) INFO [matter_server.server.device_controller] Attempting to resolve node 6... (attempt 2 of 2)
2024-05-13 15:11:18.632 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:264333359 on exchange 56763i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-13 15:11:25.443 (Dummy-2) CHIP_ERROR [chip.native.SC] CASESession timed out while waiting for a response from the peer. Current state was 4
2024-05-13 15:12:30.821 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:264333360 on exchange 56764i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-13 15:12:42.174 (Dummy-2) CHIP_ERROR [chip.native.SC] CASESession timed out while waiting for a response from the peer. Current state was 4
2024-05-13 15:12:42.176 (Dummy-2) CHIP_ERROR [chip.native.DMG] Failed to establish CASE for re-subscription with error 'src/protocols/secure_channel/CASESession.cpp:560: CHIP Error 0x00000032: Timeout'
2024-05-13 15:12:42.178 (MainThread) INFO [matter_server.server.device_controller.node_6] Previous subscription failed with Error: 50, re-subscribing in 189284 ms...
2024-05-13 15:12:42.179 (MainThread) DEBUG [matter_server.server.device_controller] Resolving node 6 took 918 seconds
2024-05-13 15:12:42.179 (MainThread) DEBUG [matter_server.server.device_controller] Resolving node 6 took 1078 seconds
2024-05-13 15:12:42.179 (MainThread) ERROR [matter_server.server.client_handler] [549391037840] Error while handling: read_attribute (node 6): Unable to resolve Node 6
2024-05-13 15:13:49.159 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:264333361 on exchange 56765i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-13 15:13:59.111 (Dummy-2) CHIP_ERROR [chip.native.SC] CASESession timed out while waiting for a response from the peer. Current state was 4
2024-05-13 15:15:05.120 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:264333362 on exchange 56766i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-13 15:15:15.843 (Dummy-2) CHIP_ERROR [chip.native.SC] CASESession timed out while waiting for a response from the peer. Current state was 4
2024-05-13 15:15:15.844 (Dummy-2) CHIP_ERROR [chip.native.DMG] Failed to establish CASE for re-subscription with error 'src/protocols/secure_channel/CASESession.cpp:560: CHIP Error 0x00000032: Timeout'
2024-05-13 15:15:15.845 (MainThread) INFO [matter_server.server.device_controller.node_6] Previous subscription failed with Error: 50, re-subscribing in 221743 ms...
2024-05-13 15:15:15.846 (MainThread) DEBUG [matter_server.server.device_controller] Resolving node 6 took 765 seconds
2024-05-13 15:15:15.846 (MainThread) DEBUG [matter_server.server.device_controller] Resolving node 6 took 1157 seconds
2024-05-13 15:15:15.846 (MainThread) ERROR [matter_server.server.client_handler] [549391037840] Error while handling: read_attribute (node 6): Unable to resolve Node 6

Additional information

The other non-thread matter devices work mostly w/o any issues.

[home-assistant]

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)}}

[jkporter]

This issue has recently resolved itself. Only notable change was a core upgrade from 2024.5.3 to 2024.5.4. After resetting and repairing the sensor on May 13th; from May 16th to the writing of comment it has been perfectly stable save for one 11 min and one 16 min unavailability window.