Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

iOS 16.2 QR Code pairing issue #181

Closed
Apollon77 opened this issue Jan 8, 2023 · 11 comments
Closed

iOS 16.2 QR Code pairing issue #181

Apollon77 opened this issue Jan 8, 2023 · 11 comments

Comments

@Apollon77
Copy link
Collaborator

I tried to pair with current GitHub version on iOS by using QR code and interestingly he tries to call removeFabric with 0 as fabricIndex which is then crashing because fabricIndex is minimum 1 :-(

Log:

2023-0-0 17:56:36.727 INFO Device [email protected]
2023-0-0 17:56:36.753 INFO Device Listening
▄▄▄▄▄▄▄▄▄▄▄▄▄▄▄▄▄▄▄▄▄▄▄
█ ▄▄▄▄▄ ██▀▄▀▄█ ▄▄▄▄▄ █
█ █   █ █▄▀▄▀▄█ █   █ █
█ █▄▄▄█ ██ ▀▀▄█ █▄▄▄█ █
█▄▄▄▄▄▄▄█ █ ▀▄█▄▄▄▄▄▄▄█
█▄ ▄█▄ ▄▄ ▀ █  ▄▀██ █▀█
██ █▀▀ ▄▄█ █ ▀▄▄██ ▀█▀█
█▄▄████▄▄▄▀▄▀ ▀██▄▄▀▄▀█
█ ▄▄▄▄▄ █  ▄█▄█▄▄█▄ █ █
█ █   █ █▄▀▀█▄ ▄▀▀▄ ▀██
█ █▄▄▄█ █  ▀█▄█ ▀█  ▀ █
█▄▄▄▄▄▄▄█▄█▄█▄██▄██▄█▄█
▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀

QR Code URL: https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT:Y.K90AFN00KA0648G00
Manual pairing code: 34970112332
2023-0-0 17:56:36.757 ERROR MdnsBroadcaster Error: send EHOSTUNREACH ff02::fb:5353
2023-0-0 17:56:47.921 DEBUG MessageExchange onMessageReceived id:0/65489/27583476 t:0/32 reqAck:true payload: 153001205862e1aa8ee6bca933e57cd2b338834768554d0e785456d867de1b179541b14425024694240300280435052501881325022c011818
2023-0-0 17:56:47.922 INFO PaseServer Pase server: Received pairing request from udp://fe80::141c:e38b:5593:10e3%en0:60357
2023-0-0 17:56:47.925 DEBUG ExchangeManager sending id:0/65489/747125667 t:0/33 acked:27583476 reqAck:true payload: 153001205862e1aa8ee6bca933e57cd2b338834768554d0e785456d867de1b179541b144300220206e179ebd5dd624395c96bdfeef7116bb0caa888e9412ffe23380cd65e681f82503cc7e35042501e803300220ffbc1d8d20b034590bd31ca42edf6c4ff2e84e25048045ec28a122277dd3df371835052501881325022c011818
2023-0-0 17:56:48.127 DEBUG MessageExchange onMessageReceived id:0/65489/27583477 t:0/34 acked:747125667 reqAck:true payload: 1530014104e9b7b93c8c08dab9d21694398d4ff13a61bca9babbff285567e694bbcd0b2158b75f6531e4716410577613c3c8016663463e72ea3a9ab791d3ccb171fc31d74d18
2023-0-0 17:56:48.177 DEBUG ExchangeManager sending id:0/65489/747125668 t:0/35 acked:27583477 reqAck:true payload: 153001410487361d2139ccfa800cf1cf3d6098c2c9d7d5cc6869498577530c6a451b0ad4e579689de82ded0426493bad5b6f767fd5ece93e2c015532f25178403515d81d1a30022072b14caf9426ed10868dbe06d84a43abf8edbaf4a507642f51067b3694fd93fc18
2023-0-0 17:56:48.242 DEBUG MessageExchange onMessageReceived id:0/65489/27583478 t:0/36 acked:747125668 reqAck:true payload: 15300120a6a09102084ac4024e444f2e0107e555b624b060348284eea185b3acf6161b6718
2023-0-0 17:56:48.244 DEBUG ExchangeManager sending id:0/65489/747125669 t:0/64 acked:27583478 reqAck:true payload: 0000000000000000
2023-0-0 17:56:48.251 DEBUG MessageExchange onMessageReceived id:0/65489/27583479 t:0/16 acked:747125669 reqAck:false payload: 
2023-0-0 17:56:48.252 INFO PaseServer Pase server: session 32460 created with udp://fe80::141c:e38b:5593:10e3%en0:60357
2023-0-0 17:56:48.258 DEBUG MessageExchange onMessageReceived id:32460/65490/31779803 t:1/2 reqAck:true payload: 1536001724020024031d2404031818290324ff0118
2023-0-0 17:56:48.259 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32460: MA-rootdevice(0x0)/Descriptor(0x1d)/partsList(0x3)
2023-0-0 17:56:48.261 DEBUG ExchangeManager sending id:32460/65490/747125670 t:1/5 acked:31779803 reqAck:true payload: 153601153501240001370124020024031d240403183602040118181818290424ff0118
2023-0-0 17:56:48.267 DEBUG MessageExchange onMessageReceived id:32460/65490/31779804 t:0/16 acked:747125670 reqAck:false payload: 
2023-0-0 17:56:48.270 DEBUG MessageExchange onMessageReceived id:32460/65491/31779805 t:1/2 reqAck:true payload: 1536001724020024031d2404011818290324ff0118
2023-0-0 17:56:48.270 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32460: MA-rootdevice(0x0)/Descriptor(0x1d)/serverList(0x1)
2023-0-0 17:56:48.271 DEBUG ExchangeManager sending id:32460/65491/747125671 t:1/5 acked:31779805 reqAck:true payload: 153601153501240001370124020024031d24040118360204280430043e0431043c041d18181818290424ff0118
2023-0-0 17:56:48.278 DEBUG MessageExchange onMessageReceived id:32460/65491/31779806 t:0/16 acked:747125671 reqAck:false payload: 
2023-0-0 17:56:48.279 DEBUG MessageExchange onMessageReceived id:32460/65492/31779807 t:1/2 reqAck:true payload: 153600172402002403312504fcff1818290324ff0118
2023-0-0 17:56:48.279 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32460: MA-rootdevice(0x0)/Network Commissioning(0x31)/featureMap(0xfffc)
2023-0-0 17:56:48.279 DEBUG ExchangeManager sending id:32460/65492/747125672 t:1/5 acked:31779807 reqAck:true payload: 15360115350124000037012402002403312504fcff18240204181818290424ff0118
2023-0-0 17:56:48.286 DEBUG MessageExchange onMessageReceived id:32460/65492/31779808 t:0/16 acked:747125672 reqAck:false payload: 
2023-0-0 17:56:48.287 DEBUG MessageExchange onMessageReceived id:32460/65493/31779809 t:1/2 reqAck:true payload: 1536001724020024031d2404031818290324ff0118
2023-0-0 17:56:48.287 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32460: MA-rootdevice(0x0)/Descriptor(0x1d)/partsList(0x3)
2023-0-0 17:56:48.287 DEBUG ExchangeManager sending id:32460/65493/747125673 t:1/5 acked:31779809 reqAck:true payload: 153601153501240001370124020024031d240403183602040118181818290424ff0118
2023-0-0 17:56:48.293 DEBUG MessageExchange onMessageReceived id:32460/65493/31779810 t:0/16 acked:747125673 reqAck:false payload: 
2023-0-0 17:56:48.294 DEBUG MessageExchange onMessageReceived id:32460/65494/31779811 t:1/2 reqAck:true payload: 1536001724020024031d2404011818290324ff0118
2023-0-0 17:56:48.294 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32460: MA-rootdevice(0x0)/Descriptor(0x1d)/serverList(0x1)
2023-0-0 17:56:48.295 DEBUG ExchangeManager sending id:32460/65494/747125674 t:1/5 acked:31779811 reqAck:true payload: 153601153501240001370124020024031d24040118360204280430043e0431043c041d18181818290424ff0118
2023-0-0 17:56:48.300 DEBUG MessageExchange onMessageReceived id:32460/65494/31779812 t:0/16 acked:747125674 reqAck:false payload: 
2023-0-0 17:56:48.301 DEBUG MessageExchange onMessageReceived id:32460/65495/31779813 t:1/2 reqAck:true payload: 153600172402002403312504fcff1818290324ff0118
2023-0-0 17:56:48.301 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32460: MA-rootdevice(0x0)/Network Commissioning(0x31)/featureMap(0xfffc)
2023-0-0 17:56:48.301 DEBUG ExchangeManager sending id:32460/65495/747125675 t:1/5 acked:31779813 reqAck:true payload: 15360115350124000037012402002403312504fcff18240204181818290424ff0118
2023-0-0 17:56:48.307 DEBUG MessageExchange onMessageReceived id:32460/65495/31779814 t:0/16 acked:747125675 reqAck:false payload: 
2023-0-0 17:56:48.309 DEBUG MessageExchange onMessageReceived id:32460/65496/31779815 t:1/2 reqAck:true payload: 153600172403312504fcff18172402002403302404001817240200240330240401181724020024033024040218172402002403302404031817240200240328240402181724020024032824040418172403312404031818280324ff0118
2023-0-0 17:56:48.309 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32460: */0x31/0xfffc, MA-rootdevice(0x0)/General Commissioning(0x30)/breadcrumb(0x0), MA-rootdevice(0x0)/General Commissioning(0x30)/commissioningInfo(0x1), MA-rootdevice(0x0)/General Commissioning(0x30)/regulatoryConfig(0x2), MA-rootdevice(0x0)/General Commissioning(0x30)/locationCapability(0x3), MA-rootdevice(0x0)/Basic Information(0x28)/vendorId(0x2), MA-rootdevice(0x0)/Basic Information(0x28)/productId(0x4), */0x31/0x3
2023-0-0 17:56:48.310 DEBUG ExchangeManager sending id:32460/65496/747125676 t:1/5 acked:31779815 reqAck:true payload: 15360115350124000037012402002403312504fcff1824020418181535012400003701240200240330240400182402001818153501240000370124020024033024040118350224003c25018403181818153501240000370124020024033024040218240200181815350124000037012402002403302404031824020218181535012400003701240200240328240402182502f1ff1818153501240000370124020024032824040418250200801818153501240000370124020024033124040318240214181818290424ff0118
2023-0-0 17:56:48.322 DEBUG MessageExchange onMessageReceived id:32460/65497/31779816 t:1/8 reqAck:true payload: 1528002801360215370024000024013024020018350124003c24010318181824ff0118
2023-0-0 17:56:48.323 DEBUG InteractionProtocol Received invoke request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32460: 0x0/0x30/0x0
2023-0-0 17:56:48.323 DEBUG InteractionProtocol Invoke armFailSafe
2023-0-0 17:56:48.324 DEBUG ExchangeManager sending id:32460/65497/747125677 t:1/9 acked:31779816 reqAck:true payload: 152800360115350037002400002401302402011835012400002c01001818181824ff0118
2023-0-0 17:56:48.324 DEBUG MessageExchange onMessageReceived id:32460/65496/31779817 t:0/16 acked:747125676 reqAck:false payload: 
2023-0-0 17:56:48.330 DEBUG MessageExchange onMessageReceived id:32460/65498/31779818 t:1/8 reqAck:true payload: 152800280136021537002400002401302402021835012400002c0102585824020418181824ff0118
2023-0-0 17:56:48.331 DEBUG InteractionProtocol Received invoke request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32460: 0x0/0x30/0x2
2023-0-0 17:56:48.331 DEBUG InteractionProtocol Invoke setRegulatoryConfig
2023-0-0 17:56:48.331 DEBUG ExchangeManager sending id:32460/65498/747125678 t:1/9 acked:31779818 reqAck:true payload: 152800360115350037002400002401302402031835012400002c01001818181824ff0118
2023-0-0 17:56:48.331 DEBUG MessageExchange onMessageReceived id:32460/65497/31779819 t:0/16 acked:747125677 reqAck:false payload: 
2023-0-0 17:56:48.342 DEBUG MessageExchange onMessageReceived id:32460/65499/31779820 t:1/8 reqAck:true payload: 1528002801360215370024000024013e24020218350124000218181824ff0118
2023-0-0 17:56:48.342 DEBUG InteractionProtocol Received invoke request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32460: 0x0/0x3e/0x2
2023-0-0 17:56:48.342 DEBUG InteractionProtocol Invoke requestCertChain
2023-0-0 17:56:48.342 DEBUG ExchangeManager sending id:32460/65499/747125679 t:1/9 acked:31779820 reqAck:true payload: 1528003601153500370024000024013e2402031835013100d801308201d43082017aa00302010202083e6ce6509ad840cd300a06082a8648ce3d04030230303118301606035504030c0f4d617474657220546573742050414131143012060a2b0601040182a27c02010c04464646313020170d3231303632383134323334335a180f39393939313233313233353935395a30463118301606035504030c0f4d617474657220546573742050414931143012060a2b0601040182a27c02010c044646463131143012060a2b0601040182a27c02020c04383030303059301306072a8648ce3d020106082a8648ce3d0301070342000480ddf11b228f3e31f63bcf5798da14623aebbde82ef378eeadbfb18fe1abce31d08ed4b20604b6ccc6d9b5fab64e7de10cb74be017c9ec1516056d70f2cd0b22a366306430120603551d130101ff040830060101ff020100300e0603551d0f0101ff040403020106301d0603551d0e04160414af42b7094debd515ec6ecf33b81115225f325288301f0603551d230418301680146afd22771f511fecbf1641976710dcdc31a1717e300a06082a8648ce3d040302034800304502210096c9c8cf2e01886005d8f5bc72c07b75fd9a57695ac4911131138bea033ce50302202554943be57d53d6c475f7d23ebfcfc2036cd29ba6393ec7efad8714ab7182191818181824ff0118
2023-0-0 17:56:48.343 DEBUG MessageExchange onMessageReceived id:32460/65498/31779821 t:0/16 acked:747125678 reqAck:false payload: 
2023-0-0 17:56:48.350 DEBUG MessageExchange onMessageReceived id:32460/65500/31779822 t:1/8 reqAck:true payload: 1528002801360215370024000024013e24020218350124000118181824ff0118
2023-0-0 17:56:48.350 DEBUG InteractionProtocol Received invoke request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32460: 0x0/0x3e/0x2
2023-0-0 17:56:48.350 DEBUG InteractionProtocol Invoke requestCertChain
2023-0-0 17:56:48.351 DEBUG ExchangeManager sending id:32460/65500/747125680 t:1/9 acked:31779822 reqAck:true payload: 1528003601153500370024000024013e2402031835013100ec01308201e83082018fa0030201020208143c9d1689f498f0300a06082a8648ce3d04030230463118301606035504030c0f4d617474657220546573742050414931143012060a2b0601040182a27c02010c044646463131143012060a2b0601040182a27c02020c04383030303020170d3231303632383134323334335a180f39393939313233313233353935395a304b311d301b06035504030c144d6174746572205465737420444143203030303731143012060a2b0601040182a27c02010c044646463131143012060a2b0601040182a27c02020c04383030303059301306072a8648ce3d020106082a8648ce3d0301070342000462e2b6e1baff8d74a6fd8216c4cb67a3363a31e691492792e61aee610261481396725ef95e142686ba98f339b0ff65bc338bec7b9e8be0bdf3b2774982476220a360305e300c0603551d130101ff04023000300e0603551d0f0101ff040403020780301d0603551d0e04160414ee95ad96983a9ea95bcd2b00dc5e671727690383301f0603551d23041830168014af42b7094debd515ec6ecf33b81115225f325288300a06082a8648ce3d040302034700304402202f51cf53bf7777df7318094b9db595eebf2fa881c8c572847b1e689ece654264022029782708ee6b32c7f08ff63dbe618e9a580bb14c183bc288777adf9e2dcff5e61818181824ff0118
2023-0-0 17:56:48.351 DEBUG MessageExchange onMessageReceived id:32460/65499/31779823 t:0/16 acked:747125679 reqAck:false payload: 
2023-0-0 17:56:48.357 DEBUG MessageExchange onMessageReceived id:32460/65501/31779824 t:1/8 reqAck:true payload: 1528002801360215370024000024013e2402001835013000209e6c06b0d41332bf3de8bbf016b2819d86b1ee38ac4e8254c6934e4147b47ffd18181824ff0118
2023-0-0 17:56:48.358 DEBUG InteractionProtocol Received invoke request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32460: 0x0/0x3e/0x0
2023-0-0 17:56:48.358 DEBUG InteractionProtocol Invoke requestAttestation
2023-0-0 17:56:48.359 DEBUG ExchangeManager sending id:32460/65501/747125681 t:1/9 acked:31779824 reqAck:true payload: 1528003601153500370024000024013e240201183501310049021531011d023082021906092a864886f70d010702a082020a30820206020103310d300b06096086480165030402013082017106092a864886f70d010701a08201620482015e152400012501f1ff3602050080050180050280050380050480050580050680050780050880050980050a80050b80050c80050d80050e80050f80051080051180051280051380051480051580051680051780051880051980051a80051b80051c80051d80051e80051f80052080052180052280052380052480052580052680052780052880052980052a80052b80052c80052d80052e80052f80053080053180053280053380053480053580053680053780053880053980053a80053b80053c80053d80053e80053f80054080054180054280054380054480054580054680054780054880054980054a80054b80054c80054d80054e80054f80055080055180055280055380055480055580055680055780055880055980055a80055b80055c80055d80055e80055f80056080056180056280056380182403162c04135a494732303134325a423333303030332d32342405002406002507942624080018317d307b020103801462fa823359acfaa9963e1cfa140addf504f37160300b0609608648016503040201300a06082a8648ce3d04030204473045022024e5d1f47a7d7b0d206a26ef699b7c9757b72d469089de3192e678c745e7f60c022100f8aa2fa711fcb79b97e397ceda667bae464e2bd3ffdfc3cced7aa8ca5f4c1a7c3002209e6c06b0d41332bf3de8bbf016b2819d86b1ee38ac4e8254c6934e4147b47ffd240300183001400af44d07bf95f865394ad2467e78305ea80ca85a6e51e03480c23cd5671ddfd3e0c9b6cef899a63db038403b063d39d7f72eca8701e77172a93fcf78cfd089d31818181824ff0118
2023-0-0 17:56:48.360 DEBUG MessageExchange onMessageReceived id:32460/65500/31779825 t:0/16 acked:747125680 reqAck:false payload: 
2023-0-0 17:56:48.399 DEBUG MessageExchange onMessageReceived id:32460/65502/31779826 t:1/8 reqAck:true payload: 1528002801360215370024000024013024020018350124003c24010818181824ff0118
2023-0-0 17:56:48.400 DEBUG InteractionProtocol Received invoke request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32460: 0x0/0x30/0x0
2023-0-0 17:56:48.400 DEBUG InteractionProtocol Invoke armFailSafe
2023-0-0 17:56:48.400 DEBUG ExchangeManager sending id:32460/65502/747125682 t:1/9 acked:31779826 reqAck:true payload: 152800360115350037002400002401302402011835012400002c01001818181824ff0118
2023-0-0 17:56:48.401 DEBUG MessageExchange onMessageReceived id:32460/65501/31779827 t:0/16 acked:747125681 reqAck:false payload: 
2023-0-0 17:56:48.407 DEBUG MessageExchange onMessageReceived id:32460/65502/31779828 t:0/16 acked:747125682 reqAck:false payload: 
2023-0-0 17:56:50.377 DEBUG MessageExchange onMessageReceived id:32460/65503/31779829 t:1/8 reqAck:true payload: 1528002801360215370024000024013e240204183501300020ef922221c8f9f52f5b43e98ff7f9e6c607ff7487b7263babe1a1b6a379d4af9b18181824ff0118
2023-0-0 17:56:50.377 DEBUG InteractionProtocol Received invoke request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32460: 0x0/0x3e/0x4
2023-0-0 17:56:50.377 DEBUG InteractionProtocol Invoke requestCertSigning
2023-0-0 17:56:50.379 DEBUG ExchangeManager sending id:32460/65503/747125683 t:1/9 acked:31779829 reqAck:true payload: 1528003601153500370024000024013e2402051835013000f3153001cb3081c83070020100300e310c300a060355040a0c034353523059301306072a8648ce3d020106082a8648ce3d03010703420004e9b22db274011efe5758d1dcf193dc194708155f486202b321a5162d227da11c3db4b7a1118e13637342528947bbda2e70bf61e26642d88ecc5c8387cf523ab2a000300a06082a8648ce3d04030203480030450220142cd2b27d04ac699f19ac55d3e201e839834fae22d679b9ce9e024712e35d9f022100f866dcf486dda24e66e2ca2e0162366b5f8f1ec5e0d43c1964709f515526dbdb300220ef922221c8f9f52f5b43e98ff7f9e6c607ff7487b7263babe1a1b6a379d4af9b18300140899024c361d25c0349f125886028bee9f079564db79bf3e528d109bc560401e8cef13bea92736d30e90ad5f1002bbf0e0c60ad6470728d636a46b8fbb98885f21818181824ff0118
2023-0-0 17:56:50.453 DEBUG MessageExchange onMessageReceived id:32460/65504/31779830 t:1/8 reqAck:true payload: 1528002801360215370024000024013e24020b1835013000fb15300101002402013703271447345acbc31be2c2241502182604a24f012b26052283e22c3706271447345acbc31be2c224150218240701240801300941047f7bd2a28eaa181abd4118140037c6354c834cf74909dc138f9db212e609d0eeec47af344f0701c395e3ef4b5a5454c7664ddb3d3c0f8b08920f9580b31c7e7a370a35012901182402603004144b1c9982934b8bd2e6b3c407d3611db976e50e733005144b1c9982934b8bd2e6b3c407d3611db976e50e7318300b40929938cde88683fd11439c94c11c6b37d5dccd3dda39f9507e2d96edd2420f64969e537c7f58faf900a80ed7ad472353719c30eacc07b515a3e1ea73c788eb7c1818181824ff0118
2023-0-0 17:56:50.453 DEBUG InteractionProtocol Received invoke request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32460: 0x0/0x3e/0xb
2023-0-0 17:56:50.453 DEBUG InteractionProtocol Invoke addRootCert
2023-0-0 17:56:50.454 DEBUG ExchangeManager sending id:32460/65504/747125684 t:1/9 acked:31779830 reqAck:true payload: 1528003601153501370024000024013e24020b1835012400001818181824ff0118
2023-0-0 17:56:50.454 DEBUG MessageExchange onMessageReceived id:32460/65503/31779831 t:0/16 acked:747125683 reqAck:false payload: 
2023-0-0 17:56:50.462 DEBUG MessageExchange onMessageReceived id:32460/65505/31779832 t:1/8 reqAck:true payload: 1528002801360215370024000024013e2402061835013000fe15300101012402013703271447345acbc31be2c224150218260452b24d2b2605d2e52e2d37062415022611ed8edbe41824070124080130094104e9b22db274011efe5758d1dcf193dc194708155f486202b321a5162d227da11c3db4b7a1118e13637342528947bbda2e70bf61e26642d88ecc5c8387cf523ab2370a3501280118240201360304020401183004145ff46c51e93989265574e18c43e24eca3276bd143005144b1c9982934b8bd2e6b3c407d3611db976e50e7318300b40474127f9c41d74583574b8baa8d13e0fc373d9e83eb779021fa5afd23629d275c74ed4a9819e95d0c7d6d43b2238eb0457f030809b0e5fcb58c96ea1449eb5fb183001003002108c0a1d163110ea191b9b5eb55162c8cb270327062caf9b1a95272504491318181824ff0118
2023-0-0 17:56:50.462 DEBUG InteractionProtocol Received invoke request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32460: 0x0/0x3e/0x6
2023-0-0 17:56:50.462 DEBUG InteractionProtocol Invoke addOperationalCert
2023-0-0 17:56:50.463 DEBUG MessageExchange onMessageReceived id:32460/65504/31779833 t:0/16 acked:747125684 reqAck:false payload: 
addOperationalCert success
2023-0-0 17:56:50.469 DEBUG ExchangeManager sending id:32460/65505/747125685 t:1/9 acked:31779832 reqAck:true payload: 1528003601153500370024000024013e2402081835012400002401011818181824ff0118
2023-0-0 17:56:50.470 ERROR MdnsBroadcaster Error: send EHOSTUNREACH ff02::fb:5353
2023-0-0 17:56:50.488 DEBUG MessageExchange onMessageReceived id:32460/65505/31779834 t:0/16 acked:747125685 reqAck:false payload: 
2023-0-0 17:56:50.695 DEBUG MessageExchange onMessageReceived id:0/65506/27583480 t:0/48 reqAck:true payload: 153001204881f18a54067971dca36730e90de66c0bd684e3474c9543618e13003e0fd9e6250247943003208352d808b22e194fdc9ad9456573993caf3450488c30e03946f18dc8b724fec130044104a0b6304f122b2270b5e81d92f8a7d610496e3633606bbf07d8ea967ccc4e87b9a6104c6531490dfa2472fa6647e6d49f9ba9be2fa7778a931255138c944d52f135052501881325022c011818
2023-0-0 17:56:50.695 INFO CaseServer Case server: Received pairing request from udp://fe80::141c:e38b:5593:10e3%en0:60357
2023-0-0 17:56:50.697 DEBUG ExchangeManager sending id:0/65506/747125686 t:0/49 acked:27583480 reqAck:true payload: 15300120e3a3d3152abbdd02d62243239742abafe91a8823de804bc6b00f4c52125a14392502cd7e300341049d7cfa232b29db3183c83e1296811fb424bc75b7980c24e62939e12fa4903cd3c243381b96dd90df52c8d201902a438f8e286840a9dbd8281f9dc87d1df5f25131046901a9bf111759cc3380a7d54be7b41a7ab9af9bc97cd2976db5ed157f30bf709e6ac7df2b3f1555d3c27d3c2adaf4e928c4226be88d4cef61faaa46900cc629d98b831037334a0095c7bcf8bd76847e0441bb15abe228307a9399e3f0df0f821f3d41b3b3c692dcd429d57593451465bb3d1aba11c70bd0b77391109a027c7ead2b88ce019e6ab48d31661db6e67b950e787957efc28f91c4ea7c5ccdae16eb819d4d1b0b2e0b874b6a0995892d76b5401d89619099ce8148590e7b838f640af420b6e46e707df50fcc73221b13f836e6390d1311a7bcb17453dc7f59c9ac074c5130f9af8f7518483a3dd7c0faf915563bc60b76be73e516e6f9633ae2bb2b1cda95ee6fa96ac8fcb1c2a931acd86f1acd37e27f2f1ffc928dc2a4cb2e48645dd397a3016bc2eeb9a046d774765d516317da2010c9067d70faf0aa87e3abc84d1f7b07031cd8afa4fc2ab727f85a347c6d3aebc05be47ba565a89c3e35986c857d2269140f08812a20b635052501881325022c011818
2023-0-0 17:56:50.760 DEBUG MessageExchange onMessageReceived id:0/65506/27583481 t:0/50 acked:747125686 reqAck:true payload: 1531015b018b33dcd9adb641bf2679140462499bf63807f66ad8ae3945534ad9a57400d656b24f3600573591dcd95b88bb8b1ca31dbb70699206e76c63122633f564d3154d3a2ccc3fb3e89e2efd8c30c68e4bdfbb9c2615a28692f0b22719e6b1a96ff9eeeceaf607a501ca0650a87f2e1475d477da0119558c82ce486e575095fb1fb2bf2d190140ded4415ad4ef5b510c2107b7090867a2be8ae083d1a0363c985eeb20efac31afb6537f565706348ee025f2b3f031dd1bdb77deb2846a164382d7daa3edfc7d573c488cab99de9ff5bdea9a98c93aa6faec67238b8a8ef83e4f4296e40b7b7566a70fb981dcacc273c76c8accc9121c2943f06312c9b7b69701a6f62d3813c86032eb0204fae174c99978b6f7d3f6af41f0e17881391095aa21922590faa51f3b151a92ca167c65497142d07587daa54c0d7029959d3e87d4a96ee635eb4011ea10b9b5105ea60df436aceb1c630b3ae62829fb5dae389d18
2023-0-0 17:56:50.762 INFO CaseServer Case server: session 32461 created with udp://fe80::141c:e38b:5593:10e3%en0:60357
2023-0-0 17:56:50.762 DEBUG ExchangeManager sending id:0/65506/747125687 t:0/64 acked:27583481 reqAck:true payload: 0000000000000000
2023-0-0 17:56:50.771 DEBUG MessageExchange onMessageReceived id:32461/65507/192438192 t:1/8 reqAck:true payload: 1528002801360215370024000024013024020418350118181824ff0118
2023-0-0 17:56:50.772 DEBUG InteractionProtocol Received invoke request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32461: 0x0/0x30/0x4
2023-0-0 17:56:50.772 DEBUG InteractionProtocol Invoke commissioningComplete
2023-0-0 17:56:50.772 INFO GeneralCommissioningClusterHandler Commissioning completed on fabric #2 as node #00000000E4DB8EED.
2023-0-0 17:56:50.772 DEBUG ExchangeManager sending id:32461/65507/747125688 t:1/9 acked:192438192 reqAck:true payload: 152800360115350037002400002401302402051835012400002c01001818181824ff0118
2023-0-0 17:56:50.773 DEBUG MessageExchange onMessageReceived id:0/65506/27583482 t:0/16 acked:747125687 reqAck:false payload: 
2023-0-0 17:56:50.780 DEBUG MessageExchange onMessageReceived id:32461/65507/192438193 t:0/16 acked:747125688 reqAck:false payload: 
2023-0-0 17:56:50.814 DEBUG MessageExchange onMessageReceived id:32461/65508/192438194 t:1/2 reqAck:true payload: 1536001724020024033e2404011818290324ff0118
2023-0-0 17:56:50.815 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32461: MA-rootdevice(0x0)/Operational Credentials(0x3e)/fabrics(0x1)
2023-0-0 17:56:50.815 DEBUG ExchangeManager sending id:32461/65508/747125689 t:1/5 acked:192438194 reqAck:true payload: 153601153501240001370124020024033e24040118360215300141047f7bd2a28eaa181abd4118140037c6354c834cf74909dc138f9db212e609d0eeec47af344f0701c395e3ef4b5a5454c7664ddb3d3c0f8b08920f9580b31c7e7a250249132403022604ed8edbe42c050024fe011818181818290424ff0118
2023-0-0 17:56:50.826 DEBUG MessageExchange onMessageReceived id:32461/65508/192438195 t:0/16 acked:747125689 reqAck:false payload: 
2023-0-0 17:56:50.845 DEBUG MessageExchange onMessageReceived id:32461/65509/192438196 t:1/2 reqAck:true payload: 1536001724020024031d2404031818290324ff0118
2023-0-0 17:56:50.845 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32461: MA-rootdevice(0x0)/Descriptor(0x1d)/partsList(0x3)
2023-0-0 17:56:50.845 DEBUG ExchangeManager sending id:32461/65509/747125690 t:1/5 acked:192438196 reqAck:true payload: 153601153501240001370124020024031d240403183602040118181818290424ff0118
2023-0-0 17:56:50.851 DEBUG MessageExchange onMessageReceived id:32461/65509/192438197 t:0/16 acked:747125690 reqAck:false payload: 
2023-0-0 17:56:50.852 DEBUG MessageExchange onMessageReceived id:32461/65510/192438198 t:1/2 reqAck:true payload: 1536001724020124031d2404001818290324ff0118
2023-0-0 17:56:50.852 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32461: MA-onofflight(0x1)/Descriptor(0x1d)/deviceTypeList(0x0)
2023-0-0 17:56:50.853 DEBUG ExchangeManager sending id:32461/65510/747125691 t:1/5 acked:192438198 reqAck:true payload: 153601153501240000370124020124031d24040018360215250000012401011818181818290424ff0118
2023-0-0 17:56:50.859 DEBUG MessageExchange onMessageReceived id:32461/65510/192438199 t:0/16 acked:747125691 reqAck:false payload: 
2023-0-0 17:56:50.861 DEBUG MessageExchange onMessageReceived id:32461/65511/192438200 t:1/2 reqAck:true payload: 1536001724020124031d2404031818290324ff0118
2023-0-0 17:56:50.861 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32461: MA-onofflight(0x1)/Descriptor(0x1d)/partsList(0x3)
2023-0-0 17:56:50.861 DEBUG ExchangeManager sending id:32461/65511/747125692 t:1/5 acked:192438200 reqAck:true payload: 153601153501240000370124020124031d24040318360218181818290424ff0118
2023-0-0 17:56:50.867 DEBUG MessageExchange onMessageReceived id:32461/65511/192438201 t:0/16 acked:747125692 reqAck:false payload: 
2023-0-0 17:56:50.868 DEBUG MessageExchange onMessageReceived id:32461/65512/192438202 t:1/2 reqAck:true payload: 1536001724020124031d2404011818290324ff0118
2023-0-0 17:56:50.868 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32461: MA-onofflight(0x1)/Descriptor(0x1d)/serverList(0x1)
2023-0-0 17:56:50.868 DEBUG ExchangeManager sending id:32461/65512/747125693 t:1/5 acked:192438202 reqAck:true payload: 153601153501240001370124020124031d2404011836020406041d18181818290424ff0118
2023-0-0 17:56:50.874 DEBUG MessageExchange onMessageReceived id:32461/65512/192438203 t:0/16 acked:747125693 reqAck:false payload: 
2023-0-0 17:56:50.877 DEBUG MessageExchange onMessageReceived id:32461/65513/192438204 t:1/2 reqAck:true payload: 153600172402012403062504fcff1818290324ff0118
2023-0-0 17:56:50.877 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32461: MA-onofflight(0x1)/On/Off(0x6)/featureMap(0xfffc)
2023-0-0 17:56:50.877 DEBUG ExchangeManager sending id:32461/65513/747125694 t:1/5 acked:192438204 reqAck:true payload: 15360115350124000037012402012403062504fcff18240200181818290424ff0118
2023-0-0 17:56:50.884 DEBUG MessageExchange onMessageReceived id:32461/65513/192438205 t:0/16 acked:747125694 reqAck:false payload: 
2023-0-0 17:56:50.890 DEBUG MessageExchange onMessageReceived id:32461/65514/192438206 t:1/2 reqAck:true payload: 1536001724020024033e2404011818280324ff0118
2023-0-0 17:56:50.890 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32461: MA-rootdevice(0x0)/Operational Credentials(0x3e)/fabrics(0x1)
2023-0-0 17:56:50.890 DEBUG ExchangeManager sending id:32461/65514/747125695 t:1/5 acked:192438206 reqAck:true payload: 153601153501240001370124020024033e24040118360215300141047f7bd2a28eaa181abd4118140037c6354c834cf74909dc138f9db212e609d0eeec47af344f0701c395e3ef4b5a5454c7664ddb3d3c0f8b08920f9580b31c7e7a250249132403022604ed8edbe42c050024fe011818181818290424ff0118
2023-0-0 17:56:50.897 DEBUG MessageExchange onMessageReceived id:32461/65514/192438207 t:0/16 acked:747125695 reqAck:false payload: 
2023-0-0 17:56:51.001 DEBUG MessageExchange onMessageReceived id:32461/65515/192438208 t:1/10 reqAck:true payload: 152500102724ff0118
2023-0-0 17:56:51.001 DEBUG InteractionProtocol Received timed request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32461
2023-0-0 17:56:51.001 DEBUG ExchangeManager sending id:32461/65515/747125696 t:1/1 acked:192438208 reqAck:true payload: 1524000024ff0118
2023-0-0 17:56:51.008 DEBUG MessageExchange onMessageReceived id:32461/65515/192438209 t:1/8 acked:747125696 reqAck:true payload: 1528002901360215370024000024013c24020018350125002c01300161847ab827ce129d1a7d7130f05efb9603bfe01143cf38455bd01244747af6a81104d49aed59e88a5a3e78bf082f7c1c118b3ff4aacb825cc0723eae2007d260932697c55b0e2db00a4d8709802bda3cb01a7af4c66424b5935f045213610a47894425025a0e2503e8033004206f54b8c4328c4c2ca714ff2a0e5a56ea3d8df984090767015386939179549bcc18181824ff0118
2023-0-0 17:56:51.009 DEBUG InteractionProtocol Received invoke request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32461: 0x0/0x3c/0x0
2023-0-0 17:56:51.009 DEBUG InteractionProtocol Invoke openCommissioningWindow
2023-0-0 17:56:51.018 DEBUG ExchangeManager sending id:32461/65515/747125697 t:1/9 acked:192438209 reqAck:true payload: 1528003601153500370024000024013c2402001835011818181824ff0118
2023-0-0 17:56:51.019 ERROR MdnsBroadcaster Error: send EHOSTUNREACH ff02::fb:5353
2023-0-0 17:56:51.028 DEBUG MessageExchange onMessageReceived id:32461/65515/192438210 t:0/16 acked:747125697 reqAck:false payload: 
2023-0-0 17:56:51.028 DEBUG MessageExchange onMessageReceived id:32461/65516/192438211 t:1/2 reqAck:true payload: 1536001724020024033e2404051818290324ff0118
2023-0-0 17:56:51.028 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32461: MA-rootdevice(0x0)/Operational Credentials(0x3e)/currentFabricIndex(0x5)
2023-0-0 17:56:51.028 DEBUG ExchangeManager sending id:32461/65516/747125698 t:1/5 acked:192438211 reqAck:true payload: 153601153501240000370124020024033e24040518240200181818290424ff0118
2023-0-0 17:56:51.040 DEBUG MessageExchange onMessageReceived id:32461/65516/192438212 t:0/16 acked:747125698 reqAck:false payload: 
2023-0-0 17:56:51.041 DEBUG MessageExchange onMessageReceived id:32461/65517/192438213 t:1/8 reqAck:true payload: 1528002801360215370024000024013e24020a18350124000018181824ff0118
2023-0-0 17:56:51.041 DEBUG InteractionProtocol Received invoke request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32461: 0x0/0x3e/0xa
2023-0-0 17:56:51.041 DEBUG InteractionProtocol Invoke removeFabric
2023-0-0 17:56:51.041 ERROR InteractionMessenger Error: Invalid value: 0 is below the minimum, 1.
    at TlvNumberSchema.validate (/Users/ingof/Dev/GitHub/node-matter/node_modules/@project-chip/matter.js/dist/cjs/tlv/TlvNumber.js:42:19)
    at TlvNumberSchema.decodeTlvInternalValue (/Users/ingof/Dev/GitHub/node-matter/node_modules/@project-chip/matter.js/dist/cjs/tlv/TlvNumber.js:36:14)
    at TlvNumberSchema.decodeTlvInternalValue (/Users/ingof/Dev/GitHub/node-matter/node_modules/@project-chip/matter.js/dist/cjs/tlv/TlvNumber.js:57:29)
    at TlvWrapper.decodeTlvInternalValue (/Users/ingof/Dev/GitHub/node-matter/node_modules/@project-chip/matter.js/dist/cjs/tlv/TlvWrapper.js:18:50)
    at ObjectSchema.decodeTlvInternalValue (/Users/ingof/Dev/GitHub/node-matter/node_modules/@project-chip/matter.js/dist/cjs/tlv/TlvObject.js:61:41)
    at ObjectSchema.decodeTlvInternal (/Users/ingof/Dev/GitHub/node-matter/node_modules/@project-chip/matter.js/dist/cjs/tlv/TlvSchema.js:33:35)
    at ObjectSchema.decodeTlv (/Users/ingof/Dev/GitHub/node-matter/node_modules/@project-chip/matter.js/dist/cjs/tlv/TlvSchema.js:29:21)
    at CommandServer.<anonymous> (/Users/ingof/Dev/GitHub/node-matter/build/matter/cluster/server/CommandServer.js:24:48)
    at Generator.next (<anonymous>)
    at /Users/ingof/Dev/GitHub/node-matter/build/matter/cluster/server/CommandServer.js:8:71
2023-0-0 17:56:51.041 DEBUG ExchangeManager sending id:32461/65517/747125699 t:1/1 acked:192438213 reqAck:true payload: 1524000124ff0118
2023-0-0 17:56:51.048 DEBUG MessageExchange onMessageReceived id:32461/65517/192438214 t:1/1 acked:747125699 reqAck:true payload: 1524008024ff0118
2023-0-0 17:56:51.048 DEBUG ExchangeManager sending id:32461/65517/747125700 t:0/16 acked:192438214 reqAck:false payload:

Spec wise this is all correct, so Apple does an invalid call?

(the one command logile I added)
@Apollon77
Copy link
Collaborator Author

Apollon77 commented Jan 8, 2023 •
edited
Loading

Ok, I digged deeper:

  • on "addOperationalCert" we return id 1 as fabricIndex ... so it can not be because we return a wrong value
  • if I add code to removeFabric to react to "0" as invalid id as defined in specs the process will also stop on the same place
  • if I return status Success (aka 0 ... hope this is same as "ok") it is also the same and pairing process stops there.

@Apollon77
Copy link
Collaborator Author

oookkk ... it gets more interesting .... All above was my macbook connected to LAN.

Now I tried with WLAN and heeyy ... it goes different ...

2023-0-0 19:47:27.073 INFO Device [email protected]
2023-0-0 19:47:27.105 INFO Device Listening
▄▄▄▄▄▄▄▄▄▄▄▄▄▄▄▄▄▄▄▄▄▄▄
█ ▄▄▄▄▄ ██▀▄▀▄█ ▄▄▄▄▄ █
█ █   █ █▄▀▄▀▄█ █   █ █
█ █▄▄▄█ ██ ▀▀▄█ █▄▄▄█ █
█▄▄▄▄▄▄▄█ █ ▀▄█▄▄▄▄▄▄▄█
█▄ ▄█▄ ▄▄ ▀ █  ▄▀██ █▀█
██ █▀▀ ▄▄█ █ ▀▄▄██ ▀█▀█
█▄▄████▄▄▄▀▄▀ ▀██▄▄▀▄▀█
█ ▄▄▄▄▄ █  ▄█▄█▄▄█▄ █ █
█ █   █ █▄▀▀█▄ ▄▀▀▄ ▀██
█ █▄▄▄█ █  ▀█▄█ ▀█  ▀ █
█▄▄▄▄▄▄▄█▄█▄█▄██▄██▄█▄█
▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀▀

QR Code URL: https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT:Y.K90AFN00KA0648G00
Manual pairing code: 34970112332
2023-0-0 19:47:27.110 ERROR MdnsBroadcaster Error: send EHOSTUNREACH ff02::fb:5353
2023-0-0 19:47:49.535 DEBUG MessageExchange onMessageReceived id:0/7156/162373656 t:0/32 reqAck:true payload: 153001204a7eb39389e092ef37921728c5504c966ab29c1f133f8ced5184b9e9b59eece925020929240300280435052501881325022c011818
2023-0-0 19:47:49.536 INFO PaseServer Pase server: Received pairing request from udp://fe80::141c:e38b:5593:10e3%en0:62854
2023-0-0 19:47:49.540 DEBUG ExchangeManager sending id:0/7156/1846426683 t:0/33 acked:162373656 reqAck:true payload: 153001204a7eb39389e092ef37921728c5504c966ab29c1f133f8ced5184b9e9b59eece93002203ea89606cd1cce71a9a4478e93f06dbff06a0aab3842efec03815f7e228ce0142503e5ce35042501e803300220f52b8c0b8b308c830a709a0a8cd8d087ad6ac402f91d6727a5bfb80ef79b88311835052501881325022c011818
2023-0-0 19:47:49.646 DEBUG MessageExchange onMessageReceived id:0/7156/162373657 t:0/34 acked:1846426683 reqAck:true payload: 15300141040acd094f7eb6af419e737a1a9047a716fa657ec7399763edbecd2a754cfe7ee581f41425dab5c7c02dabf09e3e6fec09c9c2652fd3ab7c07cf234c836d129fa918
2023-0-0 19:47:49.697 DEBUG ExchangeManager sending id:0/7156/1846426684 t:0/35 acked:162373657 reqAck:true payload: 1530014104472a30692f0a4f984866d4fe303e0e4a0358b3bb14e59b2123b474ec3677e5e19f992ea5b63430b46d4640bdf54935f95dac78081ec682ab08f0870900a03902300220ed58001d75f56cf3cb9901c759c5e6871077b4d660aeca1397f0ea1985e3d50318
2023-0-0 19:47:49.766 DEBUG MessageExchange onMessageReceived id:0/7156/162373658 t:0/36 acked:1846426684 reqAck:true payload: 15300120bfa968b9d3e90c169d286f0e6c36ff805d994ca48e1ee35461fbcf66bc5968bd18
2023-0-0 19:47:49.768 DEBUG ExchangeManager sending id:0/7156/1846426685 t:0/64 acked:162373658 reqAck:true payload: 0000000000000000
2023-0-0 19:47:49.778 DEBUG MessageExchange onMessageReceived id:0/7156/162373659 t:0/16 acked:1846426685 reqAck:false payload: 
2023-0-0 19:47:49.779 INFO PaseServer Pase server: session 52965 created with udp://fe80::141c:e38b:5593:10e3%en0:62854
2023-0-0 19:47:49.788 DEBUG MessageExchange onMessageReceived id:52965/7157/71824226 t:1/2 reqAck:true payload: 1536001724020024031d2404031818290324ff0118
2023-0-0 19:47:49.790 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52965: MA-rootdevice(0x0)/Descriptor(0x1d)/partsList(0x3)
2023-0-0 19:47:49.791 DEBUG ExchangeManager sending id:52965/7157/1846426686 t:1/5 acked:71824226 reqAck:true payload: 153601153501240001370124020024031d240403183602040118181818290424ff0118
2023-0-0 19:47:49.804 DEBUG MessageExchange onMessageReceived id:52965/7157/71824227 t:0/16 acked:1846426686 reqAck:false payload: 
2023-0-0 19:47:49.805 DEBUG MessageExchange onMessageReceived id:52965/7158/71824228 t:1/2 reqAck:true payload: 1536001724020024031d2404011818290324ff0118
2023-0-0 19:47:49.805 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52965: MA-rootdevice(0x0)/Descriptor(0x1d)/serverList(0x1)
2023-0-0 19:47:49.805 DEBUG ExchangeManager sending id:52965/7158/1846426687 t:1/5 acked:71824228 reqAck:true payload: 153601153501240001370124020024031d24040118360204280430043e0431043c041d18181818290424ff0118
2023-0-0 19:47:49.819 DEBUG MessageExchange onMessageReceived id:52965/7158/71824229 t:0/16 acked:1846426687 reqAck:false payload: 
2023-0-0 19:47:49.820 DEBUG MessageExchange onMessageReceived id:52965/7159/71824230 t:1/2 reqAck:true payload: 153600172402002403312504fcff1818290324ff0118
2023-0-0 19:47:49.820 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52965: MA-rootdevice(0x0)/Network Commissioning(0x31)/featureMap(0xfffc)
2023-0-0 19:47:49.821 DEBUG ExchangeManager sending id:52965/7159/1846426688 t:1/5 acked:71824230 reqAck:true payload: 15360115350124000037012402002403312504fcff18240204181818290424ff0118
2023-0-0 19:47:49.839 DEBUG MessageExchange onMessageReceived id:52965/7159/71824231 t:0/16 acked:1846426688 reqAck:false payload: 
2023-0-0 19:47:49.839 DEBUG MessageExchange onMessageReceived id:52965/7160/71824232 t:1/2 reqAck:true payload: 1536001724020024031d2404031818290324ff0118
2023-0-0 19:47:49.840 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52965: MA-rootdevice(0x0)/Descriptor(0x1d)/partsList(0x3)
2023-0-0 19:47:49.840 DEBUG ExchangeManager sending id:52965/7160/1846426689 t:1/5 acked:71824232 reqAck:true payload: 153601153501240001370124020024031d240403183602040118181818290424ff0118
2023-0-0 19:47:49.851 DEBUG MessageExchange onMessageReceived id:52965/7160/71824233 t:0/16 acked:1846426689 reqAck:false payload: 
2023-0-0 19:47:49.851 DEBUG MessageExchange onMessageReceived id:52965/7161/71824234 t:1/2 reqAck:true payload: 1536001724020024031d2404011818290324ff0118
2023-0-0 19:47:49.852 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52965: MA-rootdevice(0x0)/Descriptor(0x1d)/serverList(0x1)
2023-0-0 19:47:49.852 DEBUG ExchangeManager sending id:52965/7161/1846426690 t:1/5 acked:71824234 reqAck:true payload: 153601153501240001370124020024031d24040118360204280430043e0431043c041d18181818290424ff0118
2023-0-0 19:47:49.864 DEBUG MessageExchange onMessageReceived id:52965/7161/71824235 t:0/16 acked:1846426690 reqAck:false payload: 
2023-0-0 19:47:49.864 DEBUG MessageExchange onMessageReceived id:52965/7162/71824236 t:1/2 reqAck:true payload: 153600172402002403312504fcff1818290324ff0118
2023-0-0 19:47:49.865 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52965: MA-rootdevice(0x0)/Network Commissioning(0x31)/featureMap(0xfffc)
2023-0-0 19:47:49.865 DEBUG ExchangeManager sending id:52965/7162/1846426691 t:1/5 acked:71824236 reqAck:true payload: 15360115350124000037012402002403312504fcff18240204181818290424ff0118
2023-0-0 19:47:49.876 DEBUG MessageExchange onMessageReceived id:52965/7162/71824237 t:0/16 acked:1846426691 reqAck:false payload: 
2023-0-0 19:47:49.878 DEBUG MessageExchange onMessageReceived id:52965/7163/71824238 t:1/2 reqAck:true payload: 153600172403312504fcff18172402002403302404001817240200240330240401181724020024033024040218172402002403302404031817240200240328240402181724020024032824040418172403312404031818280324ff0118
2023-0-0 19:47:49.879 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52965: */0x31/0xfffc, MA-rootdevice(0x0)/General Commissioning(0x30)/breadcrumb(0x0), MA-rootdevice(0x0)/General Commissioning(0x30)/commissioningInfo(0x1), MA-rootdevice(0x0)/General Commissioning(0x30)/regulatoryConfig(0x2), MA-rootdevice(0x0)/General Commissioning(0x30)/locationCapability(0x3), MA-rootdevice(0x0)/Basic Information(0x28)/vendorId(0x2), MA-rootdevice(0x0)/Basic Information(0x28)/productId(0x4), */0x31/0x3
2023-0-0 19:47:49.880 DEBUG ExchangeManager sending id:52965/7163/1846426692 t:1/5 acked:71824238 reqAck:true payload: 15360115350124000037012402002403312504fcff1824020418181535012400003701240200240330240400182402001818153501240000370124020024033024040118350224003c25018403181818153501240000370124020024033024040218240200181815350124000037012402002403302404031824020218181535012400003701240200240328240402182502f1ff1818153501240000370124020024032824040418250200801818153501240000370124020024033124040318240214181818290424ff0118
2023-0-0 19:47:49.897 DEBUG MessageExchange onMessageReceived id:52965/7164/71824239 t:1/8 reqAck:true payload: 1528002801360215370024000024013024020018350124003c24010318181824ff0118
2023-0-0 19:47:49.898 DEBUG InteractionProtocol Received invoke request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52965: 0x0/0x30/0x0
2023-0-0 19:47:49.898 DEBUG InteractionProtocol Invoke armFailSafe
2023-0-0 19:47:49.899 DEBUG ExchangeManager sending id:52965/7164/1846426693 t:1/9 acked:71824239 reqAck:true payload: 152800360115350037002400002401302402011835012400002c01001818181824ff0118
2023-0-0 19:47:49.899 DEBUG MessageExchange onMessageReceived id:52965/7163/71824240 t:0/16 acked:1846426692 reqAck:false payload: 
2023-0-0 19:47:49.915 DEBUG MessageExchange onMessageReceived id:52965/7165/71824241 t:1/8 reqAck:true payload: 152800280136021537002400002401302402021835012400002c0102585824020418181824ff0118
2023-0-0 19:47:49.916 DEBUG InteractionProtocol Received invoke request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52965: 0x0/0x30/0x2
2023-0-0 19:47:49.916 DEBUG InteractionProtocol Invoke setRegulatoryConfig
2023-0-0 19:47:49.916 DEBUG ExchangeManager sending id:52965/7165/1846426694 t:1/9 acked:71824241 reqAck:true payload: 152800360115350037002400002401302402031835012400002c01001818181824ff0118
2023-0-0 19:47:49.917 DEBUG MessageExchange onMessageReceived id:52965/7164/71824242 t:0/16 acked:1846426693 reqAck:false payload: 
2023-0-0 19:47:49.942 DEBUG MessageExchange onMessageReceived id:52965/7166/71824243 t:1/8 reqAck:true payload: 1528002801360215370024000024013e24020218350124000218181824ff0118
2023-0-0 19:47:49.942 DEBUG InteractionProtocol Received invoke request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52965: 0x0/0x3e/0x2
2023-0-0 19:47:49.942 DEBUG InteractionProtocol Invoke requestCertChain
2023-0-0 19:47:49.943 DEBUG ExchangeManager sending id:52965/7166/1846426695 t:1/9 acked:71824243 reqAck:true payload: 1528003601153500370024000024013e2402031835013100d801308201d43082017aa00302010202083e6ce6509ad840cd300a06082a8648ce3d04030230303118301606035504030c0f4d617474657220546573742050414131143012060a2b0601040182a27c02010c04464646313020170d3231303632383134323334335a180f39393939313233313233353935395a30463118301606035504030c0f4d617474657220546573742050414931143012060a2b0601040182a27c02010c044646463131143012060a2b0601040182a27c02020c04383030303059301306072a8648ce3d020106082a8648ce3d0301070342000480ddf11b228f3e31f63bcf5798da14623aebbde82ef378eeadbfb18fe1abce31d08ed4b20604b6ccc6d9b5fab64e7de10cb74be017c9ec1516056d70f2cd0b22a366306430120603551d130101ff040830060101ff020100300e0603551d0f0101ff040403020106301d0603551d0e04160414af42b7094debd515ec6ecf33b81115225f325288301f0603551d230418301680146afd22771f511fecbf1641976710dcdc31a1717e300a06082a8648ce3d040302034800304502210096c9c8cf2e01886005d8f5bc72c07b75fd9a57695ac4911131138bea033ce50302202554943be57d53d6c475f7d23ebfcfc2036cd29ba6393ec7efad8714ab7182191818181824ff0118
2023-0-0 19:47:49.946 DEBUG MessageExchange onMessageReceived id:52965/7165/71824244 t:0/16 acked:1846426694 reqAck:false payload: 
2023-0-0 19:47:49.957 DEBUG MessageExchange onMessageReceived id:52965/7167/71824245 t:1/8 reqAck:true payload: 1528002801360215370024000024013e24020218350124000118181824ff0118
2023-0-0 19:47:49.957 DEBUG InteractionProtocol Received invoke request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52965: 0x0/0x3e/0x2
2023-0-0 19:47:49.957 DEBUG InteractionProtocol Invoke requestCertChain
2023-0-0 19:47:49.958 DEBUG ExchangeManager sending id:52965/7167/1846426696 t:1/9 acked:71824245 reqAck:true payload: 1528003601153500370024000024013e2402031835013100ec01308201e83082018fa0030201020208143c9d1689f498f0300a06082a8648ce3d04030230463118301606035504030c0f4d617474657220546573742050414931143012060a2b0601040182a27c02010c044646463131143012060a2b0601040182a27c02020c04383030303020170d3231303632383134323334335a180f39393939313233313233353935395a304b311d301b06035504030c144d6174746572205465737420444143203030303731143012060a2b0601040182a27c02010c044646463131143012060a2b0601040182a27c02020c04383030303059301306072a8648ce3d020106082a8648ce3d0301070342000462e2b6e1baff8d74a6fd8216c4cb67a3363a31e691492792e61aee610261481396725ef95e142686ba98f339b0ff65bc338bec7b9e8be0bdf3b2774982476220a360305e300c0603551d130101ff04023000300e0603551d0f0101ff040403020780301d0603551d0e04160414ee95ad96983a9ea95bcd2b00dc5e671727690383301f0603551d23041830168014af42b7094debd515ec6ecf33b81115225f325288300a06082a8648ce3d040302034700304402202f51cf53bf7777df7318094b9db595eebf2fa881c8c572847b1e689ece654264022029782708ee6b32c7f08ff63dbe618e9a580bb14c183bc288777adf9e2dcff5e61818181824ff0118
2023-0-0 19:47:49.958 DEBUG MessageExchange onMessageReceived id:52965/7166/71824246 t:0/16 acked:1846426695 reqAck:false payload: 
2023-0-0 19:47:49.972 DEBUG MessageExchange onMessageReceived id:52965/7168/71824247 t:1/8 reqAck:true payload: 1528002801360215370024000024013e24020018350130002007cb328978c30afe5b9d65f516309d088e88ff64fa61c56149ce6807119609ec18181824ff0118
2023-0-0 19:47:49.972 DEBUG InteractionProtocol Received invoke request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52965: 0x0/0x3e/0x0
2023-0-0 19:47:49.972 DEBUG InteractionProtocol Invoke requestAttestation
2023-0-0 19:47:49.975 DEBUG ExchangeManager sending id:52965/7168/1846426697 t:1/9 acked:71824247 reqAck:true payload: 1528003601153500370024000024013e240201183501310049021531011d023082021906092a864886f70d010702a082020a30820206020103310d300b06096086480165030402013082017106092a864886f70d010701a08201620482015e152400012501f1ff3602050080050180050280050380050480050580050680050780050880050980050a80050b80050c80050d80050e80050f80051080051180051280051380051480051580051680051780051880051980051a80051b80051c80051d80051e80051f80052080052180052280052380052480052580052680052780052880052980052a80052b80052c80052d80052e80052f80053080053180053280053380053480053580053680053780053880053980053a80053b80053c80053d80053e80053f80054080054180054280054380054480054580054680054780054880054980054a80054b80054c80054d80054e80054f80055080055180055280055380055480055580055680055780055880055980055a80055b80055c80055d80055e80055f80056080056180056280056380182403162c04135a494732303134325a423333303030332d32342405002406002507942624080018317d307b020103801462fa823359acfaa9963e1cfa140addf504f37160300b0609608648016503040201300a06082a8648ce3d04030204473045022024e5d1f47a7d7b0d206a26ef699b7c9757b72d469089de3192e678c745e7f60c022100f8aa2fa711fcb79b97e397ceda667bae464e2bd3ffdfc3cced7aa8ca5f4c1a7c30022007cb328978c30afe5b9d65f516309d088e88ff64fa61c56149ce6807119609ec24030018300140663e58f5c371105c2bd16356165bc08d0144cbbc04e4034d9cdaecd8af4a899befa08613a0ab26cb5e86e2cb095d248dfbf455e8b48f07090637289c9972c6e01818181824ff0118
2023-0-0 19:47:49.975 DEBUG MessageExchange onMessageReceived id:52965/7167/71824248 t:0/16 acked:1846426696 reqAck:false payload: 
2023-0-0 19:47:50.021 DEBUG MessageExchange onMessageReceived id:52965/7169/71824249 t:1/8 reqAck:true payload: 1528002801360215370024000024013024020018350124003c24010818181824ff0118
2023-0-0 19:47:50.021 DEBUG InteractionProtocol Received invoke request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52965: 0x0/0x30/0x0
2023-0-0 19:47:50.021 DEBUG InteractionProtocol Invoke armFailSafe
2023-0-0 19:47:50.022 DEBUG ExchangeManager sending id:52965/7169/1846426698 t:1/9 acked:71824249 reqAck:true payload: 152800360115350037002400002401302402011835012400002c01001818181824ff0118
2023-0-0 19:47:50.022 DEBUG MessageExchange onMessageReceived id:52965/7168/71824250 t:0/16 acked:1846426697 reqAck:false payload: 
2023-0-0 19:47:50.034 DEBUG MessageExchange onMessageReceived id:52965/7169/71824251 t:0/16 acked:1846426698 reqAck:false payload: 
2023-0-0 19:47:51.377 DEBUG MessageExchange onMessageReceived id:52965/7170/71824252 t:1/8 reqAck:true payload: 1528002801360215370024000024013e240204183501300020d8ddedb24f533f0efbf84e904390d30acb2d0623927f40e84be7dd41d945d5b218181824ff0118
2023-0-0 19:47:51.377 DEBUG InteractionProtocol Received invoke request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52965: 0x0/0x3e/0x4
2023-0-0 19:47:51.377 DEBUG InteractionProtocol Invoke requestCertSigning
2023-0-0 19:47:51.379 DEBUG ExchangeManager sending id:52965/7170/1846426699 t:1/9 acked:71824252 reqAck:true payload: 1528003601153500370024000024013e2402051835013000f4153001cc3081c93070020100300e310c300a060355040a0c034353523059301306072a8648ce3d020106082a8648ce3d030107034200046373cd030e4b6945b43cd0acf15d071fae8c01c72e9f94ccc2a70e66f86505ee3c38ac765994966d5a43f57ed095e36525c883d6a3a66ee8e470704f9d72340fa000300a06082a8648ce3d0403020349003046022100c9ca5638c4fd9edc64a75d0a67e12d6c7a7e044672bad53a3a19227ad1ffa30b0221009c7501aae1543f13da6fe238c371d7cc0ebd35e4349d13e93fbcccb67f0591f0300220d8ddedb24f533f0efbf84e904390d30acb2d0623927f40e84be7dd41d945d5b218300140814f6face265a6a6b0761b8972415a4f99bd5b1f1e70c77a0d422057191ab47b5ab0125c087727d745cd6ce6bbe9e07e38a322c88f8c57814651b2a8a19d8c331818181824ff0118
2023-0-0 19:47:51.446 DEBUG MessageExchange onMessageReceived id:52965/7171/71824253 t:1/8 reqAck:true payload: 1528002801360215370024000024013e24020b1835013000fb15300101002402013703271447345acbc31be2c2241502182604a24f012b26052283e22c3706271447345acbc31be2c224150218240701240801300941047f7bd2a28eaa181abd4118140037c6354c834cf74909dc138f9db212e609d0eeec47af344f0701c395e3ef4b5a5454c7664ddb3d3c0f8b08920f9580b31c7e7a370a35012901182402603004144b1c9982934b8bd2e6b3c407d3611db976e50e733005144b1c9982934b8bd2e6b3c407d3611db976e50e7318300b40929938cde88683fd11439c94c11c6b37d5dccd3dda39f9507e2d96edd2420f64969e537c7f58faf900a80ed7ad472353719c30eacc07b515a3e1ea73c788eb7c1818181824ff0118
2023-0-0 19:47:51.446 DEBUG InteractionProtocol Received invoke request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52965: 0x0/0x3e/0xb
2023-0-0 19:47:51.446 DEBUG InteractionProtocol Invoke addRootCert
2023-0-0 19:47:51.447 DEBUG ExchangeManager sending id:52965/7171/1846426700 t:1/9 acked:71824253 reqAck:true payload: 1528003601153501370024000024013e24020b1835012400001818181824ff0118
2023-0-0 19:47:51.447 DEBUG MessageExchange onMessageReceived id:52965/7170/71824254 t:0/16 acked:1846426699 reqAck:false payload: 
2023-0-0 19:47:51.459 DEBUG MessageExchange onMessageReceived id:52965/7172/71824255 t:1/8 reqAck:true payload: 1528002801360215370024000024013e2402061835013000fe15300101012402013703271447345acbc31be2c224150218260457cc4d2b2605d7ff2e2d370624150226110a7900c618240701240801300941046373cd030e4b6945b43cd0acf15d071fae8c01c72e9f94ccc2a70e66f86505ee3c38ac765994966d5a43f57ed095e36525c883d6a3a66ee8e470704f9d72340f370a350128011824020136030402040118300414c846526776ec2d39977222f1198100153aefd53c3005144b1c9982934b8bd2e6b3c407d3611db976e50e7318300b407ecdb456ce1ce758df566cc57e1ca4e5b651a919abdda8a36513cd8b24956c41f972141226a770ae529d396510a907afc014b7cae16f5177fd3e74c7b22c626e183001003002108c0a1d163110ea191b9b5eb55162c8cb270327062caf9b1a95272504491318181824ff0118
2023-0-0 19:47:51.460 DEBUG InteractionProtocol Received invoke request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52965: 0x0/0x3e/0x6
2023-0-0 19:47:51.460 DEBUG InteractionProtocol Invoke addOperationalCert
addOperationalCert success
2023-0-0 19:47:51.467 DEBUG ExchangeManager sending id:52965/7172/1846426701 t:1/9 acked:71824255 reqAck:true payload: 1528003601153500370024000024013e2402081835012400002401011818181824ff0118
2023-0-0 19:47:51.468 ERROR MdnsBroadcaster Error: send EHOSTUNREACH ff02::fb:5353
2023-0-0 19:47:51.469 DEBUG MessageExchange onMessageReceived id:52965/7171/71824256 t:0/16 acked:1846426700 reqAck:false payload: 
2023-0-0 19:47:51.491 DEBUG MessageExchange onMessageReceived id:52965/7172/71824257 t:0/16 acked:1846426701 reqAck:false payload: 
2023-0-0 19:47:51.890 DEBUG MessageExchange onMessageReceived id:0/7173/162373660 t:0/48 reqAck:true payload: 1530012038d582b0156ce621440db81f2c1d7a70c40875e115d695f7f6998e4e78213ea725020a293003203263f0cd07bd26851f726b408be1b2a3d6580b3dd453dd1d322b22e8040756603004410454e602ebfe00ecb4d860a231637ce67e4ee9ca6d360ca2c5f929f6bb83acfe8c2b28d1d78b34d6d86fe463a2622938e50aef69c887e5e3460ba329bdb9fe725a35052501881325022c011818
2023-0-0 19:47:51.891 INFO CaseServer Case server: Received pairing request from udp://fe80::141c:e38b:5593:10e3%en0:62854
2023-0-0 19:47:51.893 DEBUG ExchangeManager sending id:0/7173/1846426702 t:0/49 acked:162373660 reqAck:true payload: 15300120c104ee49997d555762ce649ec914dc0f58b9d3d3f7de7ecf13c5b49638192bd22502e6ce30034104706191f8ca9881fd03e477903e5d221a92e1dcfc691966336e1088e613f2f71bb81088fc362d27e3874962bbfb5e5d41d5c9dda990b9e88f20ff7e951a23181c3104690196b23a795416fc2013cce386b61147fa527fe837983e9679e3d1d5a58c9d268b43363b3947917c87e90a65eb350ac397d0d0155337023f4808b0489f1c379e9118d8dd3894e12ef86428dc003633765978066374514163feac0781b051e8b1cbec81e964c5ec62f46b2ba39d530ac0228a832d7f02c29e4d6cb4c53f185d68070b01284756d628ee6e54054e8bfa67868f527478a279096a83efac1bbba3862a8f0f448840fd95cbd154449dcf547fe5095599d8fd666d126ba9cf2fbd7bb5d68e2e2e35fdcf539e327d39bbcd6d250b85ae14ae0bca6a4b6d2012d7a986f0e881c7d5e0776b1312d39e6b1fcd52029de93dfe89e764ca386e8af4d670aa5ed48357559b7b7abd04bab35b15f292af900e2b70d5e5a54355cfcd02550abf6852c74f81302e48280afb24ccaf931df179e3905b3080381f04709895de2c3eb5708adf23e8632e8bef42f206d1a6da71ad09c73975c1d3ee109df62d52cfd5f7fccb0f7c6527e57631af35052501881325022c011818
2023-0-0 19:47:51.963 DEBUG MessageExchange onMessageReceived id:0/7173/162373661 t:0/50 acked:1846426702 reqAck:true payload: 1531015b01a37c89d5bdc6c7e4349a788e1418427ee8b9e456759543d1932835571ba907fa41c20349bfd096715bae973dc0935f527d6f818c242c164a2552e234ac82993fb7fc17c2ce02d977405bd187bd9f2147640d020feb0432eb94420c4d0f025ab9fde48f77b96b190dee67cea21eb3d2881aa435ab20cbf235a349ed9ba1d00570298d7a24931fe8176cb5d4b6f6f5073b0629c5e3ec8d17dff3593eb6c6e8b5033ede50e8788840dff8e2a1194d2139d8b959ed97af940f1c9d857b580d9068dd901f93e0a9c32ca1849f7e44c1f20b7438d17d1d764445b1a0d4581bcb2618db67d34f3349c39374c5a088baa1f17abc6a1f8b0de411933f3c1f5da35bf00aa96fde82f91a6a9fd99291021a2475b31c779453ad39b18a1bdf11f431cee095f8c8ad51d2d5262638e6ec0da70df926341c93426d3869c75142f35ee76a96ec1ac8bae36fd061f48b754f91feb01cf586571272db92f52a10f50e9818
2023-0-0 19:47:51.965 INFO CaseServer Case server: session 52966 created with udp://fe80::141c:e38b:5593:10e3%en0:62854
2023-0-0 19:47:51.965 DEBUG ExchangeManager sending id:0/7173/1846426703 t:0/64 acked:162373661 reqAck:true payload: 0000000000000000
2023-0-0 19:47:52.002 DEBUG MessageExchange onMessageReceived id:52966/7174/256531824 t:1/8 reqAck:true payload: 1528002801360215370024000024013024020418350118181824ff0118
2023-0-0 19:47:52.002 DEBUG InteractionProtocol Received invoke request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52966: 0x0/0x30/0x4
2023-0-0 19:47:52.002 DEBUG InteractionProtocol Invoke commissioningComplete
2023-0-0 19:47:52.003 INFO GeneralCommissioningClusterHandler Commissioning completed on fabric #2 as node #00000000C600790A.
2023-0-0 19:47:52.003 DEBUG ExchangeManager sending id:52966/7174/1846426704 t:1/9 acked:256531824 reqAck:true payload: 152800360115350037002400002401302402051835012400002c01001818181824ff0118
2023-0-0 19:47:52.003 DEBUG MessageExchange onMessageReceived id:0/7173/162373662 t:0/16 acked:1846426703 reqAck:false payload: 
2023-0-0 19:47:52.012 DEBUG MessageExchange onMessageReceived id:52966/7174/256531825 t:0/16 acked:1846426704 reqAck:false payload: 
2023-0-0 19:47:52.043 DEBUG MessageExchange onMessageReceived id:52966/7175/256531826 t:1/2 reqAck:true payload: 1536001724020024033e2404011818290324ff0118
2023-0-0 19:47:52.043 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52966: MA-rootdevice(0x0)/Operational Credentials(0x3e)/fabrics(0x1)
2023-0-0 19:47:52.043 DEBUG ExchangeManager sending id:52966/7175/1846426705 t:1/5 acked:256531826 reqAck:true payload: 153601153501240001370124020024033e24040118360215300141047f7bd2a28eaa181abd4118140037c6354c834cf74909dc138f9db212e609d0eeec47af344f0701c395e3ef4b5a5454c7664ddb3d3c0f8b08920f9580b31c7e7a2502491324030226040a7900c62c050024fe011818181818290424ff0118
2023-0-0 19:47:52.057 DEBUG MessageExchange onMessageReceived id:52966/7175/256531827 t:0/16 acked:1846426705 reqAck:false payload: 
2023-0-0 19:47:52.104 DEBUG MessageExchange onMessageReceived id:52966/7176/256531828 t:1/2 reqAck:true payload: 1536001724020024031d2404031818290324ff0118
2023-0-0 19:47:52.104 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52966: MA-rootdevice(0x0)/Descriptor(0x1d)/partsList(0x3)
2023-0-0 19:47:52.105 DEBUG ExchangeManager sending id:52966/7176/1846426706 t:1/5 acked:256531828 reqAck:true payload: 153601153501240001370124020024031d240403183602040118181818290424ff0118
2023-0-0 19:47:52.115 DEBUG MessageExchange onMessageReceived id:52966/7176/256531829 t:0/16 acked:1846426706 reqAck:false payload: 
2023-0-0 19:47:52.115 DEBUG MessageExchange onMessageReceived id:52966/7177/256531830 t:1/2 reqAck:true payload: 1536001724020124031d2404001818290324ff0118
2023-0-0 19:47:52.115 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52966: MA-onofflight(0x1)/Descriptor(0x1d)/deviceTypeList(0x0)
2023-0-0 19:47:52.116 DEBUG ExchangeManager sending id:52966/7177/1846426707 t:1/5 acked:256531830 reqAck:true payload: 153601153501240000370124020124031d24040018360215250000012401011818181818290424ff0118
2023-0-0 19:47:52.416 DEBUG ExchangeManager sending id:10506/7177/1846426707 t:1/5 acked:256531830 reqAck:true payload: 153601153501240000370124020124031d24040018360215250000012401011818181818290424ff0118
2023-0-0 19:47:52.616 DEBUG MessageExchange onMessageReceived id:52966/7177/256531831 t:0/16 acked:1846426707 reqAck:false payload: 
2023-0-0 19:47:52.616 DEBUG MessageExchange onMessageReceived id:52966/7178/256531832 t:1/2 reqAck:true payload: 1536001724020124031d2404031818290324ff0118
2023-0-0 19:47:52.617 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52966: MA-onofflight(0x1)/Descriptor(0x1d)/partsList(0x3)
2023-0-0 19:47:52.617 DEBUG ExchangeManager sending id:52966/7178/1846426708 t:1/5 acked:256531832 reqAck:true payload: 153601153501240000370124020124031d24040318360218181818290424ff0118
2023-0-0 19:47:52.835 DEBUG MessageExchange onMessageReceived id:52966/7178/256531832 t:1/2 reqAck:true payload: 1536001724020124031d2404031818290324ff0118
2023-0-0 19:47:52.835 DEBUG ExchangeManager sending id:10506/7178/1846426708 t:1/5 acked:256531832 reqAck:true payload: 153601153501240000370124020124031d24040318360218181818290424ff0118
2023-0-0 19:47:52.835 DEBUG MessageExchange onMessageReceived id:52966/7177/256531833 t:0/16 acked:1846426707 reqAck:false payload: 
2023-0-0 19:47:52.836 DEBUG MessageExchange onMessageReceived id:52966/7178/256531834 t:0/16 acked:1846426708 reqAck:false payload: 
2023-0-0 19:47:52.836 DEBUG MessageExchange onMessageReceived id:52966/7179/256531835 t:1/2 reqAck:true payload: 1536001724020124031d2404011818290324ff0118
2023-0-0 19:47:52.836 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52966: MA-onofflight(0x1)/Descriptor(0x1d)/serverList(0x1)
2023-0-0 19:47:52.836 DEBUG ExchangeManager sending id:52966/7179/1846426709 t:1/5 acked:256531835 reqAck:true payload: 153601153501240001370124020124031d2404011836020406041d18181818290424ff0118
2023-0-0 19:47:52.843 DEBUG MessageExchange onMessageReceived id:52966/7178/256531836 t:0/16 acked:1846426708 reqAck:false payload: 
2023-0-0 19:47:52.850 DEBUG MessageExchange onMessageReceived id:52966/7179/256531837 t:0/16 acked:1846426709 reqAck:false payload: 
2023-0-0 19:47:53.273 DEBUG MessageExchange onMessageReceived id:52966/7180/256531838 t:1/2 reqAck:true payload: 153600172402012403062504fcff1818290324ff0118
2023-0-0 19:47:53.273 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52966: MA-onofflight(0x1)/On/Off(0x6)/featureMap(0xfffc)
2023-0-0 19:47:53.273 DEBUG ExchangeManager sending id:52966/7180/1846426710 t:1/5 acked:256531838 reqAck:true payload: 15360115350124000037012402012403062504fcff18240200181818290424ff0118
2023-0-0 19:47:53.574 DEBUG ExchangeManager sending id:10506/7180/1846426710 t:1/5 acked:256531838 reqAck:true payload: 15360115350124000037012402012403062504fcff18240200181818290424ff0118
2023-0-0 19:47:53.792 DEBUG MessageExchange onMessageReceived id:52966/7180/256531838 t:1/2 reqAck:true payload: 153600172402012403062504fcff1818290324ff0118
2023-0-0 19:47:53.792 DEBUG ExchangeManager sending id:10506/7180/1846426710 t:1/5 acked:256531838 reqAck:true payload: 15360115350124000037012402012403062504fcff18240200181818290424ff0118
2023-0-0 19:47:53.793 DEBUG MessageExchange onMessageReceived id:52966/7180/256531839 t:0/16 acked:1846426710 reqAck:false payload: 
2023-0-0 19:47:53.793 DEBUG MessageExchange onMessageReceived id:52966/7181/256531840 t:1/2 reqAck:true payload: 1536001724020024033e2404011818280324ff0118
2023-0-0 19:47:53.793 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52966: MA-rootdevice(0x0)/Operational Credentials(0x3e)/fabrics(0x1)
2023-0-0 19:47:53.794 DEBUG ExchangeManager sending id:52966/7181/1846426711 t:1/5 acked:256531840 reqAck:true payload: 153601153501240001370124020024033e24040118360215300141047f7bd2a28eaa181abd4118140037c6354c834cf74909dc138f9db212e609d0eeec47af344f0701c395e3ef4b5a5454c7664ddb3d3c0f8b08920f9580b31c7e7a2502491324030226040a7900c62c050024fe011818181818290424ff0118
2023-0-0 19:47:54.052 DEBUG MessageExchange onMessageReceived id:52966/7181/256531840 t:1/2 reqAck:true payload: 1536001724020024033e2404011818280324ff0118
2023-0-0 19:47:54.052 DEBUG ExchangeManager sending id:10506/7181/1846426711 t:1/5 acked:256531840 reqAck:true payload: 153601153501240001370124020024033e24040118360215300141047f7bd2a28eaa181abd4118140037c6354c834cf74909dc138f9db212e609d0eeec47af344f0701c395e3ef4b5a5454c7664ddb3d3c0f8b08920f9580b31c7e7a2502491324030226040a7900c62c050024fe011818181818290424ff0118
2023-0-0 19:47:54.056 DEBUG MessageExchange onMessageReceived id:52966/7180/256531841 t:0/16 acked:1846426710 reqAck:false payload: 
2023-0-0 19:47:54.056 DEBUG MessageExchange onMessageReceived id:52966/7180/256531842 t:0/16 acked:1846426710 reqAck:false payload: 
2023-0-0 19:47:54.061 DEBUG MessageExchange onMessageReceived id:52966/7181/256531843 t:0/16 acked:1846426711 reqAck:false payload: 
2023-0-0 19:47:54.065 DEBUG MessageExchange onMessageReceived id:52966/7181/256531844 t:0/16 acked:1846426711 reqAck:false payload: 
2023-0-0 19:47:54.576 DEBUG MessageExchange onMessageReceived id:52966/7182/256531845 t:1/10 reqAck:true payload: 152500102724ff0118
2023-0-0 19:47:54.577 DEBUG InteractionProtocol Received timed request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52966
2023-0-0 19:47:54.577 DEBUG ExchangeManager sending id:52966/7182/1846426712 t:1/1 acked:256531845 reqAck:true payload: 1524000024ff0118
2023-0-0 19:47:54.578 DEBUG MessageExchange onMessageReceived id:52966/7182/256531845 t:1/10 reqAck:true payload: 152500102724ff0118
2023-0-0 19:47:54.578 DEBUG ExchangeManager sending id:10506/7182/1846426712 t:1/1 acked:256531845 reqAck:true payload: 1524000024ff0118
2023-0-0 19:47:54.589 DEBUG MessageExchange onMessageReceived id:52966/7182/256531846 t:1/8 acked:1846426712 reqAck:true payload: 1528002901360215370024000024013c24020018350125002c013001613629773174310bf0d63874f3a7530c0e791d5440f35d6a16a63a841edb158891040360afe09a0d830500ed3ff0ba16eef707765bccb74f301fc5526d9e3a1adcfc1c7ab2db79541a7a0294a9527f80fe8ee543139a22d7c0aeb9efdc622ffee0e2250296092503e8033004200f3b96b8171e12482eb6a30668f32205af44a601eb9f5962e574f43989e22f3f18181824ff0118
2023-0-0 19:47:54.590 DEBUG InteractionProtocol Received invoke request from udp://fe80::141c:e38b:5593:10e3%en0:62854 on session secure/52966: 0x0/0x3c/0x0
2023-0-0 19:47:54.590 DEBUG InteractionProtocol Invoke openCommissioningWindow
2023-0-0 19:47:54.598 DEBUG ExchangeManager sending id:52966/7182/1846426713 t:1/9 acked:256531846 reqAck:true payload: 1528003601153500370024000024013c2402001835011818181824ff0118
2023-0-0 19:47:54.599 ERROR MdnsBroadcaster Error: send EHOSTUNREACH ff02::fb:5353
2023-0-0 19:47:54.600 DEBUG MessageExchange onMessageReceived id:52966/7182/256531847 t:0/16 acked:1846426712 reqAck:false payload: 
/Users/ingof/Dev/GitHub/node-matter/build/matter/common/MessageExchange.js:70
                    throw new Error(`Incorrect ack received. Expected ${sentMessageIdToAck}, received: ${ackedMessageId}`);
                          ^

Error: Incorrect ack received. Expected 1846426713, received: 1846426712
    at MessageExchange.<anonymous> (/Users/ingof/Dev/GitHub/node-matter/build/matter/common/MessageExchange.js:70:27)
    at Generator.next (<anonymous>)
    at /Users/ingof/Dev/GitHub/node-matter/build/matter/common/MessageExchange.js:8:71
    at new Promise (<anonymous>)
    at __awaiter (/Users/ingof/Dev/GitHub/node-matter/build/matter/common/MessageExchange.js:4:12)
    at MessageExchange.onMessageReceived (/Users/ingof/Dev/GitHub/node-matter/build/matter/common/MessageExchange.js:52:16)
    at ExchangeManager.<anonymous> (/Users/ingof/Dev/GitHub/node-matter/build/matter/common/ExchangeManager.js:81:26)
    at Generator.next (<anonymous>)
    at /Users/ingof/Dev/GitHub/node-matter/build/matter/common/ExchangeManager.js:8:71
    at new Promise (<anonymous>)

@Apollon77
Copy link
Collaborator Author

Apollon77 commented Jan 8, 2023 •
edited
Loading

Hhmm ... ok second try with WLAN ... same as at the beginning :-(

Ok wil multiple more tries I alwys end between the two error scenaries

@Apollon77 Apollon77 changed the title iOS 16.2 QR Codde pairing issue iOS 16.2 QR Code pairing issue Jan 8, 2023
@Apollon77
Copy link
Collaborator Author

Apollon77 commented Jan 8, 2023 •
edited
Loading

Oookkkk ... Then I tried with Alexa App and here pairing works :-)) BBUTTT when I delete the device in alexa then I get the same issue again ...

2023-0-0 19:59:22.198 DEBUG MessageExchange onMessageReceived id:59107/40618/218140403 t:1/10 reqAck:true payload: 152500102724ff0118
2023-0-0 19:59:22.198 DEBUG InteractionProtocol Received timed request from udp://192.168.178.34:5541 on session secure/59107
2023-0-0 19:59:22.198 DEBUG ExchangeManager sending id:59107/40618/47216721 t:1/1 acked:218140403 reqAck:true payload: 1524000024ff0118
2023-0-0 19:59:22.199 DEBUG MessageExchange onMessageReceived id:59109/38330/183001635 t:1/10 reqAck:true payload: 152500102724ff0118
2023-0-0 19:59:22.199 DEBUG InteractionProtocol Received timed request from udp://192.168.178.181:5541 on session secure/59109
2023-0-0 19:59:22.199 DEBUG ExchangeManager sending id:59109/38330/47216722 t:1/1 acked:183001635 reqAck:true payload: 1524000024ff0118
2023-0-0 19:59:22.199 DEBUG MessageExchange onMessageReceived id:59108/56191/30810589 t:1/10 reqAck:true payload: 152500102724ff0118
2023-0-0 19:59:22.200 DEBUG InteractionProtocol Received timed request from udp://192.168.178.36:5541 on session secure/59108
2023-0-0 19:59:22.200 DEBUG ExchangeManager sending id:59108/56191/47216723 t:1/1 acked:30810589 reqAck:true payload: 1524000024ff0118
2023-0-0 19:59:22.209 DEBUG MessageExchange onMessageReceived id:59107/40618/218140404 t:1/8 acked:47216721 reqAck:true payload: 1528002901360215370024000024013e24020a18350124000018181824ff0118
2023-0-0 19:59:22.210 DEBUG InteractionProtocol Received invoke request from udp://192.168.178.34:5541 on session secure/59107: 0x0/0x3e/0xa
2023-0-0 19:59:22.210 DEBUG InteractionProtocol Invoke removeFabric
2023-0-0 19:59:22.210 DEBUG OperationalCredentialsHandler removeFabric: fabric 0 not found
2023-0-0 19:59:22.211 DEBUG ExchangeManager sending id:59107/40618/47216724 t:1/9 acked:218140404 reqAck:true payload: 1528003601153500370024000024013e24020818350124000b1818181824ff0118
2023-0-0 19:59:22.211 DEBUG MessageExchange onMessageReceived id:59109/38330/183001636 t:1/8 acked:47216722 reqAck:true payload: 1528002901360215370024000024013e24020a18350124000018181824ff0118
2023-0-0 19:59:22.211 DEBUG InteractionProtocol Received invoke request from udp://192.168.178.181:5541 on session secure/59109: 0x0/0x3e/0xa
2023-0-0 19:59:22.212 DEBUG InteractionProtocol Invoke removeFabric
2023-0-0 19:59:22.212 DEBUG OperationalCredentialsHandler removeFabric: fabric 0 not found
2023-0-0 19:59:22.212 DEBUG ExchangeManager sending id:59109/38330/47216725 t:1/9 acked:183001636 reqAck:true payload: 1528003601153500370024000024013e24020818350124000b1818181824ff0118
2023-0-0 19:59:22.212 DEBUG MessageExchange onMessageReceived id:59108/56191/30810590 t:1/8 acked:47216723 reqAck:true payload: 1528002901360215370024000024013e24020a18350124000018181824ff0118
2023-0-0 19:59:22.212 DEBUG InteractionProtocol Received invoke request from udp://192.168.178.36:5541 on session secure/59108: 0x0/0x3e/0xa
2023-0-0 19:59:22.213 DEBUG InteractionProtocol Invoke removeFabric
2023-0-0 19:59:22.213 DEBUG OperationalCredentialsHandler removeFabric: fabric 0 not found
2023-0-0 19:59:22.213 DEBUG ExchangeManager sending id:59108/56191/47216726 t:1/9 acked:30810590 reqAck:true payload: 1528003601153500370024000024013e24020818350124000b1818181824ff0118
2023-0-0 19:59:22.222 DEBUG MessageExchange onMessageReceived id:59108/56191/30810591 t:0/16 acked:47216726 reqAck:false payload: 
2023-0-0 19:59:22.222 DEBUG MessageExchange onMessageReceived id:59107/40618/218140405 t:0/16 acked:47216724 reqAck:false payload: 
2023-0-0 19:59:22.226 DEBUG MessageExchange onMessageReceived id:59109/38330/183001637 t:0/16 acked:47216725 reqAck:false payload:

Maybe we have annissue in decoding??

@Apollon77
Copy link
Collaborator Author

I checked ... Alexa when deleting fabric and Apple when pairing send the exact same data:

1528002901360215370024000024013e24020a18350124000018181824ff0118

@Apollon77 Apollon77 mentioned this issue Jan 8, 2023
Closed
@mfucci
Copy link
Owner

mfucci commented Jan 8, 2023

Hi Ingo,

1_ Original log trace: the problem is at this line:
2023-0-0 17:56:51.028 DEBUG InteractionProtocol Received read request from udp://fe80::141c:e38b:5593:10e3%en0:60357 on session secure/32461: MA-rootdevice(0x0)/Operational Credentials(0x3e)/currentFabricIndex(0x5)

On my side iOs never requested this characteristic so the logic to return the right value is not implemented.
Also, this characteristic should returns a different value depending on the secure channel used to access it so this requires supporting fabric-scoped values.

I don't know why Home on my iPhone is not requesting this characteristic, there seems to be no way to check the version for it... (I am on iOS 16.2).

2 _ Original log trace: ERROR line
The subsequent ERROR "Invalid value: 0 is below the minimum, 1" is because iOS tries to reset the device by calling removeFabric which is not implemented. A fabricId has a minimum value of 1, but 0 is used in many commands to indicates NO_FABRIC. We haven't described that correctly in the cluster specifications.

3 _ 2nd log trace: "ERROR MdnsBroadcaster Error: send EHOSTUNREACH ff02::fb:5353"
This seems to be an IPv6 broadcast issue. Probably with no consequences might be good to address it to avoid polluting the logs

4 _ 2nd log trace: "Error: Incorrect ack received. Expected 1846426713, received: 1846426712"
iOs sent messages 1846426712 Ack twice in two different messages which is not supported.
I wrote the message exchange logic before the specs were released so the business logic is probably not accurate. I saw in the code that a stack of messages to acked is kept, while I only keep the last one.
Some packets seemed to have been lost in the exchange (as you said, you were using WLAN) and retransmitted, which created this out-of-order issue. This should be a transient issue, you should probably try again

5 _ 3rd log trace: yes, removeFabric is not implemented

Can you split this issue into 5 separate issues for tracking them?

  1. currentFabricIndex attribute not implemented, crashing iOS
  2. Incorrect cluster specifications for fabricId, when 0 is allowed
  3. EHOSTUNREACH in MdnsBroadcaster
  4. Incorrect message exchange logic
  5. removeFabric command is not implemented

I think only nb 1 is blocking for you to be able to pair node-matter with iOS

@Apollon77
Copy link
Collaborator Author

Good morning,

Yes I will split up the issue. Thank you for all the insights.

I also have iOS 16.2. and it happened with HomePod online and also without.

@Apollon77
Copy link
Collaborator Author

For removeFabric there is no case of "id 0 is allowed" defined in the specs, and as said: when I delete the device in Alexa App then the same case happens too and also Id 0 is sent ... and there is no such read request before in my logs.

@mfucci
Copy link
Owner

mfucci commented Jan 9, 2023

Point 2: correction, it is actually FabricIndex and not FabricId used in this method.
Spec 7.5.2: "A fabric-index of 0 (zero) or null SHALL indicate that there is no fabric"
That will require more digging to understand what point is wrong in the spec or if an incorrect message before trick the sender to send an index of 0...

This was referenced Jan 9, 2023
Closed
Open
Closed
@Apollon77
Copy link
Collaborator Author

1.) #183
2.) Lets wait if #1 fixes that ... I would assume it
3.) #184
4.) fixed by #182
5.) #185

@mfucci
Copy link
Owner

mfucci commented Jan 10, 2023

Closing this since this has been split into different issues

@mfucci mfucci closed this as completed Jan 10, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@mfucci @Apollon77