Adding a thread device

stevegroom · May 25, 2024, 9:11am

OK, it’s the weekend and time to try again.

So I checked HA and have just one Matter device - a Meross WiFi plug. So I removed the device, then removed the Thread and Matter integrations.

Then I re-added the Matter and Thread integrations.

Immediately the previous matter networks and device were there!
The Meross WiFi plug and the thread neworks:

I used the integration > delete option to remove both of these.

Anyway, back to the SmartBlind to see if this made any difference. The SmartWings Blind was already added to Apple Home, so I went into Home > Device Settings > Turn On Pairing Mode and following several attempts it reported Could Not Complete Operation OK.

I suspected this was because the blind was too remote from the Apple TV, so I dismounted the blind and moved it closer to the TV and the pairing code was immediately displayed. But every attempt to use that code in HA resulted in the same failed to add device message from HA.

The Matter Server log:

2024-05-25 10:04:19.348 (MainThread) INFO [matter_server.server.device_controller] Starting Matter commissioning with code using Node ID 19 (attempt 1/3).
2024-05-25 10:04:48.252 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:125688233 on exchange 11064i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-25 10:04:49.354 (Dummy-2) CHIP_ERROR [chip.native.CTL] Discovery timed out
2024-05-25 10:04:56.587 (Dummy-2) CHIP_ERROR [chip.native.SC] PASESession timed out while waiting for a response from the peer. Expected message type was 33
2024-05-25 10:04:56.588 (Dummy-2) CHIP_ERROR [chip.native.ZCL] Secure Pairing Failed
2024-05-25 10:04:56.589 (Dummy-2) WARNING [root] Failed to establish secure session to device: src/controller/python/ChipDeviceController-ScriptDevicePairingDelegate.cpp:89: CHIP Error 0x00000003: Incorrect state
2024-05-25 10:04:56.589 (Dummy-2) WARNING [root] Failed to commission: src/controller/python/ChipDeviceController-ScriptDevicePairingDelegate.cpp:89: CHIP Error 0x00000003: Incorrect state
2024-05-25 10:05:01.593 (MainThread) INFO [matter_server.server.device_controller] Starting Matter commissioning with code using Node ID 19 (attempt 2/3).
2024-05-25 10:05:30.440 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:125688234 on exchange 11065i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-25 10:05:31.601 (Dummy-2) CHIP_ERROR [chip.native.CTL] Discovery timed out
2024-05-25 10:05:38.789 (Dummy-2) CHIP_ERROR [chip.native.SC] PASESession timed out while waiting for a response from the peer. Expected message type was 33
2024-05-25 10:05:38.790 (Dummy-2) CHIP_ERROR [chip.native.ZCL] Secure Pairing Failed
2024-05-25 10:05:38.791 (Dummy-2) WARNING [root] Failed to establish secure session to device: src/controller/python/ChipDeviceController-ScriptDevicePairingDelegate.cpp:89: CHIP Error 0x00000003: Incorrect state
2024-05-25 10:05:38.791 (Dummy-2) WARNING [root] Failed to commission: src/controller/python/ChipDeviceController-ScriptDevicePairingDelegate.cpp:89: CHIP Error 0x00000003: Incorrect state
2024-05-25 10:05:43.794 (MainThread) INFO [matter_server.server.device_controller] Starting Matter commissioning with code using Node ID 19 (attempt 3/3).
2024-05-25 10:06:13.801 (Dummy-2) CHIP_ERROR [chip.native.CTL] Discovery timed out
2024-05-25 10:06:14.176 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:125688235 on exchange 11066i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-25 10:06:20.963 (Dummy-2) CHIP_ERROR [chip.native.SC] PASESession timed out while waiting for a response from the peer. Expected message type was 33
2024-05-25 10:06:20.964 (Dummy-2) CHIP_ERROR [chip.native.ZCL] Secure Pairing Failed
2024-05-25 10:06:20.965 (Dummy-2) WARNING [root] Failed to establish secure session to device: src/controller/python/ChipDeviceController-ScriptDevicePairingDelegate.cpp:89: CHIP Error 0x00000003: Incorrect state
2024-05-25 10:06:20.965 (Dummy-2) WARNING [root] Failed to commission: src/controller/python/ChipDeviceController-ScriptDevicePairingDelegate.cpp:89: CHIP Error 0x00000003: Incorrect state
2024-05-25 10:06:20.967 (MainThread) ERROR [matter_server.server.client_handler] [547542435216] Error while handling: commission_with_code: Commission with code failed for node 19.

I need to buy a device to act as a Thread network extender and add that to Apple Home and I still need to clean up the HA Matter config to properly start over.

wmaker · May 25, 2024, 3:27pm

I think “commission_with_code” is for a new device that is not already on the network.
In HA, how did you do the “Add Device”?

stevegroom · May 25, 2024, 3:50pm

I added the blinds to Apple Home by scanning the QR code on the label.

Steve

wmaker · May 25, 2024, 4:36pm

Did theses instructions for adding a Matter device to HA that was already on Apple to HA not work?

stevegroom · May 25, 2024, 6:07pm

Yes, exactly that - devices > add matter device > already paired with Apple Home > get the pairing code from Apple and it gives the error log as shown earlier.

If there any sort of clean up needed in addition to deleting and reinstalling the Matter and Thread Integrations?

wmaker · May 25, 2024, 7:30pm

I went back and looked at the Matter Server code, and they did change the API call where “commission with code” should indeed handle the case of a device already on the network.

The other possible clue in the logs is “Discovery timed out”.
My understanding is that when commissioning a device on a second Matter fabric and that device is already commissioned an on another network/Matter-fabric, that only DNS-SD can be used to discover a device. A DNS-SD for _matterc._udp is sent out and the second Matter (HA) fabric controller listens for this when going through commissioning. For a Thread Network, the TBR proxies this for the actual device, so in your case the Apple TBR should be sending the DNS-SD out and Matter Server on HA should be seeing this. If you have the Apple TBR and HA on the same Layer2 network and IPv6 is enabled (set to automatic) on HA, then there is some problem I’m afraid I don’t have much of a clue as to why Discovery is failing.

stevegroom · May 25, 2024, 8:57pm

You might be on to something there. The Apple TV and the HomeAssistant are on different VLANS (on Ubiquiti). I’ll check the settings tomorrow to see if some additional config is needed.

regards
Steve

wmaker · May 25, 2024, 9:23pm

Its best to put them on the same VLAN. There are a few HA community threads using some kind of mDNS reflector/proxy on their Home G/W router so that mDNS will cross VLANs, but whether this works on Ubiquiti and if it does, will it work for IPv6, yeah you’ll have to research out.

stevegroom · May 26, 2024, 8:51am

First time looking at Thread networking etc, but after some googling I used the dns-sd command to do some tests.

I have two Macs, one on the main vlan and one now on the IOT vlan.

To monitor for AirTunes (Remote Audio Output Protocol)
dns-sd -B _raop._tcp

IOT Vlan:

9:39:13.058  Add        2   0 openthread.thread.home.arpa. _raop._tcp.          A851AB121788@Living Room
 9:39:27.600  Rmv        1  11 local.               _raop._tcp.          949F3ED8EBEE@Living Room
 9:39:27.600  Rmv        1  11 local.               _raop._tcp.          C43875001E14@Move
 9:39:27.600  Rmv        1  11 local.               _raop._tcp.          6C7E67BBF25E@Steve’s MacBook Pro (5)
 9:39:27.600  Rmv        0  11 local.               _raop._tcp.          A851AB121788@Living Room
 9:39:46.328  Add        3  11 local.               _raop._tcp.          949F3ED8EBEE@Living Room
 9:39:46.328  Add        3  11 local.               _raop._tcp.          6C7E67BBF25E@Steve’s MacBook Pro (5)
 9:39:46.328  Add        2  11 local.               _raop._tcp.          C43875001E14@Move
 9:39:46.424  Add        2  11 local.               _raop._tcp.          A851AB121788@Living Room

and on the general VLAN

dns-sd -B _raop._tcp
Browsing for _raop._tcp
DATE: ---Sun 26 May 2024---
 9:39:08.509  ...STARTING...
Timestamp     A/R    Flags  if Domain               Service Type         Instance Name
 9:39:08.511  Add        3   0 openthread.thread.home.arpa. _raop._tcp.          A851AB121788@Living Room
 9:39:08.511  Add        3  14 local.               _raop._tcp.          6C7E67BBF25E@Steve’s MacBook Pro (5)
 9:39:08.511  Add        3   1 local.               _raop._tcp.          6C7E67BBF25E@Steve’s MacBook Pro (5)
 9:39:08.511  Add        3  15 local.               _raop._tcp.          A477F304B821@SkarvaMac (2)
 9:39:08.511  Add        3  15 local.               _raop._tcp.          949F3ED8EBEE@Living Room
 9:39:08.511  Add        3  15 local.               _raop._tcp.          6C7E67BBF25E@Steve’s MacBook Pro (5)
 9:39:08.511  Add        3  15 local.               _raop._tcp.          A851AB121788@Living Room
 9:39:08.511  Add        2  15 local.               _raop._tcp.          C43875001E14@Move

Now trying the _matterc._udp protocol. Start the dns-sd command and then go to the device properties in Apple Home and Turn On Pairing Mode

IOT VLAN (HA is connected here)

dns-sd -B _matterc._tcp
Browsing for _matterc._tcp
DATE: ---Sun 26 May 2024---
 9:40:19.048  ...STARTING...

the messages are not getting through, whereas they are seen on the originating network.

General VLAN (Apple TV is connected here)

dns-sd -B _matterc._udp
Browsing for _matterc._udp
DATE: ---Sun 26 May 2024---
 9:40:20.508  ...STARTING...
Timestamp     A/R    Flags  if Domain               Service Type         Instance Name
 9:40:33.390  Add        2  15 local.               _matterc._udp.       CB854B5D620296BF
 9:45:33.787  Rmv        0  15 local.               _matterc._udp.       CB854B5D620296BF

wmaker · May 26, 2024, 6:47pm

Its a bit of a guess, but probably the IPv4 DNS-SD is getting across but not the IPv6 DNS-SD (which is the matterc._udp)

stevegroom · May 26, 2024, 7:38pm

I made a typo - on one side I had matter.tcp not udp.
After that the results are the same on both VLANS. And no change the logged messages in the matter server log.

wmaker · May 26, 2024, 7:45pm

Maybe next, from HA (on IoT VLAN) try pinging a device on the “General VLAN” using name.local to see if it gets across along with a response back.

stevegroom · May 26, 2024, 8:20pm

I found various IP addresses for the Apple TV and pinged them all.

IPv4 192.168.50.40 ping successfully
IPv6 has 5 IP addresses according to Ubiquiti - the first pings successfully the other 4 time out.
Finally ping livingroom.local responds - reporting the IPv4 address.

stevegroom · May 27, 2024, 7:53am

Today I tried temporarily moving the HomeAssistant Yellow over to the main VLAN so that Apple TV and HA are on the same network.

The pairing process changed in that Apple Home reported the pairing

But on the HA side the results were not better, though the logs are slightly differerent:

Please, share the above information when looking for help
 or support in, e.g., GitHub, forums or the Discord chat.
-----------------------------------------------------------
s6-rc: info: service banner successfully started
s6-rc: info: service matter-server: starting
s6-rc: info: service matter-server successfully started
s6-rc: info: service legacy-services: starting
[08:34:26] INFO: Starting Matter Server...
s6-rc: info: service legacy-services successfully started
[08:34:28] INFO: Using 'end0' as primary network interface.
[08:34:28] INFO: Successfully send discovery information to Home Assistant.
2024-05-27 08:34:35.230 (MainThread) INFO [matter_server.server.stack] Initializing CHIP/Matter Logging...
2024-05-27 08:34:35.231 (MainThread) INFO [matter_server.server.stack] Initializing CHIP/Matter Controller Stack...
[1716795275.424814][126:126] CHIP:CTL: Setting attestation nonce to random value
[1716795275.430899][126:126] CHIP:CTL: Setting CSR nonce to random value
[1716795275.449510][126:126] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1716795275.450137][126:126] CHIP:DL: writing settings to file (/tmp/chip_kvs-5xxFXH)
[1716795275.450674][126:126] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs)
[1716795275.451837][126:126] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /data/chip_factory.ini
[1716795275.456256][126:126] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /data/chip_config.ini
[1716795275.456925][126:126] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /data/chip_counters.ini
[1716795275.459012][126:126] CHIP:DL: writing settings to file (/data/chip_counters.ini-46tAWG)
[1716795275.459963][126:126] CHIP:DL: renamed tmp file to file (/data/chip_counters.ini)
[1716795275.460031][126:126] CHIP:DL: NVS set: chip-counters/reboot-count = 50 (0x32)
[1716795275.461209][126:126] CHIP:DL: Got Ethernet interface: end0
[1716795275.462013][126:126] CHIP:DL: Found the primary Ethernet interface:end0
[1716795275.462581][126:126] CHIP:DL: Got WiFi interface: wlan0
[1716795275.462651][126:126] CHIP:DL: Failed to reset WiFi statistic counts
2024-05-27 08:34:35.464 (MainThread) WARNING [PersistentStorage] Initializing persistent storage from file: /data/chip.json
2024-05-27 08:34:35.465 (MainThread) WARNING [PersistentStorage] Loading configuration from /data/chip.json...
2024-05-27 08:34:35.749 (MainThread) WARNING [CertificateAuthorityManager] Loading certificate authorities from storage...
2024-05-27 08:34:35.750 (MainThread) WARNING [CertificateAuthority] New CertificateAuthority at index 1
2024-05-27 08:34:35.753 (MainThread) WARNING [CertificateAuthority] Loading fabric admins from storage...
2024-05-27 08:34:35.754 (MainThread) WARNING [FabricAdmin] New FabricAdmin: FabricId: 0x0000000000000002, VendorId = 0x134B
2024-05-27 08:34:35.755 (MainThread) INFO [matter_server.server.stack] CHIP Controller Stack initialized.
2024-05-27 08:34:35.766 (MainThread) INFO [matter_server.server.server] Starting the Matter Server...
2024-05-27 08:34:35.778 (MainThread) INFO [matter_server.server.helpers.paa_certificates] Skip fetching certificates (already fetched within the last 24h).
2024-05-27 08:34:35.778 (MainThread) WARNING [FabricAdmin] Allocating new controller with CaIndex: 1, FabricId: 0x0000000000000002, NodeId: 0x000000000001B669, CatTags: []
2024-05-27 08:34:36.246 (Dummy-2) CHIP_ERROR [chip.native.DL] Long dispatch time: 464 ms, for event type 2
2024-05-27 08:34:36.260 (MainThread) INFO [matter_server.server.device_controller] Loaded 1 nodes from stored configuration
2024-05-27 08:34:36.277 (MainThread) INFO [matter_server.server.vendor_info] Loading vendor info from storage.
2024-05-27 08:34:36.290 (MainThread) INFO [matter_server.server.vendor_info] Loaded 196 vendors from storage.
2024-05-27 08:34:36.290 (MainThread) INFO [matter_server.server.vendor_info] Fetching the latest vendor info from DCL.
2024-05-27 08:34:36.734 (MainThread) INFO [matter_server.server.vendor_info] Fetched 194 vendors from DCL.
2024-05-27 08:34:36.734 (MainThread) INFO [matter_server.server.vendor_info] Saving vendor info to storage.
2024-05-27 08:34:36.931 (MainThread) INFO [matter_server.server.device_controller.mdns] Node 4 discovered on MDNS
2024-05-27 08:34:36.932 (MainThread) INFO [matter_server.server.device_controller.node_4] Setting-up node...
2024-05-27 08:34:43.296 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:88635637 on exchange 60652i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-27 08:34:46.182 (Dummy-2) CHIP_ERROR [chip.native.SC] CASESession timed out while waiting for a response from the peer. Current state was 1
2024-05-27 08:34:52.718 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:88635638 on exchange 60653i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-27 08:34:55.231 (Dummy-2) CHIP_ERROR [chip.native.SC] CASESession timed out while waiting for a response from the peer. Current state was 1
2024-05-27 08:34:58.692 (MainThread) INFO [matter_server.server.device_controller.node_4] Setting up attributes and events subscription.
2024-05-27 08:35:01.257 (MainThread) INFO [matter_server.server.device_controller.node_4] Subscription succeeded with report interval [0, 60]
2024-05-27 08:35:38.482 (MainThread) INFO [matter_server.server.device_controller] Starting Matter commissioning with code using Node ID 40 (attempt 1/3).
2024-05-27 08:35:40.960 (Dummy-2) INFO [root] Established secure session with Device
2024-05-27 08:35:50.269 (Dummy-2) CHIP_ERROR [chip.native.SC] Received error (protocol code 2) during pairing process: src/protocols/secure_channel/CASESession.cpp:1980: CHIP Error 0x00000054: Invalid CASE parameter
2024-05-27 08:35:50.270 (Dummy-2) CHIP_ERROR [chip.native.CTL] Error on commissioning step 'kFindOperationalForStayActive': 'src/protocols/secure_channel/CASESession.cpp:1980: CHIP Error 0x00000054: Invalid CASE parameter'
2024-05-27 08:35:50.271 (Dummy-2) WARNING [root] Failed to commission: src/protocols/secure_channel/CASESession.cpp:1980: CHIP Error 0x00000054: Invalid CASE parameter
2024-05-27 08:35:55.275 (MainThread) INFO [matter_server.server.device_controller] Starting Matter commissioning with code using Node ID 40 (attempt 2/3).
2024-05-27 08:36:25.279 (Dummy-2) CHIP_ERROR [chip.native.CTL] Discovery timed out
2024-05-27 08:36:25.280 (Dummy-2) CHIP_ERROR [chip.native.ZCL] Secure Pairing Failed
2024-05-27 08:36:25.280 (Dummy-2) WARNING [root] Failed to establish secure session to device: src/controller/python/ChipDeviceController-ScriptDevicePairingDelegate.cpp:89: CHIP Error 0x00000003: Incorrect state
2024-05-27 08:36:25.281 (Dummy-2) WARNING [root] Failed to commission: src/controller/python/ChipDeviceController-ScriptDevicePairingDelegate.cpp:89: CHIP Error 0x00000003: Incorrect state
2024-05-27 08:36:30.287 (MainThread) INFO [matter_server.server.device_controller] Starting Matter commissioning with code using Node ID 40 (attempt 3/3).
2024-05-27 08:36:43.837 (Dummy-2) INFO [root] Established secure session with Device
2024-05-27 08:37:26.033 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:165370396 on exchange 60668i with Node: <FFFFFFFB00000000, 0> sendCount: 4 max retries: 4
2024-05-27 08:37:32.348 (Dummy-2) CHIP_ERROR [chip.native.DMG] Time out! failed to receive report data from Exchange: 60668i with Node: <FFFFFFFB00000000, 0>
2024-05-27 08:38:13.292 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:165370397 on exchange 60669i with Node: <FFFFFFFB00000000, 0> sendCount: 4 max retries: 4
2024-05-27 08:38:20.861 (Dummy-2) CHIP_ERROR [chip.native.DMG] Time out! failed to receive report data from Exchange: 60669i with Node: <FFFFFFFB00000000, 0>
2024-05-27 08:38:20.861 (Dummy-2) CHIP_ERROR [chip.native.CTL] Failed to read BasicCommissioningInfo: src/app/ClusterStateCache.cpp:303: CHIP Error 0x00000010: Key not found
2024-05-27 08:38:20.862 (Dummy-2) CHIP_ERROR [chip.native.CTL] Failed to read RegulatoryConfig: src/app/ClusterStateCache.cpp:303: CHIP Error 0x00000010: Key not found
2024-05-27 08:38:20.863 (Dummy-2) CHIP_ERROR [chip.native.CTL] Failed to read LocationCapability: src/app/ClusterStateCache.cpp:303: CHIP Error 0x00000010: Key not found
2024-05-27 08:38:20.863 (Dummy-2) CHIP_ERROR [chip.native.CTL] Failed to read Breadcrumb: src/app/ClusterStateCache.cpp:303: CHIP Error 0x00000010: Key not found
2024-05-27 08:38:20.864 (Dummy-2) CHIP_ERROR [chip.native.CTL] Error parsing commissioning information
2024-05-27 08:38:20.865 (Dummy-2) CHIP_ERROR [chip.native.CTL] Error on commissioning step 'ReadCommissioningInfo2': 'src/app/ClusterStateCache.cpp:303: CHIP Error 0x00000010: Key not found'
2024-05-27 08:39:04.155 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:165370398 on exchange 60670i with Node: <FFFFFFFB00000000, 0> sendCount: 4 max retries: 4
2024-05-27 08:39:09.376 (Dummy-2) WARNING [root] Failed to commission: src/app/ClusterStateCache.cpp:303: CHIP Error 0x00000010: Key not found
2024-05-27 08:39:09.377 (MainThread) ERROR [matter_server.server.client_handler] [548104738320] Error while handling: commission_with_code: Commission with code failed for node 40.

wmaker · May 27, 2024, 6:06pm

stevegroom:

Starting Matter commissioning with code using Node ID 40 (attempt 1/3).
2024-05-27 08:35:40.960 (Dummy-2) INFO [root] Established secure session with Device
2024-05-27 08:35:50.269 (Dummy-2) CHIP_ERROR [chip.native.SC] Received error (protocol code 2) during pairing process: src/protocols/secure_channel/CASESession.cpp:1980: CHIP Error 0x00000054: Invalid CASE parameter

At least some progress… HA Matter Server is now talking to the device and has accepted the passcode; That is what “Established a secure session” means. The last part of commissioning is setting up a CASE session with the device which means you got this far, but I really have no idea at this point what the “Invalid CASE parameter” means. Are you using the iOS HA Companion App when adding the device to HA?

stevegroom · May 27, 2024, 6:49pm

Yes, used all the permutations available to me - ios Home to ios HomeAssistant app, iPad OS versions, and Macos too, but with the same results.

I have two matter / thread devices on the Apple Home - a smart plug and the blinds. The blinds are quite distant from the Apple TV but they are working well enough in the Home app.

Is there any way in the Apple Home ecosystem to tell if a Matter device has a good signal or is using another device as a repeater?

Steve.

wmaker · May 28, 2024, 6:01pm

Since HA and Apple are on the same VLAN, and what Matter calls the “Device Discovery” phase works (which means the communication with the device is working), I really don’t know why the “Operational Discovery” (CASE) phase is failing. I would recommend writing up an issue here and provide the logs above and see what they say.

agners · May 29, 2024, 7:00am

In general, Thread and Matter are quite orthogonal technologies. If a device is on a Thread network the Matter can control, pretty much all things Thread are not relevant anymore: As long as the device is on the Thread network and HA gets routes to that Thread network (via a existing Thread BR), you’re good. The fact that you see the Apple BR in the Thread panel tells you that the BR and HA is in the same network indeed

This is because the Matter Server is stateful: It stores all the devices it is connected to. If you want to really start clean slate all things Matter, you have to remove the Matter Server add-on as well.

stevegroom:

2024-05-25 10:04:19.348 (MainThread) INFO [matter_server.server.device_controller] Starting Matter commissioning with code using Node ID 19 (attempt 1/3).
2024-05-25 10:04:48.252 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:125688233 on exchange 11064i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-25 10:04:49.354 (Dummy-2) CHIP_ERROR [chip.native.CTL] Discovery timed out
2024-05-25 10:04:56.587 (Dummy-2) CHIP_ERROR [chip.native.SC] PASESession timed out while waiting for a response from the peer. Expected message type was 33
2024-05-25 10:04:56.588 (Dummy-2) CHIP_ERROR [chip.native.ZCL] Secure Pairing Failed

Hm, sounds the Matter Server is able to find the device, but the device doesn’t like to setup a password authenticated session (PASE) with the Matter server. From what I understand, this is typically for two reasons: The IP address which got resolved is not reachable/stale (restarting HAOS/Thread border router and wait for a bit might help to get a clean slate). The setup code is wrong (the fact that we see this quite often I wonder sometimes if some of the devices are buggy and report a setup code but have a commissioning phase open with an older code maybe? ).

stevegroom:

2024-05-27 08:35:40.960 (Dummy-2) INFO [root] Established secure session with Device
2024-05-27 08:35:50.269 (Dummy-2) CHIP_ERROR [chip.native.SC] Received error (protocol code 2) during pairing process: src/protocols/secure_channel/CASESession.cpp:1980: CHIP Error 0x00000054: Invalid CASE parameter
2024-05-27 08:35:50.270 (Dummy-2) CHIP_ERROR [chip.native.CTL] Error on commissioning step 'kFindOperationalForStayActive': 'src/protocols/secure_channel/CASESession.cpp:1980: CHIP Error 0x00000054: Invalid CASE parameter'
2024-05-27 08:35:50.271 (Dummy-2) WARNING [root] Failed to commission: src/protocols/secure_channel/CASESession.cpp:1980: CHIP Error 0x00000054: Invalid CASE parameter

Uh that is weird. Can you try to remove the existing fabric entry on the device? E.g. from Apple Home in the device settings under “Connected Services”. Remove any entry with number 4939 (the vendor ID of Nabu Casa, used by the Python Matter Server).

stevegroom · May 29, 2024, 10:41am

Ah - missed that - I removed the integrations, and forgot there was an add on.

Could not find that path - found the following
Apple Home > … > Home Settings > Connected Services (1) > Manage in IOS settings > I can see the Blind and MSS315 > Connected services 4939

I’m going to be busy for the next week, so will have to pick this up later.

Thanks to all for your expert assistance.

stevegroom · June 8, 2024, 12:21pm

Some progress.

Removed the blinds and the Wemo smart plug from Apple Home
Then uninstalled Matter server and the two integrations from HA.
Reset the Wemo plug and tried to add it to Apple Home - it said device already exists, but I could not find it ( I wonder if I originally installed this on HA with multi-protocol).
However the Wemo plug showed up in HA as a new device. I simply clicked on matter config and then added the web plug.
Checking the HA thread integration, I can see Apple Home is added back in automatically

image1238×1374 54.3 KB

No idea what MyHome92391987 is and if it can be deleted.

Reset the blind and put it in pairing mode. Opened Apple Home and add device. Device is discovered (nothing new with this).
Go to the device in Apple Home, turn on pairing mode, go to HA, and add device > matter > existing HomeKit device and enter the pairing code. This fails as before.
Shut down HA, change the vlan, cycle PoE power and HA starts up on the default vlan. i.e. the same subnet as two Apple TVs.
Turn off the HomeKit Apple TV as it was the older one without Thread.
Go to the blinds in Apple Home and turn on pairing mode again.
Go to HA devices > add > matter > existing HomeKit device and SUCCESS!

This was probably due to resetting HA Matter server and starting over.

Blinds added to dashboard and being controlled correctly.

HOWEVER - HA is not on the IOT VLAN.

Power down HA Yellow, change VLAN, cycle PoE and HA restarts
The two blinds are unreachable.

image1216×1108 51.6 KB

The Matter log has various messages:

2024-06-08 11:20:38.482 (Dummy-2) CHIP_ERROR [chip.native.SC] CASESession timed out while waiting for a response from the peer. Current state was 1
2024-06-08 11:20:38.484 (MainThread) WARNING [matter_server.server.device_controller.node_3] Setup for node failed: Unable to establish CASE session with Node 3
2024-06-08 11:58:23.314 (MainThread) INFO [matter_server.server.device_controller.mdns] Node 3 discovered on MDNS
2024-06-08 11:58:23.315 (MainThread) INFO [matter_server.server.device_controller.node_3] Setting-up node...
2024-06-08 11:58:23.528 (Dummy-2) CHIP_ERROR [chip.native.-] src/inet/UDPEndPointImplSockets.cpp:416: OS Error 0x02000065: Network is unreachable at src/app/OperationalSessionSetup.cpp:246

At some point the wemo plug turned up in Apple Home in the default room that Homeassistant uses.

In summary.
A clean install of Matter server really helped, but I suspect that Apple Home still has some old configuration that comes back (causing the Wemo plug issues). The successful connection of the HomeKit blinds to HomeAssistant on the same vlan but not on separate vlans shows that the current problem is with the inter vlan routing of the Ubiquiti router.