Matter devices pingable but not connecting, Eero border router

Configuration Matter/Thread
1

I have about 30 Inovelli switches connected through 3 backhauled Eero Pro 6Es (latest firmware) as the border routers. HA OS on a RPi 5 directly connected to one of the Eeros.

I setup all of my devices and at some point they were all connected to HA, but over time various ones lost their connection were be unable to re-obtain it. Matter logs show loops of this form:

2025-01-13 00:03:40.081 (Dummy-2) CHIP_ERROR [chip.native.EM] <<5 [E:61936i with Node: <0000000000000000, 0> S:0 M:194691811] (U) Msg Retransmission to 0:0000000000000000 failure (max retries:4)
2025-01-13 00:03:43.473 (Dummy-2) CHIP_ERROR [chip.native.SC] CASESession timed out while waiting for a response from peer <0000000000000022, 1>. Current state was 3
2025-01-13 00:03:43.474 (MainThread) WARNING [matter_server.server.device_controller] <Node:34> Setup for node failed: Unable to establish CASE session with Node 34
2025-01-13 00:03:43.474 (MainThread) INFO [matter_server.server.device_controller] <Node:34> Retrying node setup in 60 seconds...

I don’t see much about the retransmission error online. The weird thing is that all of my switches are pingable, so I’m not sure why the Matter server can’t communicate with them.

My switches mostly show strong Thread signals when checked on-device. There’s no discernible pattern in which switches can and can’t connect. Restarting HA/the Matter addon doesn’t seem to change what is reachable, but restarting all of my routers + HA sometimes does.

Any advice on further debugging? My fear is that Eero is just a buggy border router since it seems to be a less popular solution/maybe doesn’t use OpenThread and I’d be better off switching to a ZBT-1.

2

As far as I know Eero uses OpenThread and should be a great TBR. More likely there’s an IPv6 issue somewhere. How are you determining the IP to ping your switches? Are you pinging from HA or another host? The traceroute6 command will also help determine which TBR is actually being used. I think I have seen a few instances where more than one TBR has caused disconnect issues.

1 Like
3

How are you determining the IP to ping your switches? Are you pinging from HA or another host?

I’ve found IP via both the Flame iOS app (lists mDNS records) and HA’s device info: they’ve always been the same. I have pinged both via HA’s button and my laptop via ping6.

The traceroute6 command will also help determine which TBR is actually being used.

I’m not familiar with the right flags to achieve that…advice? With no args or -I I only get my gateway and the destination device, nothing or timeouts in between.

For my own debugging, trying to isolate this to specific switches:
I cut power to all switches and brought them back one at a time, starting closest to one of my TBRs, watching logs for session establishment. The ones that failed to connect (6 of them) I re-cut power to. There’s no pattern to those 6, switches in the same gang box as them connect just fine. Then, to test, I restarted my Matter server to see if the previously-working ones would successfully re-pair. After about 2m the whole network (minus the 6 without power) was back.

I have trouble believing this is due to some issue with that switch, but more likely something in the routing to the device. Going to (1) leave one weird switch powered to see if it heals (2) reset and re-pair another weird switch to see if it loses its marbles again.

Any additional suggestions always appreciated :slight_smile:

4

Of note: I have some switches bound together, one connecting and one not connecting to HA, and these still work/talk to each other without issue.

I went whole-hog on debug settings and compared a non-connecting switch with a connecting switch. Below is the non-working switch exchange.

It looks like the switch is ACKing the first message (89626870), but then never receives 89626872 (it keeps sending ACKs). The only other weird thing is that 30s after the exchange there’s some random message ACK (33564705) that has a different exchange number but the same IPv6.

The million dollar question is why 89626872 isn’t getting through, especially since 89626870 is…

2025-01-14 13:37:18.285 (MainThread) INFO [matter_server.server.device_controller.mdns] <Node:1> Discovered on mDNS
2025-01-14 13:37:18.294 (MainThread) INFO [matter_server.server.device_controller] <Node:1> Setting-up node...
2025-01-14 13:37:18.294 (MainThread) DEBUG [matter_server.server.sdk] <Node:1> Attempting to establish CASE session... (attempt 1 of 2)
2025-01-14 13:37:18.319 (Dummy-2) CHIP_PROGRESS [chip.native.DIS] UDP:[fdeb:f2b3:8680:1:2e4b:23fa:b743:c222%end0]:5540: new best score: 3 (for 6E9B37F21E729731-0000000000000001)
2025-01-14 13:37:18.319 (Dummy-2) CHIP_PROGRESS [chip.native.DIS] Checking node lookup status for 6E9B37F21E729731-0000000000000001 after 20 ms
2025-01-14 13:37:18.319 (Dummy-2) CHIP_PROGRESS [chip.native.DIS] Keeping DNSSD lookup active
2025-01-14 13:37:18.332 (Dummy-2) CHIP_DETAIL [chip.native.DIS] Lookup clearing interface for non LL address
2025-01-14 13:37:18.332 (Dummy-2) CHIP_PROGRESS [chip.native.DIS] UDP:[fdeb:f2b3:8680:1:2e4b:23fa:b743:c222%end0]:5540: new best score: 3 (for 6E9B37F21E729731-0000000000000001)
2025-01-14 13:37:18.332 (Dummy-2) CHIP_PROGRESS [chip.native.DIS] Checking node lookup status for 6E9B37F21E729731-0000000000000001 after 33 ms
2025-01-14 13:37:18.332 (Dummy-2) CHIP_PROGRESS [chip.native.DIS] Keeping DNSSD lookup active
2025-01-14 13:37:18.504 (Dummy-2) CHIP_PROGRESS [chip.native.DIS] Checking node lookup status for 6E9B37F21E729731-0000000000000001 after 205 ms
2025-01-14 13:37:18.504 (Dummy-2) CHIP_DETAIL [chip.native.DIS] OperationalSessionSetup[1:0000000000000001]: Updating device address to UDP:[fdeb:f2b3:8680:1:2e4b:23fa:b743:c222]:5540 while in state 2
2025-01-14 13:37:18.504 (Dummy-2) CHIP_DETAIL [chip.native.DIS] OperationalSessionSetup[1:0000000000000001]: State change 2 --> 3
2025-01-14 13:37:18.504 (Dummy-2) CHIP_DETAIL [chip.native.IN] SecureSession[0x7fa0008d00]: Allocated Type:2 LSID:24273
2025-01-14 13:37:18.505 (Dummy-2) CHIP_PROGRESS [chip.native.SC] Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001
2025-01-14 13:37:18.507 (Dummy-2) CHIP_DETAIL [chip.native.CTL] StorageAdapter::GetKeyValue: Key = f/1/g, Value = 0x7fabffdb88 (128)
2025-01-14 13:37:18.507 (Dummy-2) CHIP_DETAIL [chip.native.CTL] Key Found 23

2025-01-14 13:37:18.507 (Dummy-2) CHIP_DETAIL [chip.native.CTL] StorageAdapter::GetKeyValue: Key = f/1/k/0, Value = 0x7fabffd9b0 (128)
2025-01-14 13:37:18.507 (Dummy-2) CHIP_DETAIL [chip.native.CTL] Key Found 97

2025-01-14 13:37:18.508 (Dummy-2) CHIP_DETAIL [chip.native.CTL] StorageAdapter::GetKeyValue: Key = f/1/s/0000000000000001, Value = 0x7fabffdbd8 (74)
2025-01-14 13:37:18.508 (Dummy-2) CHIP_DETAIL [chip.native.CTL] Key Not Found

2025-01-14 13:37:18.508 (Dummy-2) CHIP_PROGRESS [chip.native.EM] <<< [E:53248i S:0 M:89626870] (U) Msg TX from 6C8B39B11FC512AD to 0:0000000000000000 [0000] [UDP:[fdeb:f2b3:8680:1:2e4b:23fa:b743:c222]:5540] --- Type 0000:30 (SecureChannel:CASE_Sigma1) (B:196)
2025-01-14 13:37:18.508 (Dummy-2) CHIP_PROGRESS [chip.native.EM] ??1 [E:53248i with Node: <0000000000000000, 0> S:0 M:89626870] (U) Msg Retransmission to 0:0000000000000000 in 1081ms [State:Idle II:800 AI:2000 AT:4000]
2025-01-14 13:37:18.508 (Dummy-2) CHIP_PROGRESS [chip.native.SC] Sent Sigma1 msg to <0000000000000001, 1> [II:500ms AI:300ms AT:4000ms]
2025-01-14 13:37:18.508 (Dummy-2) CHIP_DETAIL [chip.native.DIS] OperationalSessionSetup[1:0000000000000001]: State change 3 --> 4
2025-01-14 13:37:18.661 (Dummy-2) CHIP_PROGRESS [chip.native.EM] >>> [E:53248i S:0 M:33564702 (Ack:89626870)] (U) Msg RX from 0:0000000000000000 [0000] to 6C8B39B11FC512AD --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
2025-01-14 13:37:18.661 (Dummy-2) CHIP_DETAIL [chip.native.EM] Found matching exchange: 53248i with Node: <0000000000000000, 0>, Delegate: 0x7fa0009378
2025-01-14 13:37:18.661 (Dummy-2) CHIP_DETAIL [chip.native.EM] Rxd Ack; Removing MessageCounter:89626870 from Retrans Table on exchange 53248i with Node: <0000000000000000, 0>
2025-01-14 13:37:19.152 (Dummy-2) CHIP_PROGRESS [chip.native.EM] >>> [E:53248i S:0 M:33564703 (Ack:89626870)] (U) Msg RX from 0:0000000000000000 [0000] to 6C8B39B11FC512AD --- Type 0000:31 (SecureChannel:CASE_Sigma2) (B:732)
2025-01-14 13:37:19.152 (Dummy-2) CHIP_DETAIL [chip.native.EM] Found matching exchange: 53248i with Node: <0000000000000000, 0>, Delegate: 0x7fa0009378
2025-01-14 13:37:19.152 (Dummy-2) CHIP_DETAIL [chip.native.EM] CHIP MessageCounter:89626870 not in RetransTable on exchange 53248i with Node: <0000000000000000, 0>
2025-01-14 13:37:19.153 (Dummy-2) CHIP_PROGRESS [chip.native.SC] Received Sigma2 msg
2025-01-14 13:37:19.153 (Dummy-2) CHIP_DETAIL [chip.native.SC] Peer assigned session session ID 51017
2025-01-14 13:37:19.159 (Dummy-2) CHIP_DETAIL [chip.native.CTL] StorageAdapter::GetKeyValue: Key = f/1/r, Value = 0x7fabffcee0 (400)
2025-01-14 13:37:19.159 (Dummy-2) CHIP_DETAIL [chip.native.CTL] Key Found 231
2025-01-14 13:37:19.179 (Dummy-2) CHIP_DETAIL [chip.native.SC] Found MRP parameters in the message
2025-01-14 13:37:19.179 (Dummy-2) CHIP_DETAIL [chip.native.SC] Sending Sigma3
2025-01-14 13:37:19.179 (Dummy-2) CHIP_DETAIL [chip.native.CTL] StorageAdapter::GetKeyValue: Key = f/1/i, Value = 0x7fa000d340 (400)
2025-01-14 13:37:19.180 (Dummy-2) CHIP_DETAIL [chip.native.CTL] Key Found 231
2025-01-14 13:37:19.180 (Dummy-2) CHIP_DETAIL [chip.native.CTL] StorageAdapter::GetKeyValue: Key = f/1/n, Value = 0x7fa00174f0 (400)
2025-01-14 13:37:19.180 (Dummy-2) CHIP_DETAIL [chip.native.CTL] Key Found 244
2025-01-14 13:37:19.183 (Dummy-2) CHIP_PROGRESS [chip.native.EM] <<< [E:53248i S:0 M:89626872 (Ack:33564703)] (U) Msg TX from 6C8B39B11FC512AD to 0:0000000000000000 [0000] [UDP:[fdeb:f2b3:8680:1:2e4b:23fa:b743:c222]:5540] --- Type 0000:32 (SecureChannel:CASE_Sigma3) (B:598)
2025-01-14 13:37:19.183 (Dummy-2) CHIP_PROGRESS [chip.native.EM] ??1 [E:53248i with Node: <0000000000000000, 0> S:0 M:89626872] (U) Msg Retransmission to 0:0000000000000000 in 2495ms [State:Active II:800 AI:2000 AT:4000]

2025-01-14 13:37:20.122 (Dummy-2) CHIP_DETAIL [chip.native.IN] Received a duplicate message with MessageCounter:33564703 on exchange 53248i
2025-01-14 13:37:20.123 (Dummy-2) CHIP_PROGRESS [chip.native.EM] >>> [E:53248i S:0 M:33564703 (Ack:89626870)] (U) Msg RX from 0:0000000000000000 [0000] to 6C8B39B11FC512AD --- Type 0000:31 (SecureChannel:CASE_Sigma2) (B:732)
2025-01-14 13:37:20.123 (Dummy-2) CHIP_DETAIL [chip.native.EM] Found matching exchange: 53248i with Node: <0000000000000000, 0>, Delegate: 0x7fa0009378
2025-01-14 13:37:20.123 (Dummy-2) CHIP_DETAIL [chip.native.EM] Forcing tx of solitary ack for duplicate MessageCounter:33564703 on exchange 53248i with Node: <0000000000000000, 0>
2025-01-14 13:37:20.123 (Dummy-2) CHIP_PROGRESS [chip.native.EM] <<< [E:53248i S:0 M:89626877 (Ack:33564703)] (U) Msg TX from 6C8B39B11FC512AD to 0:0000000000000000 [0000] [UDP:[fdeb:f2b3:8680:1:2e4b:23fa:b743:c222]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)

2025-01-14 13:37:20.770 (Dummy-2) CHIP_DETAIL [chip.native.IN] Received a duplicate message with MessageCounter:33564703 on exchange 53248i
2025-01-14 13:37:20.771 (Dummy-2) CHIP_PROGRESS [chip.native.EM] >>> [E:53248i S:0 M:33564703 (Ack:89626870)] (U) Msg RX from 0:0000000000000000 [0000] to 6C8B39B11FC512AD --- Type 0000:31 (SecureChannel:CASE_Sigma2) (B:732)
2025-01-14 13:37:20.771 (Dummy-2) CHIP_DETAIL [chip.native.EM] Found matching exchange: 53248i with Node: <0000000000000000, 0>, Delegate: 0x7fa0009378
2025-01-14 13:37:20.771 (Dummy-2) CHIP_DETAIL [chip.native.EM] Forcing tx of solitary ack for duplicate MessageCounter:33564703 on exchange 53248i with Node: <0000000000000000, 0>
2025-01-14 13:37:20.771 (Dummy-2) CHIP_PROGRESS [chip.native.EM] <<< [E:53248i S:0 M:89626883 (Ack:33564703)] (U) Msg TX from 6C8B39B11FC512AD to 0:0000000000000000 [0000] [UDP:[fdeb:f2b3:8680:1:2e4b:23fa:b743:c222]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)

2025-01-14 13:37:21.678 (Dummy-2) CHIP_PROGRESS [chip.native.EM] <<1 [E:53248i with Node: <0000000000000000, 0> S:0 M:89626872] (U) Msg Retransmission to 0:0000000000000000
2025-01-14 13:37:21.679 (Dummy-2) CHIP_PROGRESS [chip.native.EM] ??2 [E:53248i with Node: <0000000000000000, 0> S:0 M:89626872] (U) Msg Retransmission to 0:0000000000000000 in 2284ms [State:Active II:800 AI:2000 AT:4000]

2025-01-14 13:37:21.886 (Dummy-2) CHIP_DETAIL [chip.native.IN] Received a duplicate message with MessageCounter:33564703 on exchange 53248i
2025-01-14 13:37:21.886 (Dummy-2) CHIP_PROGRESS [chip.native.EM] >>> [E:53248i S:0 M:33564703 (Ack:89626870)] (U) Msg RX from 0:0000000000000000 [0000] to 6C8B39B11FC512AD --- Type 0000:31 (SecureChannel:CASE_Sigma2) (B:732)
2025-01-14 13:37:21.887 (Dummy-2) CHIP_DETAIL [chip.native.EM] Found matching exchange: 53248i with Node: <0000000000000000, 0>, Delegate: 0x7fa0009378
2025-01-14 13:37:21.888 (Dummy-2) CHIP_DETAIL [chip.native.EM] Forcing tx of solitary ack for duplicate MessageCounter:33564703 on exchange 53248i with Node: <0000000000000000, 0>
2025-01-14 13:37:21.888 (Dummy-2) CHIP_PROGRESS [chip.native.EM] <<< [E:53248i S:0 M:89626885 (Ack:33564703)] (U) Msg TX from 6C8B39B11FC512AD to 0:0000000000000000 [0000] [UDP:[fdeb:f2b3:8680:1:2e4b:23fa:b743:c222]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)

2025-01-14 13:37:23.161 (Dummy-2) CHIP_DETAIL [chip.native.IN] Received a duplicate message with MessageCounter:33564703 on exchange 53248i
2025-01-14 13:37:23.161 (Dummy-2) CHIP_PROGRESS [chip.native.EM] >>> [E:53248i S:0 M:33564703 (Ack:89626870)] (U) Msg RX from 0:0000000000000000 [0000] to 6C8B39B11FC512AD --- Type 0000:31 (SecureChannel:CASE_Sigma2) (B:732)
2025-01-14 13:37:23.162 (Dummy-2) CHIP_DETAIL [chip.native.EM] Found matching exchange: 53248i with Node: <0000000000000000, 0>, Delegate: 0x7fa0009378
2025-01-14 13:37:23.162 (Dummy-2) CHIP_DETAIL [chip.native.EM] Forcing tx of solitary ack for duplicate MessageCounter:33564703 on exchange 53248i with Node: <0000000000000000, 0>
2025-01-14 13:37:23.162 (Dummy-2) CHIP_PROGRESS [chip.native.EM] <<< [E:53248i S:0 M:89626886 (Ack:33564703)] (U) Msg TX from 6C8B39B11FC512AD to 0:0000000000000000 [0000] [UDP:[fdeb:f2b3:8680:1:2e4b:23fa:b743:c222]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)

2025-01-14 13:37:45.072 (Dummy-2) CHIP_ERROR [chip.native.EM] <<5 [E:53248i with Node: <0000000000000000, 0> S:0 M:89626872] (U) Msg Retransmission to 0:0000000000000000 failure (max retries:4)

2025-01-14 13:38:12.783 (Dummy-2) CHIP_DETAIL [chip.native.IN] Received a duplicate message with MessageCounter:33564705 on exchange 53264i
2025-01-14 13:38:12.783 (Dummy-2) CHIP_PROGRESS [chip.native.EM] >>> [E:53264i S:0 M:33564705 (Ack:89626905)] (U) Msg RX from 0:0000000000000000 [0000] to 989469872C5BBE35 --- Type 0000:31 (SecureChannel:CASE_Sigma2) (B:732)
2025-01-14 13:38:12.783 (Dummy-2) CHIP_DETAIL [chip.native.EM] Found matching exchange: 53264i with Node: <0000000000000000, 0>, Delegate: 0x7fa0009378
2025-01-14 13:38:12.783 (Dummy-2) CHIP_DETAIL [chip.native.EM] Forcing tx of solitary ack for duplicate MessageCounter:33564705 on exchange 53264i with Node: <0000000000000000, 0>
2025-01-14 13:38:12.783 (Dummy-2) CHIP_PROGRESS [chip.native.EM] <<< [E:53264i S:0 M:89626919 (Ack:33564705)] (U) Msg TX from 989469872C5BBE35 to 0:0000000000000000 [0000] [UDP:[fdeb:f2b3:8680:1:2e4b:23fa:b743:c222]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)