core: Adding matter device failed
The problem
I am trying Matter integration with Meross MSS315 and TAdpoP100M Matter compatible power plugs. Installed Matter Add-On and Integration 5.0.1, with the iOS companion app on the IoT wifi network I tried to add Matter devices but ultimately failed.
After failure (see log) I installed the respective vendor iOS apps and I can see and connect to the devices. I can see the two devices joined the IoT wifi network and took their respective IPv4 address.
Matter addon & integration 5.01 on HAOS 10.5, core-2023.12.2, Network: IPv6 is enabled on HA, IPv4 used on physical network, Unifi based (I mention it as many other posts relate to it) with all IoT devices (I have ) residing in their VLAN network and with access to HA host. mDNS is in use.
What version of Home Assistant Core has the issue?
core-2023.12.2
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
integration:matter
Link to integration documentation on our website
https://www.home-assistant.io/integrations/matter
Diagnostics information
No response
Example YAML snippet
No response
Anything in the logs that might be useful for us?
2023-12-15 09:30:19 core-matter-server chip.EM[127] DEBUG Found matching exchange: 17864i, Delegate: 0x7f6d84028ca8
2023-12-15 09:30:19 core-matter-server chip.EM[127] DEBUG Rxd Ack; Removing MessageCounter:238032483 from Retrans Table on exchange 17864i
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG ICR moving to [ResponseRe]
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG InvokeResponseMessage =
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG {
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG suppressResponse = false,
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG InvokeResponseIBs =
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG [
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG InvokeResponseIB =
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG {
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG CommandDataIB =
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG {
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG CommandPathIB =
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG {
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG EndpointId = 0x0,
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG ClusterId = 0x30,
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG CommandId = 0x1,
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG },
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG CommandFields =
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG {
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG 0x0 = 0,
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG 0x1 = "" (0 chars),
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG },
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG },
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG },
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG ],
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG InteractionModelRevision = 1
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG },
2023-12-15 09:30:19 core-matter-server chip.DMG[127] INFO Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
2023-12-15 09:30:19 core-matter-server chip.CTL[127] INFO Status of extending fail-safe for CASE retry: 0
2023-12-15 09:30:19 core-matter-server chip.DMG[127] DEBUG ICR moving to [AwaitingDe]
2023-12-15 09:30:19 core-matter-server chip.EM[127] INFO <<< [E:17864i S:17680 M:238032484 (Ack:101796576)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:192.168.107.106%enp0s3:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
2023-12-15 09:30:19 core-matter-server chip.EM[127] DEBUG Flushed pending ack for MessageCounter:101796576 on exchange 17864i
2023-12-15 09:30:55 core-matter-server chip.DIS[127] DEBUG OperationalSessionSetup[1:0000000000000009]: State change 6 --> 2
2023-12-15 09:30:55 core-matter-server chip.DIS[127] INFO UDP:[fe80::4ae1:e9ff:fedb:b928%enp0s3]:5540: new best score: 7
2023-12-15 09:30:55 core-matter-server chip.DIS[127] INFO UDP:192.168.107.106%enp0s3:5540: score has not improved: 2
2023-12-15 09:30:55 core-matter-server chip.DIS[127] INFO Checking node lookup status after 111 ms
2023-12-15 09:30:55 core-matter-server chip.DIS[127] INFO Keeping DNSSD lookup active
2023-12-15 09:30:55 core-matter-server chip.DIS[127] INFO UDP:[fe80::4ae1:e9ff:fedb:b928%enp0s3]:5540: score has not improved: 7
2023-12-15 09:30:55 core-matter-server chip.DIS[127] INFO UDP:192.168.107.106%enp0s3:5540: score has not improved: 2
2023-12-15 09:30:55 core-matter-server chip.DIS[127] INFO Checking node lookup status after 112 ms
2023-12-15 09:30:55 core-matter-server chip.DIS[127] INFO Keeping DNSSD lookup active
2023-12-15 09:30:55 core-matter-server chip.DIS[127] INFO Checking node lookup status after 201 ms
2023-12-15 09:30:55 core-matter-server chip.DIS[127] DEBUG OperationalSessionSetup[1:0000000000000009]: Updating device address to UDP:[fe80::4ae1:e9ff:fedb:b928%enp0s3]:5540 while in state 2
2023-12-15 09:30:55 core-matter-server chip.DIS[127] DEBUG OperationalSessionSetup[1:0000000000000009]: State change 2 --> 3
2023-12-15 09:30:55 core-matter-server chip.IN[127] DEBUG SecureSession[0x7f6d84028fe0]: Allocated Type:2 LSID:17683
2023-12-15 09:30:55 core-matter-server chip.SC[127] INFO Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000009
2023-12-15 09:30:55 core-matter-server chip.CTL[127] DEBUG StorageAdapter::GetKeyValue: Key = f/1/g, Value = 0x7f6d937fd3f0 (128)
2023-12-15 09:30:55 core-matter-server chip.CTL[127] DEBUG Key Found 23
2023-12-15 09:30:55 core-matter-server chip.CTL[127] DEBUG StorageAdapter::GetKeyValue: Key = f/1/k/0, Value = 0x7f6d937fd540 (128)
2023-12-15 09:30:55 core-matter-server chip.CTL[127] DEBUG Key Found 97
2023-12-15 09:30:55 core-matter-server chip.CTL[127] DEBUG StorageAdapter::GetKeyValue: Key = f/1/s/0000000000000009, Value = 0x7f6d937fd660 (74)
2023-12-15 09:30:55 core-matter-server chip.CTL[127] DEBUG Key Not Found
2023-12-15 09:30:55 core-matter-server chip.EM[127] INFO <<< [E:17865i S:0 M:35708457] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::4ae1:e9ff:fedb:b928%enp0s3]:5540] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
2023-12-15 09:30:55 core-matter-server chip.SC[127] INFO Sent Sigma1 msg
2023-12-15 09:30:55 core-matter-server chip.DIS[127] DEBUG OperationalSessionSetup[1:0000000000000009]: State change 3 --> 4
2023-12-15 09:30:55 core-matter-server chip.EM[127] INFO Retransmitting MessageCounter:35708457 on exchange 17865i Send Cnt 1
2023-12-15 09:30:56 core-matter-server chip.EM[127] INFO Retransmitting MessageCounter:35708457 on exchange 17865i Send Cnt 2
2023-12-15 09:30:56 core-matter-server chip.EM[127] INFO Retransmitting MessageCounter:35708457 on exchange 17865i Send Cnt 3
2023-12-15 09:30:57 core-matter-server chip.EM[127] INFO Retransmitting MessageCounter:35708457 on exchange 17865i Send Cnt 4
2023-12-15 09:30:57 core-matter-server chip.DIS[127] DEBUG SRV record already actively processed.
2023-12-15 09:30:57 core-matter-server chip.DIS[127] DEBUG SRV record already actively processed.
2023-12-15 09:30:57 core-matter-server chip.DIS[127] DEBUG SRV record already actively processed.
2023-12-15 09:30:57 core-matter-server chip.DIS[127] DEBUG SRV record already actively processed.
2023-12-15 09:30:57 core-matter-server chip.DIS[127] DEBUG SRV record already actively processed.
2023-12-15 09:30:57 core-matter-server chip.DIS[127] DEBUG SRV record already actively processed.
2023-12-15 09:30:57 core-matter-server chip.DIS[127] DEBUG SRV record already actively processed.
2023-12-15 09:30:57 core-matter-server chip.DIS[127] DEBUG SRV record already actively processed.
2023-12-15 09:30:57 core-matter-server chip.DIS[127] DEBUG SRV record already actively processed.
2023-12-15 09:30:57 core-matter-server chip.DIS[127] DEBUG SRV record already actively processed.
2023-12-15 09:30:57 core-matter-server chip.DIS[127] DEBUG SRV record already actively processed.
2023-12-15 09:30:57 core-matter-server chip.DIS[127] DEBUG SRV record already actively processed.
2023-12-15 09:30:57 core-matter-server chip.DIS[127] DEBUG SRV record already actively processed.
2023-12-15 09:30:57 core-matter-server chip.DIS[127] DEBUG SRV record already actively processed.
2023-12-15 09:30:59 core-matter-server chip.EM[127] ERROR Failed to Send CHIP MessageCounter:35708457 on exchange 17865i sendCount: 4 max retries: 4
2023-12-15 09:31:01 core-matter-server chip.SC[127] ERROR CASESession timed out while waiting for a response from the peer. Current state was 1
2023-12-15 09:31:01 core-matter-server chip.IN[127] DEBUG SecureSession[0x7f6d84028fe0]: Released - Type:2 LSID:17683
2023-12-15 09:31:01 core-matter-server chip.DIS[127] DEBUG OperationalSessionSetup[1:0000000000000009]: State change 4 --> 2
2023-12-15 09:31:01 core-matter-server chip.DIS[127] DEBUG OperationalSessionSetup[1:0000000000000009]: State change 2 --> 1
2023-12-15 09:31:01 core-matter-server chip.CTL[127] INFO Device connection failed. Error src/protocols/secure_channel/CASESession.cpp:553: CHIP Error 0x00000032: Timeout
2023-12-15 09:31:01 core-matter-server chip.CTL[127] INFO Error on commissioning step 'FindOperational': 'src/protocols/secure_channel/CASESession.cpp:553: CHIP Error 0x00000032: Timeout'
2023-12-15 09:31:01 core-matter-server chip.CTL[127] ERROR Failed to perform commissioning step 26
2023-12-15 09:31:01 core-matter-server chip.CTL[127] INFO Going from commissioning step 'FindOperational' with lastErr = 'src/protocols/secure_channel/CASESession.cpp:553: CHIP Error 0x00000032: Timeout' -> 'Cleanup'
2023-12-15 09:31:01 core-matter-server chip.CTL[127] INFO Performing next commissioning step 'Cleanup' with completion status = 'src/protocols/secure_channel/CASESession.cpp:553: CHIP Error 0x00000032: Timeout'
2023-12-15 09:31:01 core-matter-server chip.CTL[127] INFO Successfully finished commissioning step 'Cleanup'
2023-12-15 09:31:01 core-matter-server matter_server.server.client_handler[127] ERROR [140108682433296] Error handling message: CommandMessage(message_id='115839823acb4b0880cfffda165a31bb', command='commission_with_code', args={'code': 'MT:OIVJ0IV5272MTG6UP00'})
Traceback (most recent call last):
File "/usr/local/lib/python3.11/site-packages/matter_server/server/client_handler.py", line 188, in _run_handler
result = await result
^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/matter_server/server/device_controller.py", line 167, in commission_with_code
raise NodeCommissionFailed(
matter_server.common.errors.NodeCommissionFailed: Commission with code failed for node 9
Additional information
No response
About this issue
- Original URL
- State: closed
- Created 7 months ago
- Comments: 65 (10 by maintainers)
iOS will work fine, the bug only applies to Android
The Android app is going to be released soon so keep an eye on that.
I could be lying unfortunately. Things hummed along for an hour or so and then everything fell apart. I’m not sure what’s going on so I’m going to continue to poke after a break for my sanity.
I downgraded by restoring a backup at an older version, which luckily didn’t have any other changes.
That’s just it. SkyConnect and HA as border router alone was enough. I have some matter devices working already. Some recent update busted it.
Exactly the issue I’ve been having for months. I use Android. I was able to successfully add matter wifi and matter thread devices to SmartThings and from there share with HA. I almost never could add matter devices from the HA android app. Thank you for letting us know!
Are you all -by any chance- using Android to commission the device ? We have a bug/issue with the Android app currently so using that to commission devices will fail. A new Android app update will be launched as soon as possible.
For the time being, the best way to work around this, is using the iOS companion app OR if you want to use Android: Commission the device first to Google home and then share it from there to HA.
@dabedin I’m not going to respond on the shitload of people that hijacked your issue with all sorts of unrelated noise.
First of all, sorry for the delay in answering your report. I was almost 2 weeks off in the holiday season to spent some time on family instead of Matter issues 😉
I will respond to your original issue report that you are unable to commission (Wifi based) Matter devices. Did you read our documentation ?
In order to use Matter, you need a FLAT network. So no vLANS and especially no mdns repeaters. In particular the mDNS forwarder from Unifi is known to completely mess things up.
Actually you can use vLANS but then you also need to make sure that HA is on that same (IoT) vLAN, as well as the phone you are using for commisisoning as long as you make sure to keep that (Unifi) mDNS forwarder disabled at all times.
So I suggest you to flatten your network and try again. For a complete technical explanation to why we give this advise, have a look at this excellent blog post: https://www.derekseaman.com/2023/10/part-1-smart-home-matter-and-thread-deep-dive.html
Guess we wait for the next release and see. @bdraco is usually very responsive to any issues, so if there is one he will get it updated / fixed quickly. The updates to serviceinfo in 0.129.0 and 0.130.0 look significant , but only guessing if that even is related to the issues we are having.
Yup. No stranger to open source activity for the most part. Just never sure when chatting in a new repo.
Thanks!
I wonder if the bump in zeroconf with 2023.12.2 and/or 2023.12.3 has anything to do with this issue? My devices appeared to break after 2023.12.3 and I do know that zeroconf and an mDNS implication.
I tried to add a TP-Link Tapo Matter over WiFi Smart Plug last night and everything went fine until I tried to add it to Home Assistant (“commission the device” I guess?). Attached are the logs from my attempt but they look almost identical to others above. core_matter_server_2023-12-21T11-28-40.095Z.log
I will add that I attempted to commission this device primarily to HA as my Matter controller. I do not have any other Matter controllers to use at this time.
Just adding I am having the same issue. “SOMETHING WENT WRONG” right at the end of the process. I get the Creating Mater Credentials, Checking Network connectivity, but it fails at the adding to home assistant stage.
Same issue here. Also running mDNS between my IoT and HA server networks and also using UniFi AP’s for IoT network. Matter devices on IoT network added fine to Homekit but when trying to add to Home Assistant logs show same error as above.