search

project-chip / matter.js

A complete typescript implementation of the Matter protocol specification (https://buildwithmatter.com). Includes full support for controller, device, commissioning, secure communications, device types, and cluster definitions.
Apache License 2.0
328 stars 57 forks source link

Commissioning of Wifi devices broken in v10 #1106

Closed digitaldan closed 3 weeks ago

digitaldan commented 3 weeks ago

I upgraded my dependencies to v10 recently, and while everything else works fine, i can no longer commission wifi devices. The process fails on step 11 here:

https://github.com/project-chip/matter.js/blob/e6636a20d810fc9b48201248eea80691a45e8446/packages/matter.js/src/protocol/ControllerCommissioner.ts#L777-L779

If i print out on the console the values of this.collectedCommissioningData.networkFeatures I get:

{ endpointId: 0, value: { wiFiNetworkInterface: true, threadNetworkInterface: false, ethernetNetworkInterface: false } }

but the code at:

https://github.com/project-chip/matter.js/blob/e6636a20d810fc9b48201248eea80691a45e8446/packages/matter.js/src/protocol/ControllerCommissioner.ts#L773-L775

treats value as an array using some, and not an object as its structured in networkFeatures.

If i comment out the throw statement here, then commissioning works as expected.

digitaldan commented 3 weeks ago

~~FYI, i could fix this with a PR, but i'm not sure if networkFeatures has the wrong structure and it should be an array, or if its just the matching logic. Also not sure then if the other code earlier in this function also needs to be updated (where using some) since i have a very limited set of devices i'm testing with right now. ~~

digitaldan commented 3 weeks ago

Sorry, i totally confused myself and referenced the wrong line 🫤 , its actually here

https://github.com/project-chip/matter.js/blob/e6636a20d810fc9b48201248eea80691a45e8446/packages/matter.js/src/protocol/ControllerCommissioner.ts#L769

And it looks like its not checking for a wifi interface, just ethernet.....

Edit: Sorry, now i'm just rambling..... just kinda now going through the rest of the code. I guess this logic is assuming that the commissioner is suppose to supply wifi credentials if its a wifi device, and since i'm not doing that its failing ? In this case the device already has a wifi connection setup (its a Levition Wifi v2 matter dimmer), so i'm not sure what the right logic should be, maybe if there is no wifi credentials as part of the commissioning process, but wifi is enabled, continue ... ?

Apollon77 commented 3 weeks ago

Can you please post a full debug log of a commission on one try?

As you can see in the code you linked in your last post it checks if there is Ethernet or any connected connection and when this is the case all is good. And the exception would never throw. So this would mean that the device presents WiFi but not connected and so this is then a problem because it needs to commission one.

I would like to verify the reason here before we do changes.

digitaldan commented 3 weeks ago

Sure, i'll post the whole log here in a few mins.

Question, since the networkFeatures object looks like:

{ endpointId: 0, value: { wiFiNetworkInterface: true, threadNetworkInterface: false, ethernetNetworkInterface: false } }

If the code passes if ethernetNetworkInterface is true, curious why it would not check wiFiNetworkInterface as well? Again, just curious and trying to understand this part of the code. Thanks!

Apollon77 commented 3 weeks ago

Which if you mean? In fact it check two things and saves them as booleans. Then only one if is there.

In fact when thinking we can add for sure if commissioning happens via UDP then in fact there us a connection irrelevant what the clusters say. But would be cool to know what's up here.

digitaldan commented 3 weeks ago

Hopefully this output helps?

Which if you mean? In fact it check two things and saves them as booleans. Then only one if is there.

I guess i don't understand why the check just for ethernetNetworkInterface but not wiFiNetworkInterface , why they are treated differently, but i'm sure there's a good reason. I'm assuming ethernetNetworkInterface is literally a hardwire ethernet connection in this context vs wifi or thread? I would also assume networkStatus to contain something connected as well, but does not seem to be the case. Thanks again.

https://github.com/project-chip/matter.js/blob/e6636a20d810fc9b48201248eea80691a45e8446/packages/matter.js/src/protocol/ControllerCommissioner.ts#L766-L779

matter: Executing function nodes.pair(["24976042936"])
{"discovery":{"knownAddress":"undefined","identifierData":{"shortDiscriminator":11},"discoveryCapabilities":{"ble":false,"onIpNetwork":true}},"passcode":70337120,"commissioning":{"nodeId":"undefined","regulatoryLocation":1,"regulatoryCountryCode":"XX"}}
MatterController: Commissioning device with identifier {"shortDiscriminator":11} and 1 scanners and knownAddress "undefined"
ControllerDiscovery: Start Discovering devices using identifier {"shortDiscriminator":11} ...
ControllerDiscovery: Found 2 devices using identifier {"shortDiscriminator":11}
ControllerDiscovery: Server addresses to try: undefined: udp://fe80::207:a6ff:fe35:44d6%eth0:5540,undefined: udp://2600:8801:df00:160:207:a6ff:fe35:44d6:5540
ControllerDiscovery: Try to communicate with udp://fe80::207:a6ff:fe35:44d6%eth0:5540 ...
MatterController: Commissioning device SII: 5000 SAI: 300 SAT: undefined T: 0 DT: 257 PH: 33 ICD: 0 VP: 4251+4096 DN: undefined RI: 02000C670797D879E09D0EF38980F203EF12 PI:
MessageExchange: New exchange channel: udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session insecure/7604773502132312124 protocol: 0 id: 48945 session: insecure/7604773502132312124 peerSessionId: 0 active threshold ms: 4000 active interval ms: 300 idle interval ms: 5000 maxTransmissions: 5 useMrp: true
ExchangeManager: Message » id: 0/48945/188597334 type: 0/32 acked: undefined reqAck: true duplicate: false payload: 15300120ecd3d0f355d868eb0615228dbcc466e58237736d6b51e3a2fbb8f1f21ddeb60d25020894240300280435052501f40125022c012503a00f24041124050c26060000030124070a1818
MessageExchange: Message « id: 0/48945/174771881 type: 0/16 acked: 188597334 reqAck: false duplicate: false payload:
MessageExchange: Message « id: 0/48945/174771882 type: 0/33 acked: 188597334 reqAck: true duplicate: false payload: 15300120ecd3d0f355d868eb0615228dbcc466e58237736d6b51e3a2fbb8f1f21ddeb60d3002206cc7866873b058b2f55547cb2540f8cb1f97fe2d1c42fd6fd3eaeb91f9b2c6bd25032fa0350425018b27300220aaf1312f232fe5937c56ccd29cbcf3b2a9a3dc131ac5dca6ac3c91351fd55bc81835052501881325022c011818
ExchangeManager: Message » id: 0/48945/188597335 type: 0/34 acked: 174771882 reqAck: true duplicate: false payload: 1530014104987313c286baee171122aa806a07c707ef4332da9e4998938a8c1d840df739fdd740197fa8822ace4ef81755139eac13543d61c25234af87da8d138eb3ccd29418
MessageExchange: Message « id: 0/48945/174771883 type: 0/16 acked: 188597335 reqAck: false duplicate: false payload:
MessageExchange: Message « id: 0/48945/174771884 type: 0/35 acked: 188597335 reqAck: true duplicate: false payload: 1530014104bbe6cc612a643a014c35cd14ab6bcba60aa0637275dcf59fbb0da152eff154adf4996b8dc974e4f29b58cc90fa8573116573c633187123a6ccfb462f5cfb47003002203e70756b38ac7eba9a3013beb74c96a6b3cdda715d666de1bbbb9e05875d669d18
ExchangeManager: Message » id: 0/48945/188597336 type: 0/36 acked: 174771884 reqAck: true duplicate: false payload: 153001206f95732d897089a5660b32e97d8437734ef25e024b9455efe97334d92ff9468c18
MessageExchange: Message « id: 0/48945/174771885 type: 0/16 acked: 188597336 reqAck: false duplicate: false payload:
MessageExchange: Message « id: 0/48945/174771886 type: 0/64 acked: 188597336 reqAck: true duplicate: false payload: 0000000000000000
SecureSession: Created secure PASE session for fabric index undefined secure/37896 idleIntervalMs: 5000 activeIntervalMs: 300 activeThresholdMs: 4000 dataModelRevision: 17 interactionModelRevision: 11 specificationVersion: 0 maxPathsPerInvoke: 1
ExchangeManager: Message » id: 0/48945/188597337 type: 0/16 acked: 174771886 reqAck: false duplicate: false payload:
PaseClient: Pase client: Paired successfully with udp://fe80::207:a6ff:fe35:44d6%eth0:5540.
SessionManager: End insecure session insecure/7604773502132312124
Controller~missioner: Commissioning options: {"nodeId":"undefined","regulatoryLocation":1,"regulatoryCountryCode":"XX"}
Controller~missioner: Executing commissioning step 0.1: GetInitialData
Controller~missioner: Creating new cluster client for cluster Descriptor (endpoint 0, isFeatureSpecific false)
MessageExchange: New exchange channel: udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 protocol: 1 id: 48946 session: secure/37896 peerSessionId: 41007 active threshold ms: 4000 active interval ms: 300 idle interval ms: 5000 maxTransmissions: 5 useMrp: true
InteractionClient: Sending read request to udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 for attributes 0x0/Descriptor(0x1d)/partsList(0x3) and events undefined
ExchangeManager: Message » id: 41007/48946/22333820 type: 1/2 acked: undefined reqAck: true duplicate: false payload: 1536001724020024031d2404031818290324ff0c18
MessageExchange: Message « id: 37896/48946/235835006 type: 1/5 acked: 22333820 reqAck: true duplicate: false payload: 1536011535012600a5b58bc4370124020024031d2404031836021818181535012600a5b58bc4370124020024031d240403340518240201181818290424ff0118
InteractionMessenger: Received DataReport chunk with 2 attributes and 0 events, suppressResponse: true, moreChunkedMessages: undefined
InteractionClient: Received read response with attributes 0x0/Descriptor(0x1d)/partsList(0x3) = [1] and events
ExchangeManager: Message » id: 41007/48946/22333821 type: 0/16 acked: 235835006 reqAck: false duplicate: false payload:
MessageExchange: New exchange channel: udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 protocol: 1 id: 48947 session: secure/37896 peerSessionId: 41007 active threshold ms: 4000 active interval ms: 300 idle interval ms: 5000 maxTransmissions: 5 useMrp: true
InteractionClient: Sending read request to udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 for attributes 0x0/Descriptor(0x1d)/serverList(0x1) and events undefined
ExchangeManager: Message » id: 41007/48947/22333822 type: 1/2 acked: undefined reqAck: true duplicate: false payload: 1536001724020024031d2404011818290324ff0c18
MessageExchange: Message « id: 37896/48947/235835007 type: 1/5 acked: 22333822 reqAck: true duplicate: false payload: 1536011535012600a5b58bc4370124020024031d2404011836021818181535012600a5b58bc4370124020024031d24040134051824021d18181535012600a5b58bc4370124020024031d24040134051824021f18181535012600a5b58bc4370124020024031d24040134051824022818181535012600a5b58bc4370124020024031d24040134051824022a18181535012600a5b58bc4370124020024031d24040134051824022b18181535012600a5b58bc4370124020024031d24040134051824022c18181535012600a5b58bc4370124020024031d24040134051824023018181535012600a5b58bc4370124020024031d24040134051824023118181535012600a5b58bc4370124020024031d24040134051824023218181535012600a5b58bc4370124020024031d24040134051824023318181535012600a5b58bc4370124020024031d24040134051824023418181535012600a5b58bc4370124020024031d24040134051824023618181535012600a5b58bc4370124020024031d24040134051824023c18181535012600a5b58bc4370124020024031d24040134051824023e18181535012600a5b58bc4370124020024031d24040134051824023f181818290424ff0118
InteractionMessenger: Received DataReport chunk with 16 attributes and 0 events, suppressResponse: true, moreChunkedMessages: undefined
InteractionClient: Received read response with attributes 0x0/Descriptor(0x1d)/serverList(0x1) = [29,31,40,42,43,44,48,49,50,51,52,54,60,62,63] and events
ExchangeManager: Message » id: 41007/48947/22333823 type: 0/16 acked: 235835007 reqAck: false duplicate: false payload:
MessageExchange: New exchange channel: udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 protocol: 1 id: 48948 session: secure/37896 peerSessionId: 41007 active threshold ms: 4000 active interval ms: 300 idle interval ms: 5000 maxTransmissions: 5 useMrp: true
InteractionClient: Sending read request to udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 for attributes */NetworkCommissioning(0x31)/0xfffc, */NetworkCommissioning(0x31)/0x1 and events undefined
ExchangeManager: Message » id: 41007/48948/22333824 type: 1/2 acked: undefined reqAck: true duplicate: false payload: 153600172403312504fcff18172403312404011818290324ff0c18
MessageExchange: Message « id: 37896/48948/235835008 type: 1/5 acked: 22333824 reqAck: true duplicate: false payload: 15360115350126001cfc11c5370124020024033124040118360218181815350126001cfc11c537012402002403312504fcff18240201181818290424ff0118
InteractionMessenger: Received DataReport chunk with 2 attributes and 0 events, suppressResponse: true, moreChunkedMessages: undefined
InteractionClient: Received read response with attributes 0x0/NetworkCommissioning(0x31)/networks(0x1) = [], 0x0/NetworkCommissioning(0x31)/featureMap(0xfffc) = {"wiFiNetworkInterface":true,"threadNetworkInterface":false,"ethernetNetworkInterface":false} and events
ExchangeManager: Message » id: 41007/48948/22333825 type: 0/16 acked: 235835008 reqAck: false duplicate: false payload:
Controller~missioner: Creating new cluster client for cluster BasicInformation (endpoint 0, isFeatureSpecific false)
MessageExchange: New exchange channel: udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 protocol: 1 id: 48949 session: secure/37896 peerSessionId: 41007 active threshold ms: 4000 active interval ms: 300 idle interval ms: 5000 maxTransmissions: 5 useMrp: true
InteractionClient: Sending read request to udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 for attributes 0x0/BasicInformation(0x28)/vendorId(0x2) and events undefined
ExchangeManager: Message » id: 41007/48949/22333826 type: 1/2 acked: undefined reqAck: true duplicate: false payload: 153600172402002403282404021818290324ff0c18
MessageExchange: Message « id: 37896/48949/235835009 type: 1/5 acked: 22333826 reqAck: true duplicate: false payload: 153601153501260017e683ae37012402002403282404021825029b10181818290424ff0118
InteractionMessenger: Received DataReport chunk with 1 attributes and 0 events, suppressResponse: true, moreChunkedMessages: undefined
InteractionClient: Received read response with attributes 0x0/BasicInformation(0x28)/vendorId(0x2) = 4251 and events
ExchangeManager: Message » id: 41007/48949/22333827 type: 0/16 acked: 235835009 reqAck: false duplicate: false payload:
MessageExchange: New exchange channel: udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 protocol: 1 id: 48950 session: secure/37896 peerSessionId: 41007 active threshold ms: 4000 active interval ms: 300 idle interval ms: 5000 maxTransmissions: 5 useMrp: true
InteractionClient: Sending read request to udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 for attributes 0x0/BasicInformation(0x28)/productId(0x4) and events undefined
ExchangeManager: Message » id: 41007/48950/22333828 type: 1/2 acked: undefined reqAck: true duplicate: false payload: 153600172402002403282404041818290324ff0c18
MessageExchange: Message « id: 37896/48950/235835010 type: 1/5 acked: 22333828 reqAck: true duplicate: false payload: 153601153501260017e683ae37012402002403282404041825020010181818290424ff0118
InteractionMessenger: Received DataReport chunk with 1 attributes and 0 events, suppressResponse: true, moreChunkedMessages: undefined
InteractionClient: Received read response with attributes 0x0/BasicInformation(0x28)/productId(0x4) = 4096 and events
ExchangeManager: Message » id: 41007/48950/22333829 type: 0/16 acked: 235835010 reqAck: false duplicate: false payload:
MessageExchange: New exchange channel: udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 protocol: 1 id: 48951 session: secure/37896 peerSessionId: 41007 active threshold ms: 4000 active interval ms: 300 idle interval ms: 5000 maxTransmissions: 5 useMrp: true
InteractionClient: Sending read request to udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 for attributes 0x0/BasicInformation(0x28)/productName(0x3) and events undefined
ExchangeManager: Message » id: 41007/48951/22333830 type: 1/2 acked: undefined reqAck: true duplicate: false payload: 153600172402002403282404031818290324ff0c18
MessageExchange: Message « id: 37896/48951/235835011 type: 1/5 acked: 22333830 reqAck: true duplicate: false payload: 153601153501260017e683ae3701240200240328240403182c02054432364844181818290424ff0118
InteractionMessenger: Received DataReport chunk with 1 attributes and 0 events, suppressResponse: true, moreChunkedMessages: undefined
InteractionClient: Received read response with attributes 0x0/BasicInformation(0x28)/productName(0x3) = "D26HD" and events
ExchangeManager: Message » id: 41007/48951/22333831 type: 0/16 acked: 235835011 reqAck: false duplicate: false payload:
Controller~missioner: Creating new cluster client for cluster GeneralCommissioning (endpoint 0, isFeatureSpecific false)
MessageExchange: New exchange channel: udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 protocol: 1 id: 48952 session: secure/37896 peerSessionId: 41007 active threshold ms: 4000 active interval ms: 300 idle interval ms: 5000 maxTransmissions: 5 useMrp: true
InteractionClient: Sending read request to udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 for attributes 0x0/GeneralCommissioning(0x30)/supportsConcurrentConnection(0x4) and events undefined
ExchangeManager: Message » id: 41007/48952/22333832 type: 1/2 acked: undefined reqAck: true duplicate: false payload: 153600172402002403302404041818290324ff0c18
MessageExchange: Message « id: 37896/48952/235835012 type: 1/5 acked: 22333832 reqAck: true duplicate: false payload: 15360115350126009b965c283701240200240330240404182902181818290424ff0118
InteractionMessenger: Received DataReport chunk with 1 attributes and 0 events, suppressResponse: true, moreChunkedMessages: undefined
InteractionClient: Received read response with attributes 0x0/GeneralCommissioning(0x30)/supportsConcurrentConnection(0x4) = true and events
ExchangeManager: Message » id: 41007/48952/22333833 type: 0/16 acked: 235835012 reqAck: false duplicate: false payload:
Controller~missioner: Executing commissioning step 3.1: GeneralCommissioning.ArmFailsafe
Controller~missioner: Returning existing cluster client for cluster GeneralCommissioning (endpoint 0, isFeatureSpecific false)
MessageExchange: New exchange channel: udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 protocol: 1 id: 48953 session: secure/37896 peerSessionId: 41007 active threshold ms: 4000 active interval ms: 300 idle interval ms: 5000 maxTransmissions: 5 useMrp: true
InteractionClient: Sending read request to udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 for attributes 0x0/GeneralCommissioning(0x30)/basicCommissioningInfo(0x1) and events undefined
ExchangeManager: Message » id: 41007/48953/22333834 type: 1/2 acked: undefined reqAck: true duplicate: false payload: 153600172402002403302404011818290324ff0c18
MessageExchange: Message « id: 37896/48953/235835013 type: 1/5 acked: 22333834 reqAck: true duplicate: false payload: 15360115350126009b965c28370124020024033024040118350224003c2501840318181818290424ff0118
InteractionMessenger: Received DataReport chunk with 1 attributes and 0 events, suppressResponse: true, moreChunkedMessages: undefined
InteractionClient: Received read response with attributes 0x0/GeneralCommissioning(0x30)/basicCommissioningInfo(0x1) = {"failSafeExpiryLengthSeconds":60,"maxCumulativeFailsafeSeconds":900} and events
ExchangeManager: Message » id: 41007/48953/22333835 type: 0/16 acked: 235835013 reqAck: false duplicate: false payload:
MessageExchange: New exchange channel: udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 protocol: 1 id: 48954 session: secure/37896 peerSessionId: 41007 active threshold ms: 4000 active interval ms: 300 idle interval ms: 5000 maxTransmissions: 5 useMrp: true
InteractionClient: Invoking command: 0x0/GeneralCommissioning(0x30)/armFailSafe(0x0) with {"breadcrumb":1,"expiryLengthSeconds":60}
ExchangeManager: Message » id: 41007/48954/22333836 type: 1/8 acked: undefined reqAck: true duplicate: false payload: 1528002801360215370024000024013024020018350124003c24010118181824ff0c18
MessageExchange: Message « id: 37896/48954/235835014 type: 1/9 acked: 22333836 reqAck: true duplicate: false payload: 152800360115350037002400002401302402011835012400002c01001818181824ff0118
InteractionClient: Received invoke response: 0x0/GeneralCommissioning(0x30)/armFailSafe(0x0) with {"errorCode":0,"debugText":""})}
ExchangeManager: Message » id: 41007/48954/22333837 type: 0/16 acked: 235835014 reqAck: false duplicate: false payload:
Controller~missioner: Commissioning step armFailSafe returned 0,
Controller~missioner: Executing commissioning step 5.1: GeneralCommissioning.ConfigureRegulatoryInformation
Controller~missioner: Returning existing cluster client for cluster GeneralCommissioning (endpoint 0, isFeatureSpecific false)
MessageExchange: New exchange channel: udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 protocol: 1 id: 48955 session: secure/37896 peerSessionId: 41007 active threshold ms: 4000 active interval ms: 300 idle interval ms: 5000 maxTransmissions: 5 useMrp: true
InteractionClient: Sending read request to udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 for attributes 0x0/GeneralCommissioning(0x30)/locationCapability(0x3) and events undefined
ExchangeManager: Message » id: 41007/48955/22333838 type: 1/2 acked: undefined reqAck: true duplicate: false payload: 153600172402002403302404031818290324ff0c18
MessageExchange: Message « id: 37896/48955/235835015 type: 1/5 acked: 22333838 reqAck: true duplicate: false payload: 15360115350126009c965c28370124020024033024040318240200181818290424ff0118
InteractionMessenger: Received DataReport chunk with 1 attributes and 0 events, suppressResponse: true, moreChunkedMessages: undefined
InteractionClient: Received read response with attributes 0x0/GeneralCommissioning(0x30)/locationCapability(0x3) = 0 and events
ExchangeManager: Message » id: 41007/48955/22333839 type: 0/16 acked: 235835015 reqAck: false duplicate: false payload:
Controller~missioner: Device does not support a configurable regulatory location type. Location is set to "Indoor"
MessageExchange: New exchange channel: udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 protocol: 1 id: 48956 session: secure/37896 peerSessionId: 41007 active threshold ms: 4000 active interval ms: 300 idle interval ms: 5000 maxTransmissions: 5 useMrp: true
InteractionClient: Invoking command: 0x0/GeneralCommissioning(0x30)/setRegulatoryConfig(0x2) with {"breadcrumb":1,"newRegulatoryConfig":0,"countryCode":"XX"}
ExchangeManager: Message » id: 41007/48956/22333840 type: 1/8 acked: undefined reqAck: true duplicate: false payload: 152800280136021537002400002401302402021835012400002c0102585824020118181824ff0c18
MessageExchange: Message « id: 37896/48956/235835016 type: 1/9 acked: 22333840 reqAck: true duplicate: false payload: 152800360115350037002400002401302402031835012400002c01001818181824ff0118
InteractionClient: Received invoke response: 0x0/GeneralCommissioning(0x30)/setRegulatoryConfig(0x2) with {"errorCode":0,"debugText":""})}
ExchangeManager: Message » id: 41007/48956/22333841 type: 0/16 acked: 235835016 reqAck: false duplicate: false payload:
Controller~missioner: Commissioning step setRegulatoryConfig returned 0,
Controller~missioner: Executing commissioning step 5.2: TimeSynchronization.SynchronizeTime
Controller~missioner: Executing commissioning step 6.1: OperationalCredentials.DeviceAttestation
Controller~missioner: Creating new cluster client for cluster OperationalCredentials (endpoint 0, isFeatureSpecific false)
MessageExchange: New exchange channel: udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 protocol: 1 id: 48957 session: secure/37896 peerSessionId: 41007 active threshold ms: 4000 active interval ms: 300 idle interval ms: 5000 maxTransmissions: 5 useMrp: true
InteractionClient: Invoking command: 0x0/OperationalCredentials(0x3e)/certificateChainRequest(0x2) with {"certificateType":1}
ExchangeManager: Message » id: 41007/48957/22333842 type: 1/8 acked: undefined reqAck: true duplicate: false payload: 1528002801360215370024000024013e24020218350124000118181824ff0c18
MessageExchange: Message « id: 37896/48957/235835017 type: 1/9 acked: 22333842 reqAck: true duplicate: false payload: 1528003601153500370024000024013e2402031835013100ea01308201e63082018da003020102020828f02c706cb94bc6300a06082a8648ce3d0403023048311a301806035504030c114c657669746f6e2044323648442050414931143012060a2b0601040182a27c02010c043130394231143012060a2b0601040182a27c02020c04313030303020170d3231303632383134323334335a180f39393939313233313233353935395a30473119301706035504030c104d61747465722054657374204441432031143012060a2b0601040182a27c02010c043130394231143012060a2b0601040182a27c02020c04313030303059301306072a8648ce3d020106082a8648ce3d03010703420004c75c01dc02c0f60d9a49bb0c757079f153a50db3ce0000eddf34033d28683cfc682031a6fe77475c401a0f4ac94e3cb54dadb68cb459891fb379dcd473298892a360305e300c0603551d130101ff04023000300e0603551d0f0101ff040403020780301d0603551d0e04160414cf39c493ff69d0b0a0fb5fc94f2b2587c433a4e8301f0603551d230418301680142fbb79f88f01449e0ffc25a0c5a8e4ef6f3f2b5f300a06082a8648ce3d040302034700304402205b6375539f0b186cb92d0b7df141440c2a07d9a65006e915f2a20f09e4fed78b02201ce21a13bc0cdaadf177050b04246ab2badff453059027abc50e7c3c0e03fd171818181824ff0118
InteractionClient: Received invoke response: 0x0/OperationalCredentials(0x3e)/certificateChainRequest(0x2) with {"certificate":"308201e63082018da003020102020828f02c706cb94bc6300a06082a8648ce3d0403023048311a301806035504030c114c657669746f6e2044323648442050414931143012060a2b0601040182a27c02010c043130394231143012060a2b0601040182a27c02020c04313030303020170d3231303632383134323334335a180f39393939313233313233353935395a30473119301706035504030c104d61747465722054657374204441432031143012060a2b0601040182a27c02010c043130394231143012060a2b0601040182a27c02020c04313030303059301306072a8648ce3d020106082a8648ce3d03010703420004c75c01dc02c0f60d9a49bb0c757079f153a50db3ce0000eddf34033d28683cfc682031a6fe77475c401a0f4ac94e3cb54dadb68cb459891fb379dcd473298892a360305e300c0603551d130101ff04023000300e0603551d0f0101ff040403020780301d0603551d0e04160414cf39c493ff69d0b0a0fb5fc94f2b2587c433a4e8301f0603551d230418301680142fbb79f88f01449e0ffc25a0c5a8e4ef6f3f2b5f300a06082a8648ce3d040302034700304402205b6375539f0b186cb92d0b7df141440c2a07d9a65006e915f2a20f09e4fed78b02201ce21a13bc0cdaadf177050b04246ab2badff453059027abc50e7c3c0e03fd17"})}
ExchangeManager: Message » id: 41007/48957/22333843 type: 0/16 acked: 235835017 reqAck: false duplicate: false payload:
MessageExchange: New exchange channel: udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 protocol: 1 id: 48958 session: secure/37896 peerSessionId: 41007 active threshold ms: 4000 active interval ms: 300 idle interval ms: 5000 maxTransmissions: 5 useMrp: true
InteractionClient: Invoking command: 0x0/OperationalCredentials(0x3e)/certificateChainRequest(0x2) with {"certificateType":2}
ExchangeManager: Message » id: 41007/48958/22333844 type: 1/8 acked: undefined reqAck: true duplicate: false payload: 1528002801360215370024000024013e24020218350124000218181824ff0c18
MessageExchange: Message « id: 37896/48958/235835018 type: 1/9 acked: 22333844 reqAck: true duplicate: false payload: 1528003601153500370024000024013e2402031835013100d601308201d230820178a0030201020208304de9c239e222f9300a06082a8648ce3d040302302c3114301206035504030c0b4c657669746f6e2050414131143012060a2b0601040182a27c02010c04313039423020170d3231303632383134323334335a180f39393939313233313233353935395a3048311a301806035504030c114c657669746f6e2044323648442050414931143012060a2b0601040182a27c02010c043130394231143012060a2b0601040182a27c02020c04313030303059301306072a8648ce3d020106082a8648ce3d03010703420004a85a0884b7b6b39de615d648f3b8b7237eda6dad4b69e22fb920bc54bf3124a70da247b5ba3369bf746bb0aa5a8f4560a6d67059c81aee670ae531b77cfcb378a366306430120603551d130101ff040830060101ff020100300e0603551d0f0101ff040403020106301d0603551d0e041604142fbb79f88f01449e0ffc25a0c5a8e4ef6f3f2b5f301f0603551d230418301680148e95b1c0b6105193db41b66bef434e2c38a27a67300a06082a8648ce3d040302034800304502207eef7903ddb90379dfec0665be9e966aed058839ac6232edca75b016084019ab022100fc3e427e6cfbe254f824d08ecf589080d40bffe87fcb8794d4ab224af639d8b01818181824ff0118
InteractionClient: Received invoke response: 0x0/OperationalCredentials(0x3e)/certificateChainRequest(0x2) with {"certificate":"308201d230820178a0030201020208304de9c239e222f9300a06082a8648ce3d040302302c3114301206035504030c0b4c657669746f6e2050414131143012060a2b0601040182a27c02010c04313039423020170d3231303632383134323334335a180f39393939313233313233353935395a3048311a301806035504030c114c657669746f6e2044323648442050414931143012060a2b0601040182a27c02010c043130394231143012060a2b0601040182a27c02020c04313030303059301306072a8648ce3d020106082a8648ce3d03010703420004a85a0884b7b6b39de615d648f3b8b7237eda6dad4b69e22fb920bc54bf3124a70da247b5ba3369bf746bb0aa5a8f4560a6d67059c81aee670ae531b77cfcb378a366306430120603551d130101ff040830060101ff020100300e0603551d0f0101ff040403020106301d0603551d0e041604142fbb79f88f01449e0ffc25a0c5a8e4ef6f3f2b5f301f0603551d230418301680148e95b1c0b6105193db41b66bef434e2c38a27a67300a06082a8648ce3d040302034800304502207eef7903ddb90379dfec0665be9e966aed058839ac6232edca75b016084019ab022100fc3e427e6cfbe254f824d08ecf589080d40bffe87fcb8794d4ab224af639d8b0"})}
ExchangeManager: Message » id: 41007/48958/22333845 type: 0/16 acked: 235835018 reqAck: false duplicate: false payload:
MessageExchange: New exchange channel: udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 protocol: 1 id: 48959 session: secure/37896 peerSessionId: 41007 active threshold ms: 4000 active interval ms: 300 idle interval ms: 5000 maxTransmissions: 5 useMrp: true
InteractionClient: Invoking command: 0x0/OperationalCredentials(0x3e)/attestationRequest(0x0) with {"attestationNonce":"a0227dd889ddf5aa7b8de1e4b81a113b360238397c972f18e25fc0e00bdf4ad0"}
ExchangeManager: Message » id: 41007/48959/22333846 type: 1/8 acked: undefined reqAck: true duplicate: false payload: 1528002801360215370024000024013e240200183501300020a0227dd889ddf5aa7b8de1e4b81a113b360238397c972f18e25fc0e00bdf4ad018181824ff0c18
MessageExchange: Message « id: 37896/48959/235835019 type: 0/16 acked: 22333846 reqAck: false duplicate: false payload:
MessageExchange: Message « id: 37896/48959/235835020 type: 1/9 acked: 22333846 reqAck: true duplicate: false payload: 1528003601153500370024000024013e24020118350131001501153001ea3081e706092a864886f70d010702a081d93081d6020103310d300b0609608648016503040201304406092a864886f70d010701a03704351524000125019b10360205001018250301012c041343534132333137374d415434303639302d323424050024060024070124080218317c307a0201038014471035e7c04eaaa8be7c4d4c13e3e4c20995a84b300b0609608648016503040201300a06082a8648ce3d04030204463044022001c8fc4495da5df90b342d3c5273c8e649f54d918ce557a76654d1e7b73d2c3702201f738a3ae9f5f11cc2eacf2abd3922a4c7d29c9ac965ddb450ede575c400c9ab300220a0227dd889ddf5aa7b8de1e4b81a113b360238397c972f18e25fc0e00bdf4ad024030018300140aa53ee345d74a7de4370a16e95a879d36d60bf01c4c555ed7562e8091cde1b38b8b43ab100c239e0d5c98d1db012e276222de7e31ba120f0f6deee0ef368651a1818181824ff0118
InteractionClient: Received invoke response: 0x0/OperationalCredentials(0x3e)/attestationRequest(0x0) with {"attestationElements":"153001ea3081e706092a864886f70d010702a081d93081d6020103310d300b0609608648016503040201304406092a864886f70d010701a03704351524000125019b10360205001018250301012c041343534132333137374d415434303639302d323424050024060024070124080218317c307a0201038014471035e7c04eaaa8be7c4d4c13e3e4c20995a84b300b0609608648016503040201300a06082a8648ce3d04030204463044022001c8fc4495da5df90b342d3c5273c8e649f54d918ce557a76654d1e7b73d2c3702201f738a3ae9f5f11cc2eacf2abd3922a4c7d29c9ac965ddb450ede575c400c9ab300220a0227dd889ddf5aa7b8de1e4b81a113b360238397c972f18e25fc0e00bdf4ad024030018","attestationSignature":"aa53ee345d74a7de4370a16e95a879d36d60bf01c4c555ed7562e8091cde1b38b8b43ab100c239e0d5c98d1db012e276222de7e31ba120f0f6deee0ef368651a"})}
ExchangeManager: Message » id: 41007/48959/22333847 type: 0/16 acked: 235835020 reqAck: false duplicate: false payload:
Controller~missioner: Executing commissioning step 7.1: OperationalCredentials.Certificates
Controller~missioner: Returning existing cluster client for cluster OperationalCredentials (endpoint 0, isFeatureSpecific false)
MessageExchange: New exchange channel: udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 protocol: 1 id: 48960 session: secure/37896 peerSessionId: 41007 active threshold ms: 4000 active interval ms: 300 idle interval ms: 5000 maxTransmissions: 5 useMrp: true
InteractionClient: Invoking command: 0x0/OperationalCredentials(0x3e)/csrRequest(0x4) with {"csrNonce":"5168a74ecf33edae47ec60e22f68fe75f281f4e6e554506dc5ab814ce14758bc"}
ExchangeManager: Message » id: 41007/48960/22333848 type: 1/8 acked: undefined reqAck: true duplicate: false payload: 1528002801360215370024000024013e2402041835013000205168a74ecf33edae47ec60e22f68fe75f281f4e6e554506dc5ab814ce14758bc18181824ff0c18
MessageExchange: Message « id: 37896/48960/235835021 type: 0/16 acked: 22333848 reqAck: false duplicate: false payload:
MessageExchange: Message « id: 37896/48960/235835022 type: 1/9 acked: 22333848 reqAck: true duplicate: false payload: 1528003601153500370024000024013e2402051835013000f5153001cd3081ca3070020100300e310c300a060355040a0c034353523059301306072a8648ce3d020106082a8648ce3d03010703420004614645438c4dc4c5a8de5186e0227acc980ba966553877e710a2622cf74b1699d0cb6dc27f84c3080c2c1d6aeffd85ede3c2f1eaea54882068a3af1a67dbae63a000300c06082a8648ce3d04030205000348003045022030ef651518f0069a5d503973710b22d921e4c77a2784daafbeda425da42f73b1022100afbc9fab2d06c68d76ad3b7e54f17b82f34dc600d414a8007e62099e6635dd363002205168a74ecf33edae47ec60e22f68fe75f281f4e6e554506dc5ab814ce14758bc18300140a39ee2101d97cb594fe0137fb4defcaa88585c13cf9e61054e0b39faa547e8b8bacd1bbc6ee0aa3a512b6f30498b8add9f61c710f168335ab364172c1e649cb51818181824ff0118
InteractionClient: Received invoke response: 0x0/OperationalCredentials(0x3e)/csrRequest(0x4) with {"nocsrElements":"153001cd3081ca3070020100300e310c300a060355040a0c034353523059301306072a8648ce3d020106082a8648ce3d03010703420004614645438c4dc4c5a8de5186e0227acc980ba966553877e710a2622cf74b1699d0cb6dc27f84c3080c2c1d6aeffd85ede3c2f1eaea54882068a3af1a67dbae63a000300c06082a8648ce3d04030205000348003045022030ef651518f0069a5d503973710b22d921e4c77a2784daafbeda425da42f73b1022100afbc9fab2d06c68d76ad3b7e54f17b82f34dc600d414a8007e62099e6635dd363002205168a74ecf33edae47ec60e22f68fe75f281f4e6e554506dc5ab814ce14758bc18","attestationSignature":"a39ee2101d97cb594fe0137fb4defcaa88585c13cf9e61054e0b39faa547e8b8bacd1bbc6ee0aa3a512b6f30498b8add9f61c710f168335ab364172c1e649cb5"})}
ExchangeManager: Message » id: 41007/48960/22333849 type: 0/16 acked: 235835022 reqAck: false duplicate: false payload:
MessageExchange: New exchange channel: udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 protocol: 1 id: 48961 session: secure/37896 peerSessionId: 41007 active threshold ms: 4000 active interval ms: 300 idle interval ms: 5000 maxTransmissions: 5 useMrp: true
InteractionClient: Invoking command: 0x0/OperationalCredentials(0x3e)/addTrustedRootCertificate(0xb) with {"rootCaCertificate":"1530010100240201370324140018260483be4e2c260503f5fb403706241400182407012408013009410479d547edded4a75b4cde6c316a6e8f0baf065e683a0c805ba6e8b7b0771f96fa7c60759e557f8112c7cbb9178251b618eaec181d7c0962c995ba2fd5a58e2002370a3501290118240260300414e495b8fd782e5b14131ce0eb262e7e3934113775300514e495b8fd782e5b14131ce0eb262e7e393411377518300b401f8043dfc662bd21f5e09332a3959677ee1e19c0a190fab56de5397cc3ee1461f92e7433a574400b1f152bbbf20d783492f7a56e7acc2be1f6574d0c8bc4fd2218"}
ExchangeManager: Message » id: 41007/48961/22333850 type: 1/8 acked: undefined reqAck: true duplicate: false payload: 1528002801360215370024000024013e24020b1835013000e71530010100240201370324140018260483be4e2c260503f5fb403706241400182407012408013009410479d547edded4a75b4cde6c316a6e8f0baf065e683a0c805ba6e8b7b0771f96fa7c60759e557f8112c7cbb9178251b618eaec181d7c0962c995ba2fd5a58e2002370a3501290118240260300414e495b8fd782e5b14131ce0eb262e7e3934113775300514e495b8fd782e5b14131ce0eb262e7e393411377518300b401f8043dfc662bd21f5e09332a3959677ee1e19c0a190fab56de5397cc3ee1461f92e7433a574400b1f152bbbf20d783492f7a56e7acc2be1f6574d0c8bc4fd221818181824ff0c18
MessageExchange: Message « id: 37896/48961/235835023 type: 0/16 acked: 22333850 reqAck: false duplicate: false payload:
MessageExchange: Message « id: 37896/48961/235835024 type: 1/9 acked: 22333850 reqAck: true duplicate: false payload: 1528003601153501370024000024013e24020b1835012400001818181824ff0118
ExchangeManager: Message » id: 41007/48961/22333851 type: 0/16 acked: 235835024 reqAck: false duplicate: false payload:
MessageExchange: New exchange channel: udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 protocol: 1 id: 48962 session: secure/37896 peerSessionId: 41007 active threshold ms: 4000 active interval ms: 300 idle interval ms: 5000 maxTransmissions: 5 useMrp: true
InteractionClient: Invoking command: 0x0/OperationalCredentials(0x3e)/addNoc(0x6) with {"nocValue":"15300101012402013703241400182604200d702c2605a0431d41370624150127118b628b08eafd8d321824070124080130094104614645438c4dc4c5a8de5186e0227acc980ba966553877e710a2622cf74b1699d0cb6dc27f84c3080c2c1d6aeffd85ede3c2f1eaea54882068a3af1a67dbae63370a3501280118240201360304020401183004147241ab1e8bc75054e0e4ae7c4d749eaf77863e8b300514e495b8fd782e5b14131ce0eb262e7e393411377518300b40c614586fcf7e9f9a513e4decdee81e4a77ce724f696778b9a0cb00748e0777c124f7f0c76352e381bf34e89df791831f8465235b0fd9f27026f89826746f5e7d18","icacValue":"","ipkValue":"15a2985d679ece74591d6023a1f437f0","adminVendorId":65521,"caseAdminSubject":"18098693022946290589"}
ExchangeManager: Message » id: 41007/48962/22333852 type: 1/8 acked: undefined reqAck: true duplicate: false payload: 1528002801360215370024000024013e2402061835013000f815300101012402013703241400182604200d702c2605a0431d41370624150127118b628b08eafd8d321824070124080130094104614645438c4dc4c5a8de5186e0227acc980ba966553877e710a2622cf74b1699d0cb6dc27f84c3080c2c1d6aeffd85ede3c2f1eaea54882068a3af1a67dbae63370a3501280118240201360304020401183004147241ab1e8bc75054e0e4ae7c4d749eaf77863e8b300514e495b8fd782e5b14131ce0eb262e7e393411377518300b40c614586fcf7e9f9a513e4decdee81e4a77ce724f696778b9a0cb00748e0777c124f7f0c76352e381bf34e89df791831f8465235b0fd9f27026f89826746f5e7d1830010030021015a2985d679ece74591d6023a1f437f027039deb8dd369792bfb2504f1ff18181824ff0c18
MessageExchange: Message « id: 37896/48962/235835025 type: 0/16 acked: 22333852 reqAck: false duplicate: false payload:
MdnsScanner: Removing commissionable device A1E8A0A1D49EC530._matterc._udp.local from cache (interface eth0) because of ttl=0
MdnsScanner: Adding operational device B10EE3E333640BD1-328DFDEA088B628B._matter._tcp.local in cache (interface eth0) with TXT data: SII: 5000 SAI: 300 SAT: undefined T: 0 DT: undefined PH: undefined ICD: 0 VP: undefined DN: undefined RI: undefined PI: undefined
MessageExchange: Message « id: 37896/48962/235835026 type: 1/9 acked: 22333852 reqAck: true duplicate: false payload: 1528003601153500370024000024013e2402081835012400002401011818181824ff0118
InteractionClient: Received invoke response: 0x0/OperationalCredentials(0x3e)/addNoc(0x6) with {"statusCode":0,"fabricIndex":1})}
Controller~missioner: Commissioning step 11.1: NetworkCommissioning.Validate failed with error: No Wi-Fi/Thread network credentials are configured for commissioning and no Ethernet interface is available on the device and no interface already connected. ... Aborting commissioning
ExchangeManager: Message » id: 41007/48962/22333853 type: 0/16 acked: 235835026 reqAck: false duplicate: false payload:
Controller~missioner: Commissioning step addNoc returned 0, undefined, fabricIndex: 1
Controller~missioner: Executing commissioning step 10.1: AccessControl
Controller~missioner: Executing commissioning step 11.1: NetworkCommissioning.Validate
Controller~missioner: Returning existing cluster client for cluster GeneralCommissioning (endpoint 0, isFeatureSpecific false)
MessageExchange: New exchange channel: udp://fe80::207:a6ff:fe35:44d6%eth0:5540 on session secure/37896 protocol: 1 id: 48963 session: secure/37896 peerSessionId: 41007 active threshold ms: 4000 active interval ms: 300 idle interval ms: 5000 maxTransmissions: 5 useMrp: true
InteractionClient: Invoking command: 0x0/GeneralCommissioning(0x30)/armFailSafe(0x0) with {"breadcrumb":2,"expiryLengthSeconds":0}
ExchangeManager: Message » id: 41007/48963/22333854 type: 1/8 acked: undefined reqAck: true duplicate: false payload: 1528002801360215370024000024013024020018350124000024010218181824ff0c18
MessageExchange: Message « id: 37896/48963/235835027 type: 1/9 acked: 22333854 reqAck: true duplicate: false payload: 152800360115350037002400002401302402011835012400002c01001818181824ff0118
InteractionClient: Received invoke response: 0x0/GeneralCommissioning(0x30)/armFailSafe(0x0) with {"errorCode":0,"debugText":""})}
ExchangeManager: Message » id: 41007/48963/22333855 type: 0/16 acked: 235835027 reqAck: false duplicate: false payload:
      at ControllerCommissioner.validateNetwork (webpack://matter-server/../../../../../../Documents/workspace/matter.js/packages/matter.js/dist/cjs/protocol/ControllerCommissioner.js?:551:15)
MdnsScanner: Removing operational device B10EE3E333640BD1-328DFDEA088B628B._matter._tcp.local from cache (interface eth0) because of ttl=0
MdnsScanner: Adding operational device B10EE3E333640BD1-328DFDEA088B628B._matter._tcp.local in cache (interface eth0) with TXT data: SII: 5000 SAI: 300 SAT: undefined T: 0 DT: undefined PH: undefined ICD: 0 VP: undefined DN: undefined RI: undefined PI: undefined
digitaldan commented 3 weeks ago

Ah, maybe i just got it, that ethernet assumes no extra setup needed (just has to be plugged in) to get on the network , where wifi does require setup to get on the network.

edit:

If i print out networkFeatures and networkStatus in that throw block , this is what its reporting.

Controller~missioner: networkFeatures { endpointId: 0, value: { wiFiNetworkInterface: true, threadNetworkInterface: false, ethernetNetworkInterface: false } }
Controller~missioner: networkStatus { endpointId: 0, value: [] }
Apollon77 commented 3 weeks ago

Sooo ... ok to this topic ... iiinteresting ... and formally wrong ...

The commissioning process reads the network list from all network clusters and is getting

InteractionClient: Received read response with attributes 0x0/NetworkCommissioning(0x31)/networks(0x1) = [], 0x0/NetworkCommissioning(0x31)/featureMap(0xfffc) = {"wiFiNetworkInterface":true,"threadNetworkInterface":false,"ethernetNetworkInterface":false} and events

So this device does not report any network.

The check you reference is exactly assuming that an ethernet connection is always connected (in fact not 100% right and needs to e adjusted, but ethernet there is no configuration. For this we do not need any configuration.

For Wifi it checks if any network is connected, because if yes we also do not need any comissioning.

But in fact this is nothing that was introduced by 0.10 btw ...

Let me think about it ... but in my eyes that device is "Broken" ... but yes already on IP ... so I think I might just add the check if the commissioning connection is UDP because then all is fine

Apollon77 commented 3 weeks ago

@digitaldan I just kicked off a new nightly build, so please try this version once published and report back if it fixes the issue

digitaldan commented 3 weeks ago

Thanks @Apollon77 ! I went ahead and deployed this PR, and i can confirm it works for me now. Also thanks for the explanation on how this part of the code works.

Apollon77 commented 3 weeks ago

Great, thank you for confirming, and yw