connectedhomeip
connectedhomeip copied to clipboard
project-chip
[Documentation] Get help for network matter with HomeKit
Documentation issues
I'm using matter to network our modules with Apple HomeKit APP，but it's failed, I don't know how to proceed.
this is my questions:
1. Can I use the test certificate to access Home APP through Matter protocol?
2. What are the steps for connecting matter protocol with Apple home APP?
3. The IOS system has released version 16.1. Is the Matter component used v1.0-branch?
4. Home APP shows the lighting bulb has no responds, which reasons can cause this phenomenon?
Platform
No response
Anything else?
I am having the same issue. I am thinking it's a commissioning issue but cannot be sure.
I am having the same issue. I am thinking it's a commissioning issue but cannot be sure.
Do you have any ideas?
chip[ZCL] Commissioning complete chip[DL] Long dispatch time: 234 ms, for event type 32781 chip[IN] Received a duplicate message with MessageCounter:117382925 on exchange 37755r chip[EM] >>> [E:37755r M:117382925] (S) Msg RX from 1:61F81323C6104D18 [2BF8] --- Type 0001:08 (IM:InvokeCommandRequest) chip[EM] Found matching exchange: 37755r, Delegate: (nil) chip[EM] Forcing tx of solitary ack for duplicate MessageCounter:117382925 on exchange 37755r chip[EM] <<< [E:37755r M:129845032 (Ack:117382925)] (S) Msg TX to 1:61F81323C6104D18 [2BF8] --- Type 0000:10 (SecureChannel:Stchip[IN] (S) Sending msg 129845032 on secure session with LSID: 6155 chip[EM] >>> [E:37755r M:117382926 (Ack:129845031)] (S) Msg RX from 1:61F81323C6104D18 [2BF8] --- Type 0000:10 (SecureChannel:chip[EM] Found matching exchange: 37755r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:129845031 from Retrans Table on exchange 37755r chip[DL] StartAdvertising... chip[DL] BLE flag = 181ba chip[DL] BLE ADVCreate... chip[DL] BLE ADVCreate ret= 0. adv_actv_idx = 0 chip[EM] >>>ble:I(61842):[gapm_cmp_evt_handler]actv_idx:0 conidx:0,operation:0xa0,status:0x0 chip[DL] cmd:1 idx:0 status:0
[E:37756r M:117382927] (S) Msg RX from 1:61F81323C6104D18 [2BF8] --- Type 0001:02 (IM:ReadRequest) chip[EM] Handling via exchange: 37756r, Delegate: 0x30063b04 chip[IM] Received Read request chip[DMG] IM RH moving to [GeneratingReports] chip[DMG] Building Reports for ReadHandler with LastReportGeneration = 4294967293 DirtyGeneration = 0 chip[DMG] RE:Run Cluster 3e, Attribute 1 is dirty chip[DMG] Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_0001 (expanded=0) chip[DMG] <RE> Sending report (payload has 151 bytes)... chip[EM] <<< [E:37756r M:129845033 (Ack:117382927)] (S) Msg TX to 1:61F81323C6104D18 [2BF8] --- Type 0001:05 (IM:ReportData) chip[IN] (S) Sending msg 129845033 on secure session with LSID: 6155 chip[DMG] <RE> OnReportConfirm: NumReports = 0 chip[DMG] <RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages chip[DMG] IM RH moving to [AwaitingDestruction] chip[DMG] All ReadHandler-s are clean, clear GlobalDirtySet chip[EM] >>> [E:37756r M:117382928 (Ack:129845033)] (S) Msg RX from 1:61F81323C6104D18 [2BF8] --- Type 0000:10 (SecureChannel:chip[EM] Found matching exchange: 37756r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:129845033 from Retrans Table on exchange 37756r chip[EM] >>> [E:37757r M:117382929] (S) Msg RX from 1:61F81323C6104D18 [2BF8] --- Type 0001:02 (IM:ReadRequest) chip[EM] Handling via exchange: 37757r, Delegate: 0x30063b04 chip[IM] Received Read request chip[DMG] IM RH moving to [GeneratingReports] chip[DMG] Building Reports for ReadHandler with LastReportGeneration = 4294967293 DirtyGeneration = 0 chip[DMG] RE:Run Cluster 1d, Attribute 3 is dirty chip[DMG] Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0003 (expanded=0) chip[DMG] <RE> Sending report (payload has 64 bytes)... chip[EM] <<< [E:37757r M:129845034 (Ack:117382929)] (S) Msg TX to 1:61F81323C6104D18 [2BF8] --- Type 0001:05 (IM:ReportData) chip[IN] (S) Sending msg 129845034 on secure session with LSID: 6155 chip[DMG] <RE> OnReportConfirm: NumReports = 0 chip[DMG] <RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages chip[DMG] IM RH moving to [AwaitingDestruction] chip[DMG] All ReadHandler-s are clean, clear GlobalDirtySet chip[EM] >>> [E:37757r M:117382930 (Ack:129845034)] (S) Msg RX from 1:61F81323C6104D18 [2BF8] --- Type 0000:10 (SecureChannel:chip[EM] Found matching exchange: 37757r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:129845034 from Retrans Table on exchange 37757r chip[EM] >>> [E:37758r M:117382931] (S) Msg RX from 1:61F81323C6104D18 [2BF8] --- Type 0001:02 (IM:ReadRequest) chip[EM] Handling via exchange: 37758r, Delegate: 0x30063b04 chip[IM] Received Read request chip[DMG] IM RH moving to [GeneratingReports] chip[DMG] Building Reports for ReadHandler with LastReportGeneration = 4294967293 DirtyGeneration = 0 chip[DMG] RE:Run Cluster 1d, Attribute 0 is dirty chip[DMG] Reading attribute: Cluster=0x0000_001D Endpoint=1 AttributeId=0x0000_0000 (expanded=0) chip[DMG] <RE> Sending report (payload has 71 bytes)... chip[EM] <<< [E:37758r M:129845035 (Ack:117382931)] (S) Msg TX to 1:61F81323C6104D18 [2BF8] --- Type 0001:05 (IM:ReportData) chip[IN] (S) Sending msg 129845035 on secure session with LSID: 6155 chip[DMG] <RE> OnReportConfirm: NumReports = 0 chip[DMG] <RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages chip[DMG] IM RH moving to [AwaitingDestruction] chip[DMG] All ReadHandler-s are clean, clear GlobalDirtySet chip[EM] >>> [E:37758r M:117382932 (Ack:129845035)] (S) Msg RX from 1:61F81323C6104D18 [2BF8] --- Type 0000:10 (SecureChannel:chip[EM] Found matching exchange: 37758r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:129845035 from Retrans Table on exchange 37758r chip[EM] >>> [E:37759r M:117382933] (S) Msg RX from 1:61F81323C6104D18 [2BF8] --- Type 0001:02 (IM:ReadRequest) chip[EM] Handling via exchange: 37759r, Delegate: 0x30063b04 chip[IM] Received Read request chip[DMG] IM RH moving to [GeneratingReports] chip[DMG] Building Reports for ReadHandler with LastReportGeneration = 4294967293 DirtyGeneration = 0 chip[DMG] RE:Run Cluster 1d, Attribute 1 is dirty chip[DMG] Reading attribute: Cluster=0x0000_001D Endpoint=1 AttributeId=0x0000_0001 (expanded=0) chip[DMG] <RE> Sending report (payload has 148 bytes)... chip[EM] <<< [E:37759r M:129845036 (Ack:117382933)] (S) Msg TX to 1:61F81323C6104D18 [2BF8] --- Type 0001:05 (IM:ReportData) chip[IN] (S) Sending msg 129845036 on secure session with LSID: 6155 chip[DMG] <RE> OnReportConfirm: NumReports = 0 chip[DMG] <RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages chip[DMG] IM RH moving to [AwaitingDestruction] chip[DMG] All ReadHandler-s are clean, clear GlobalDirtySet chip[EM] >>> [E:37759r M:117382934 (Ack:129845036)] (S) Msg RX from 1:61F81323C6104D18 [2BF8] --- Type 0000:10 (SecureChannel:chip[EM] Found matching exchange: 37759r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:129845036 from Retrans Table on exchange 37759r chip[EM] >>> [E:37760r M:117382935] (S) Msg RX from 1:61F81323C6104D18 [2BF8] --- Type 0001:02 (IM:ReadRequest) chip[EM] Handling via exchange: 37760r, Delegate: 0x30063b04 chip[IM] Received Read request chip[DMG] IM RH moving to [GeneratingReports] chip[IN] Received a duplicate message with MessageCounter:117382935 on exchange 37760r chip[EM] >>> [E:37760r M:117382935] (S) Msg RX from 1:61F81323C6104D18 [2BF8] --- Type 0001:02 (IM:ReadRequest) chip[EM] Found matching exchange: 37760r, Delegate: 0x30067e4c chip[EM] Forcing tx of solitary ack for duplicate MessageCounter:117382935 on exchange 37760r chip[EM] <<< [E:37760r M:129845037 (Ack:117382935)] (S) Msg TX to 1:61F81323C6104D18 [2BF8] --- Type 0000:10 (SecureChannel:Stchip[IN] (S) Sending msg 129845037 on secure session with LSID: 6155 chip[DMG] Building Reports for ReadHandler with LastReportGeneration = 4294967293 DirtyGeneration = 0 chip[DMG] RE:Run Cluster 6, Attribute fffc is dirty chip[DMG] Reading attribute: Cluster=0x0000_0006 Endpoint=1 AttributeId=0x0000_FFFC (expanded=0) chip[DMG] <RE> Sending report (payload has 37 bytes)... chip[EM] <<< [E:37760r M:129845038 (Ack:117382935)] (S) Msg TX to 1:61F81323C6104D18 [2BF8] --- Type 0001:05 (IM:ReportData) chip[IN] (S) Sending msg 129845038 on secure session with LSID: 6155 chip[DMG] <RE> OnReportConfirm: NumReports = 0 chip[DMG] <RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages chip[DMG] IM RH moving to [AwaitingDestruction] chip[DMG] All ReadHandler-s are clean, clear GlobalDirtySet chip[EM] >>> [E:37760r M:117382936 (Ack:129845038)] (S) Msg RX from 1:61F81323C6104D18 [2BF8] --- Type 0000:10 (SecureChannel:chip[EM] Found matching exchange: 37760r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:129845038 from Retrans Table on exchange 37760r chip[EM] >>> [E:37761r M:117382937] (S) Msg RX from 1:61F81323C6104D18 [2BF8] --- Type 0001:02 (IM:ReadRequest) chip[EM] Handling via exchange: 37761r, Delegate: 0x30063b04 chip[IM] Received Read request chip[DMG] IM RH moving to [GeneratingReports] chip[DMG] Building Reports for ReadHandler with LastReportGeneration = 4294967293 DirtyGeneration = 0 chip[DMG] RE:Run Cluster 3e, Attribute 1 is dirty chip[DMG] Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_0001 (expanded=0) chip[DMG] <RE> Sending report (payload has 151 bytes)... chip[EM] <<< [E:37761r M:129845039 (Ack:117382937)] (S) Msg TX to 1:61F81323C6104D18 [2BF8] --- Type 0001:05 (IM:ReportData) chip[IN] (S) Sending msg 129845039 on secure session with LSID: 6155 chip[DMG] <RE> OnReportConfirm: NumReports = 0 chip[DMG] <RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages chip[DMG] IM RH moving to [AwaitingDestruction] chip[DMG] All ReadHandler-s are clean, clear GlobalDirtySet chip[EM] >>> [E:37761r M:117382938 (Ack:129845039)] (S) Msg RX from 1:61F81323C6104D18 [2BF8] --- Type 0000:10 (SecureChannel:chip[EM] Found matching exchange: 37761r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:129845039 from Retrans Table on exchange 37761r chip[EM] >>> [E:37762r M:117382939] (S) Msg RX from 1:61F81323C6104D18 [2BF8] --- Type 0001:0a (IM:TimedRequest) chip[EM] Handling via exchange: 37762r, Delegate: 0x30063b04 chip[DMG] Got Timed Request with timeout 10000: handler 0x30063f20 exchange 37762r chip[EM] <<< [E:37762r M:129845040 (Ack:117382939)] (S) Msg TX to 1:61F81323C6104D18 [2BF8] --- Type 0001:01 (IM:StatusResponschip[IN] (S) Sending msg 129845040 on secure session with LSID: 6155 chip[DMG] Timed Request time limit 0x0000000000011E4A: handler 0x30063f20 exchange 37762r chip[EM] >>> [E:37762r M:117382940 (Ack:129845040)] (S) Msg RX from 1:61F81323C6104D18 [2BF8] --- Type 0001:08 (IM:InvokeCommachip[EM] Found matching exchange: 37762r, Delegate: 0x30063f20 chip[EM] Rxd Ack; Removing MessageCounter:129845040 from Retrans Table on exchange 37762r chip[DMG] Timed following action arrived at 0x000000000000F7E6: handler 0x30063f20 exchange 37762r chip[DMG] Handing timed invoke to IM engine: handler 0x30063f20 exchange 37762r chip[DMG] Received command for Endpoint=0 Cluster=0x0000_003C Command=0x0000_0000 chip[ZCL] Received command to open commissioning window chip[IN] SecureSession[0x3006d688]: Allocated Type:1 LSID:6157 chip[SC] Assigned local session key ID 6157 chip[SC] Waiting for PBKDF param request chip[DIS] Updating services using commissioning mode 2 chip[DIS] CHIP minimal mDNS started advertising. chip[DL] Using wifi MAC for hostname chip[DIS] Advertise operational node F322B19FA0F52BF8-00000000A9004E92 chip[DIS] Responding with _matter._tcp.local chip[DIS] Responding with F322B19FA0F52BF8-00000000A9004E92._matter._tcp.local chip[DIS] Responding with F322B19FA0F52BF8-00000000A9004E92._matter._tcp.local chip[DIS] Responding with C8478C0C9AB7.local chip[DIS] Responding with C8478C0C9AB7.local chip[DIS] Responding with _IF322B19FA0F52BF8._sub._matter._tcp.local chip[DIS] CHIP minimal mDNS configured as 'Operational device'; instance name: F322B19FA0F52BF8-00000000A9004E92. chip[DIS] mDNS service published: _matter._tcp chip[DL] Using wifi MAC for hostname chip[DIS] Advertise commission parameter vendorID=4930 productID=1001 discriminator=2795/10 cm=2 chip[DIS] Responding with _matterc._udp.local chip[DIS] Responding with 62CF9B53131F2A42._matterc._udp.local chip[DIS] Responding with C8478C0C9AB7.local chip[DIS] Responding with C8478C0C9AB7.local chip[DIS] Responding with _V4930._sub._matterc._udp.local chip[DIS] Responding with _S10._sub._matterc._udp.local chip[DIS] Responding with _L2795._sub._matterc._udp.local chip[DIS] Responding with _CM._sub._matterc._udp.local chip[DIS] Responding with 62CF9B53131F2A42._matterc._udp.local chip[DIS] CHIP minimal mDNS configured as 'Commissionable node device'; instance name: 62CF9B53131F2A42. chip[DIS] mDNS service published: _matterc._udp chip[ZCL] Commissioning window is now open chip[DMG] Command handler moving to [ Preparing] chip[DMG] Command handler moving to [AddingComm] chip[DMG] Command handler moving to [AddedComma] chip[DMG] Decreasing reference count for CommandHandler, remaining 0 chip[EM] <<< [E:37762r M:129845041 (Ack:117382940)] (S) Msg TX to 1:61F81323C6104D18 [2BF8] --- Type 0001:09 (IM:InvokeCommandchip[IN] (S) Sending msg 129845041 on secure session with LSID: 6155 chip[DMG] Command handler moving to [CommandSen] chip[DMG] Command handler moving to [AwaitingDe] chip[DL] Long dispatch time: 270 ms, for event type 3 chip[IN] Received a duplicate message with MessageCounter:117382940 on exchange 37762r chip[EM] >>> [E:37762r M:117382940 (Ack:129845040)] (S) Msg RX from 1:61F81323C6104D18 [2BF8] --- Type 0001:08 (IM:InvokeCommachip[EM] Found matching exchange: 37762r, Delegate: (nil) chip[EM] Forcing tx of solitary ack for duplicate MessageCounter:117382940 on exchange 37762r chip[EM] <<< [E:37762r M:129845042 (Ack:117382940)] (S) Msg TX to 1:61F81323C6104D18 [2BF8] --- Type 0000:10 (SecureChannel:Stchip[IN] (S) Sending msg 129845042 on secure session with LSID: 6155 chip[EM] >>> [E:37762r M:117382941 (Ack:129845041)] (S) Msg RX from 1:61F81323C6104D18 [2BF8] --- Type 0000:10 (SecureChannel:chip[EM] Found matching exchange: 37762r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:129845041 from Retrans Table on exchange 37762r chip[EM] >>> [E:29829r M:42972674] (U) Msg RX from 0:6A876BEAE3ED96DC [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequestchip[EM] Handling via exchange: 29829r, Delegate: 0x30071604 chip[EM] <<< [E:29829r M:95217208 (Ack:42972674)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:Stanchip[IN] (U) Sending msg 95217208 to IP address 'UDP:[FE80::10CB:D578:4895:CA1B%en1]:50843' chip[EM] Flushed pending ack for MessageCounter:42972674 on exchange 29829r chip[SC] Received PBKDF param request chip[SC] Peer assigned session ID 32337 chip[SC] Found MRP parameters in the message chip[SC] Including MRP parameters in PBKDF param response chip[EM] <<< [E:29829r M:95217209 (Ack:42972674)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:21 (SecureChannel:PBKDchip[IN] (U) Sending msg 95217209 to IP address 'UDP:[FE80::10CB:D578:4895:CA1B%en1]:50843' chip[SC] Sent PBKDF param response chip[EM] >>> [E:29829r M:42972675 (Ack:95217209)] (U) Msg RX from 0:6A876BEAE3ED96DC [0000] --- Type 0000:22 (SecureChannel:PAchip[EM] Found matching exchange: 29829r, Delegate: 0x30071604 chip[EM] Rxd Ack; Removing MessageCounter:95217209 from Retrans Table on exchange 29829r chip[EM] <<< [E:29829r M:95217210 (Ack:42972675)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:Stanchip[IN] (U) Sending msg 95217210 to IP address 'UDP:[FE80::10CB:D578:4895:CA1B%en1]:50843' chip[EM] Flushed pending ack for MessageCounter:42972675 on exchange 29829r chip[SC] Received spake2p msg1 chip[EM] <<< [E:29829r M:95217211 (Ack:42972675)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:23 (SecureChannel:PASEchip[IN] (U) Sending msg 95217211 to IP address 'UDP:[FE80::10CB:D578:4895:CA1B%en1]:50843' chip[SC] Sent spake2p msg2 chip[DL] Long dispatch time: 1770 ms, for event type 3 chip[EM] >>> [E:29829r M:42972676 (Ack:95217211)] (U) Msg RX from 0:6A876BEAE3ED96DC [0000] --- Type 0000:24 (SecureChannel:PAchip[EM] Found matching exchange: 29829r, Delegate: 0x30071604 chip[EM] Rxd Ack; Removing MessageCounter:95217211 from Retrans Table on exchange 29829r chip[EM] <<< [E:29829r M:95217212 (Ack:42972676)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:Stanchip[IN] (U) Sending msg 95217212 to IP address 'UDP:[FE80::10CB:D578:4895:CA1B%en1]:50843' chip[EM] Flushed pending ack for MessageCounter:42972676 on exchange 29829r chip[SC] Received spake2p msg3 chip[SC] Sending status report. Protocol code 0, exchange 29829 chip[EM] <<< [E:29829r M:95217213 (Ack:42972676)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:Statchip[IN] (U) Sending msg 95217213 to IP address 'UDP:[FE80::10CB:D578:4895:CA1B%en1]:50843' chip[SC] SecureSession[0x3006d688]: Moving from state 'kEstablishing' --> 'kActive' chip[IN] SecureSession[0x3006d688]: Activated - Type:1 LSID:6157 chip[IN] New secure session activated for device <FFFFFFFB00000000, 0>, LSID:6157 PSID:32337! chip[SVR] Commissioning completed session establishment step chip[DIS] Updating services using commissioning mode 0 chip[DIS] CHIP minimal mDNS started advertising. chip[DL] Using wifi MAC for hostname chip[DIS] Advertise operational node F322B19FA0F52BF8-00000000A9004E92 chip[DIS] Responding with _matter._tcp.local chip[DIS] Responding with F322B19FA0F52BF8-00000000A9004E92._matter._tcp.local chip[DIS] Responding with F322B19FA0F52BF8-00000000A9004E92._matter._tcp.local chip[DIS] Responding with C8478C0C9AB7.local chip[DIS] Responding with C8478C0C9AB7.local chip[DIS] Responding with _IF322B19FA0F52BF8._sub._matter._tcp.local chip[DIS] CHIP minimal mDNS configured as 'Operational device'; instance name: F322B19FA0F52BF8-00000000A9004E92. chip[DIS] mDNS service published: _matter._tcp chip[DL] Using wifi MAC for hostname chip[DIS] Advertise commission parameter vendorID=4930 productID=1001 discriminator=3840/15 cm=0 chip[DIS] Responding with _matterc._udp.local chip[DIS] Responding with 62CF9B53131F2A42._matterc._udp.local chip[DIS] Responding with C8478C0C9AB7.local chip[DIS] Responding with C8478C0C9AB7.local chip[DIS] Responding with _V4930._sub._matterc._udp.local chip[DIS] Responding with _S15._sub._matterc._udp.local cwifid:I(71004):mm_hw_config_handler,msgid = 40,mm_state = 1,hw_state = 3 hip[DIS] Responding with _L3840._sub._matterc._udp.local chip[DIS] Responding with 62CF9B53131F2A42._matterc._udp.local chip[DIS] CHIP minimal mDNS configured as 'Commissionable node device'; instance name: 62CF9B53131F2A42. chip[DIS] mDNS service published: _matterc._udp chip[DIS] Scheduling extended discovery timeout in 900s chip[SVR] Device completed Rendezvous process chip[DL] Long dispatch time: 268 ms, for event type 3 chip[IN] Received a duplicate message with MessageCounter:42972676 on exchange 29829r chip[EM] >>> [E:29829r M:42972676 (Ack:95217211)] (U) Msg RX from 0:6A876BEAE3ED96DC [0000] --- Type 0000:24 (SecureChannel:PAchip[EM] Found matching exchange: 29829r, Delegate: (nil) chip[EM] Forcing tx of solitary ack for duplicate MessageCounter:42972676 on exchange 29829r chip[EM] <<< [E:29829r M:95217214 (Ack:42972676)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:Stanchip[IN] (U) Sending msg 95217214 to IP address 'UDP:[FE80::10CB:D578:4895:CA1B%en1]:50843' chip[EM] >>> [E:29829r M:42972677 (Ack:95217213)] (U) Msg RX from 0:6A876BEAE3ED96DC [0000] --- Type 0000:10 (SecureChannel:Stchip[EM] Found matching exchange: 29829r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:95217213 from Retrans Table on exchange 29829r chip[EM] >>> [E:29830r M:250364471] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) chip[EM] Handling via exchange: 29830r, Delegate: 0x30063b04 chip[IM] Received Read request chip[DMG] IM RH moving to [GeneratingReports] chip[DMG] Building Reports for ReadHandler with LastReportGeneration = 4294967293 DirtyGeneration = 0 chip[DMG] RE:Run Cluster 1d, Attribute 3 is dirty chip[DMG] Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0003 (expanded=0) chip[DMG] <RE> Sending report (payload has 64 bytes)... chip[EM] <<< [E:29830r M:157299309 (Ack:250364471)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) chip[IN] (S) Sending msg 157299309 on secure session with LSID: 6157 chip[DMG] <RE> OnReportConfirm: NumReports = 0 chip[DMG] <RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages chip[DMG] IM RH moving to [AwaitingDestruction] chip[DMG] All ReadHandler-s are clean, clear GlobalDirtySet chip[EM] >>> [E:29830r M:250364472 (Ack:157299309)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0000:10 (SecureChannel:chip[EM] Found matching exchange: 29830r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:157299309 from Retrans Table on exchange 29830r chip[EM] >>> [E:29831r M:250364473] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) chip[EM] Handling via exchange: 29831r, Delegate: 0x30063b04 chip[IM] Received Read request chip[DMG] IM RH moving to [GeneratingReports] chip[DMG] Building Reports for ReadHandler with LastReportGeneration = 4294967293 DirtyGeneration = 0 chip[DMG] RE:Run Cluster 1d, Attribute 1 is dirty chip[DMG] Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0001 (expanded=0) chip[DMG] <RE> Sending report (payload has 372 bytes)... chip[EM] <<< [E:29831r M:157299310 (Ack:250364473)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) chip[IN] (S) Sending msg 157299310 on secure session with LSID: 6157 chip[DMG] <RE> OnReportConfirm: NumReports = 0 chip[DMG] <RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages chip[DMG] IM RH moving to [AwaitingDestruction] chip[DMG] All ReadHandler-s are clean, clear GlobalDirtySet chip[EM] >>> [E:29831r M:250364474 (Ack:157299310)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0000:10 (SecureChannel:chip[EM] Found matching exchange: 29831r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:157299310 from Retrans Table on exchange 29831r chip[EM] >>> [E:29832r M:250364475] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) chip[EM] Handling via exchange: 29832r, Delegate: 0x30063b04 chip[IM] Received Read request chip[DMG] IM RH moving to [GeneratingReports] chip[DMG] Building Reports for ReadHandler with LastReportGeneration = 4294967293 DirtyGeneration = 0 chip[DMG] RE:Run Cluster 31, Attribute fffc is dirty chip[DMG] Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFC (expanded=0) chip[DMG] <RE> Sending report (payload has 37 bytes)... chip[EM] <<< [E:29832r M:157299311 (Ack:250364475)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) chip[IN] (S) Sending msg 157299311 on secure session with LSID: 6157 chip[DMG] <RE> OnReportConfirm: NumReports = 0 chip[DMG] <RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages chip[DMG] IM RH moving to [AwaitingDestruction] chip[DMG] All ReadHandler-s are clean, clear GlobalDirtySet chip[EM] >>> [E:29832r M:250364476 (Ack:157299311)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0000:10 (SecureChannel:chip[EM] Found matching exchange: 29832r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:157299311 from Retrans Table on exchange 29832r chip[EM] >>> [E:29833r M:250364477] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) chip[EM] Handling via exchange: 29833r, Delegate: 0x30063b04 chip[IM] Received Read request chip[DMG] IM RH moving to [GeneratingReports] chip[DMG] Building Reports for ReadHandler with LastReportGeneration = 4294967293 DirtyGeneration = 0 chip[DMG] RE:Run Cluster 31, Attribute 3 is dirty chip[DMG] Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_0003 (expanded=1) chip[DMG] RE:Run Cluster 28, Attribute 4 is dirty chip[DMG] Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0004 (expanded=0) chip[DMG] RE:Run Cluster 28, Attribute 2 is dirty chip[DMG] Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0002 (expanded=0) chip[DMG] RE:Run Cluster 30, Attribute 3 is dirty chip[DMG] Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0003 (expanded=0) chip[DMG] RE:Run Cluster 30, Attribute 2 is dirty chip[DMG] Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0002 (expanded=0) chip[DMG] RE:Run Cluster 30, Attribute 1 is dirty chip[DMG] Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0001 (expanded=0) chip[DMG] RE:Run Cluster 30, Attribute 0 is dirty chip[DMG] Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0000 (expanded=0) chip[DMG] RE:Run Cluster 31, Attribute fffc is dirty chip[DMG] Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFC (expanded=1) chip[DMG] <RE> Sending report (payload has 228 bytes)... chip[EM] <<< [E:29833r M:157299312 (Ack:250364477)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) chip[IN] (S) Sending msg 157299312 on secure session with LSID: 6157 chip[DMG] <RE> OnReportConfirm: NumReports = 0 chip[DMG] <RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages chip[DMG] IM RH moving to [AwaitingDestruction] chip[DMG] All ReadHandler-s are clean, clear GlobalDirtySet chip[DL] Long dispatch time: 156 ms, for event type 3 chip[EM] >>> [E:29834r M:250364478] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) chip[EM] Handling via exchange: 29834r, Delegate: 0x30063b04 chip[DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000 chip[FS] GeneralCommissioning: Received ArmFailSafe (60s) chip[DMG] Endpoint 0, Cluster 0x0000_0030 update version to 6272042e chip[ZCL] Unknown cluster ID: 0x0000_0030 chip[DMG] Command handler moving to [ Preparing] chip[DMG] Command handler moving to [AddingComm] chip[DMG] Command handler moving to [AddedComma] chip[DMG] Decreasing reference count for CommandHandler, remaining 0 chip[EM] <<< [E:29834r M:157299313 (Ack:250364478)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandchip[IN] (S) Sending msg 157299313 on secure session with LSID: 6157 chip[DMG] Command handler moving to [CommandSen] chip[DMG] Command handler moving to [AwaitingDe] chip[EM] >>> [E:29833r M:250364479 (Ack:157299312)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0000:10 (SecureChannel:chip[EM] Found matching exchange: 29833r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:157299312 from Retrans Table on exchange 29833r chip[EM] >>> [E:29835r M:250364480] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) chip[EM] Handling via exchange: 29835r, Delegate: 0x30063b04 chip[DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0002 chip[DMG] Endpoint 0, Cluster 0x0000_0030 update version to 6272042f chip[ZCL] Unknown cluster ID: 0x0000_0030 chip[DMG] Command handler moving to [ Preparing] chip[DMG] Command handler moving to [AddingComm] chip[DMG] Command handler moving to [AddedComma] chip[DMG] Decreasing reference count for CommandHandler, remaining 0 chip[EM] <<< [E:29835r M:157299314 (Ack:250364480)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandchip[IN] (S) Sending msg 157299314 on secure session with LSID: 6157 chip[DMG] Command handler moving to [CommandSen] chip[DMG] Command handler moving to [AwaitingDe] chip[EM] >>> [E:29834r M:250364481 (Ack:157299313)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0000:10 (SecureChannel:chip[EM] Found matching exchange: 29834r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:157299313 from Retrans Table on exchange 29834r chip[EM] >>> [E:29836r M:250364482] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) chip[EM] Handling via exchange: 29836r, Delegate: 0x30063b04 chip[DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 chip[ZCL] OpCreds: Certificate Chain request received for PAI chip[DMG] Command handler moving to [ Preparing] chip[DMG] Command handler moving to [AddingComm] chip[DMG] Command handler moving to [AddedComma] chip[DMG] Decreasing reference count for CommandHandler, remaining 0 chip[EM] <<< [E:29836r M:157299315 (Ack:250364482)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandchip[IN] (S) Sending msg 157299315 on secure session with LSID: 6157 chip[DMG] Command handler moving to [CommandSen] chip[DMG] Command handler moving to [AwaitingDe] chip[EM] >>> [E:29835r M:250364483 (Ack:157299314)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0000:10 (SecureChannel:chip[EM] Found matching exchange: 29835r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:157299314 from Retrans Table on exchange 29835r chip[EM] >>> [E:29837r M:250364484] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) chip[EM] Handling via exchange: 29837r, Delegate: 0x30063b04 chip[DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 chip[ZCL] OpCreds: Certificate Chain request received for DAC chip[DMG] Command handler moving to [ Preparing] chip[DMG] Command handler moving to [AddingComm] chip[DMG] Command handler moving to [AddedComma] chip[DMG] Decreasing reference count for CommandHandler, remaining 0 chip[EM] <<< [E:29837r M:157299316 (Ack:250364484)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandchip[IN] (S) Sending msg 157299316 on secure session with LSID: 6157 chip[DMG] Command handler moving to [CommandSen] chip[DMG] Command handler moving to [AwaitingDe] chip[EM] >>> [E:29836r M:250364485 (Ack:157299315)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0000:10 (SecureChannel:chip[EM] Found matching exchange: 29836r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:157299315 from Retrans Table on exchange 29836r chip[EM] >>> [E:29838r M:250364486] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) chip[EM] Handling via exchange: 29838r, Delegate: 0x30063b04 chip[DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0000 chip[ZCL] OpCreds: Received an AttestationRequest command chip[EM] <<< [E:29838r M:157299317 (Ack:250364486)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0000:10 (SecureChannel:Stchip[IN] (S) Sending msg 157299317 on secure session with LSID: 6157 chip[EM] Flushed pending ack for MessageCounter:250364486 on exchange 29838r chip[ZCL] OpCreds: AttestationRequest successful. chip[DMG] Command handler moving to [ Preparing] chip[DMG] Command handler moving to [AddingComm] chip[DMG] Command handler moving to [AddedComma] chip[DMG] Decreasing reference count for CommandHandler, remaining 0 chip[EM] <<< [E:29838r M:157299318 (Ack:250364486)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandchip[IN] (S) Sending msg 157299318 on secure session with LSID: 6157 chip[DMG] Command handler moving to [CommandSen] chip[DMG] Command handler moving to [AwaitingDe] chip[DL] Long dispatch time: 430 ms, for event type 3 chip[EM] >>> [E:29837r M:250364487 (Ack:157299316)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0000:10 (SecureChannel:chip[EM] Found matching exchange: 29837r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:157299316 from Retrans Table on exchange 29837r chip[EM] >>> [E:29839r M:250364488] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) chip[EM] Handling via exchange: 29839r, Delegate: 0x30063b04 chip[DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000 chip[FS] GeneralCommissioning: Received ArmFailSafe (60s) chip[DMG] Endpoint 0, Cluster 0x0000_0030 update version to 62720430 chip[ZCL] Unknown cluster ID: 0x0000_0030 chip[DMG] Command handler moving to [ Preparing] chip[DMG] Command handler moving to [AddingComm] chip[DMG] Command handler moving to [AddedComma] chip[DMG] Decreasing reference count for CommandHandler, remaining 0 chip[EM] <<< [E:29839r M:157299319 (Ack:250364488)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandchip[IN] (S) Sending msg 157299319 on secure session with LSID: 6157 chip[DMG] Command handler moving to [CommandSen] chip[DMG] Command handler moving to [AwaitingDe] chip[EM] >>> [E:29838r M:250364489 (Ack:157299318)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0000:10 (SecureChannel:chip[EM] Found matching exchange: 29838r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:157299318 from Retrans Table on exchange 29838r chip[EM] >>> [E:29839r M:250364490 (Ack:157299319)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0000:10 (SecureChannel:chip[EM] Found matching exchange: 29839r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:157299319 from Retrans Table on exchange 29839r chip[EM] >>> [E:29840r M:250364491] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) chip[EM] Handling via exchange: 29840r, Delegate: 0x30063b04 chip[DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0004 chip[ZCL] OpCreds: Received a CSRRequest command chip[ZCL] OpCreds: Finding fabric with fabricIndex 0x0 chip[EM] <<< [E:29840r M:157299320 (Ack:250364491)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0000:10 (SecureChannel:Stchip[IN] (S) Sending msg 157299320 on secure session with LSID: 6157 chip[EM] Flushed pending ack for MessageCounter:250364491 on exchange 29840r chip[ZCL] OpCreds: AllocatePendingOperationalKey succeeded chip[ZCL] OpCreds: CSRRequest successful. chip[DMG] Command handler moving to [ Preparing] chip[DMG] Command handler moving to [AddingComm] chip[DMG] Command handler moving to [AddedComma] chip[DMG] Decreasing reference count for CommandHandler, remaining 0 chip[EM] <<< [E:29840r M:157299321 (Ack:250364491)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandchip[IN] (S) Sending msg 157299321 on secure session with LSID: 6157 chip[DMG] Command handler moving to [CommandSen] chip[DMG] Command handler moving to [AwaitingDe] chip[DL] Long dispatch time: 1138 ms, for event type 3 chip[EM] >>> [E:29841r M:250364492] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) chip[EM] Handling via exchange: 29841r, Delegate: 0x30063b04 chip[DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B chip[ZCL] OpCreds: Received an AddTrustedRootCertificate command chip[EM] <<< [E:29841r M:157299322 (Ack:250364492)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0000:10 (SecureChannel:Stchip[IN] (S) Sending msg 157299322 on secure session with LSID: 6157 chip[EM] Flushed pending ack for MessageCounter:250364492 on exchange 29841r chip[ZCL] OpCreds: AddTrustedRootCertificate successful. chip[DMG] Command handler moving to [ Preparing] chip[DMG] Command handler moving to [AddingComm] chip[DMG] Command handler moving to [AddedComma] chip[DMG] Decreasing reference count for CommandHandler, remaining 0 chip[EM] <<< [E:29841r M:157299323 (Ack:250364492)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandchip[IN] (S) Sending msg 157299323 on secure session with LSID: 6157 chip[DMG] Command handler moving to [CommandSen] chip[DMG] Command handler moving to [AwaitingDe] chip[DL] Long dispatch time: 790 ms, for event type 3 chip[EM] >>> [E:29840r M:250364493 (Ack:157299321)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0000:10 (SecureChannel:chip[EM] Found matching exchange: 29840r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:157299321 from Retrans Table on exchange 29840r chip[EM] >>> [E:29842r M:250364494] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) chip[EM] Handling via exchange: 29842r, Delegate: 0x30063b04 chip[DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0006 chip[ZCL] OpCreds: Received an AddNOC command chip[EM] <<< [E:29842r M:157299324 (Ack:250364494)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0000:10 (SecureChannel:Stchip[IN] (S) Sending msg 157299324 on secure session with LSID: 6157 chip[EM] Flushed pending ack for MessageCounter:250364494 on exchange 29842r chip[FP] Validating NOC chain chip[FP] NOC chain validation successful chip[FP] Added new fabric at index: 0x2 chip[FP] Assigned compressed fabric ID: 0x102FE41D15C8F103, node ID: 0x000000001B3B4DCE chip[TS] Last Known Good Time: 2022-10-21T09:36:21 chip[TS] New proposed Last Known Good Time: 2022-10-21T09:36:43 chip[TS] Updating pending Last Known Good Time to 2022-10-21T09:36:43 chip[DMG] Endpoint 0, Cluster 0x0000_003E update version to 23dd3da7 chip[DMG] Endpoint 0, Cluster 0x0000_003E update version to 23dd3da8 put key:f/2/k/0 put key:g/gfl put key:f/2/g put key:f/2/ac/0/0 chip[EVL] LogEvent event number: 0x0000000000000003 priority: 1, endpoint id: 0x0 cluster id: 0x0000_001F event id: 0x0 Sys tchip[ZCL] OpCreds: ACL entry created for Fabric index 0x2 CASE Admin Subject 0x0D865360B3CB47FB chip[DL] Using wifi MAC for hostname chip[DIS] Advertise operational node F322B19FA0F52BF8-00000000A9004E92 chip[DIS] Responding with _matter._tcp.local chip[DIS] Responding with F322B19FA0F52BF8-00000000A9004E92._matter._tcp.local chip[DIS] Responding with F322B19FA0F52BF8-00000000A9004E92._matter._tcp.local chip[DIS] Responding with C8478C0C9AB7.local chip[DIS] Responding with C8478C0C9AB7.local chip[DIS] Responding with _IF322B19FA0F52BF8._sub._matter._tcp.local chip[DIS] CHIP minimal mDNS configured as 'Operational device'; instance name: F322B19FA0F52BF8-00000000A9004E92. chip[DIS] mDNS service published: _matter._tcp chip[DL] Using wifi MAC for hostname chip[DIS] Advertise operational node 102FE41D15C8F103-000000001B3B4DCE chip[DIS] Responding with _matter._tcp.local chip[DIS] Responding with 102FE41D15C8F103-000000001B3B4DCE._matter._tcp.local chip[DIS] Responding with 102FE41D15C8F103-000000001B3B4DCE._matter._tcp.local chip[DIS] Responding with C8478C0C9AB7.local chip[DIS] Responding with C8478C0C9AB7.local chip[DIS] Responding with _I102FE41D15C8F103._sub._matter._tcp.local chip[DIS] CHIP minimal mDNS configured as 'Operational device'; instance name: 102FE41D15C8F103-000000001B3B4DCE. chip[DIS] mDNS service published: _matter._tcp chip[DMG] Endpoint 0, Cluster 0x0000_003E update version to 23dd3da9 chip[DMG] Endpoint 0, Cluster 0x0000_003E update version to 23dd3daa chip[DMG] Command handler moving to [ Preparing] chip[DMG] Command handler moving to [AddingComm] chip[DMG] Command handler moving to [AddedComma] chip[ZCL] OpCreds: successfully created fabric index 0x2 via AddNOC chip[DMG] Decreasing reference count for CommandHandler, remaining 0 chip[EM] <<< [E:29842r M:157299325 (Ack:250364494)] (S) Msg TX to 2:FFFFFFFB00000000 [F103] --- Type 0001:09 (IM:InvokeCommandchip[IN] (S) Sending msg 157299325 on secure session with LSID: 6157 chip[DMG] Command handler moving to [CommandSen] chip[DMG] Command handler moving to [AwaitingDe] chip[DL] Long dispatch time: 1084 ms, for event type 3 chip[EM] >>> [E:29841r M:250364495 (Ack:157299323)] (S) Msg RX from 2:FFFFFFFB00000000 [F103] --- Type 0000:10 (SecureChannel:chip[EM] Found matching exchange: 29841r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:157299323 from Retrans Table on exchange 29841r chip[EM] >>> [E:29842r M:250364496 (Ack:157299325)] (S) Msg RX from 2:FFFFFFFB00000000 [F103] --- Type 0000:10 (SecureChannel:chip[EM] Found matching exchange: 29842r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:157299325 from Retrans Table on exchange 29842r chip[EM] >>> [E:29843r M:42972678] (U) Msg RX from 0:BB473A798143A962 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1) chip[EM] Handling via exchange: 29843r, Delegate: 0x3006fab0 chip[IN] CASE Server received Sigma1 message. Starting handshake. EC 0x300706b8 chip[IN] CASE Server disabling CASE session setups chip[EM] <<< [E:29843r M:95217215 (Ack:42972678)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:Stanchip[IN] (U) Sending msg 95217215 to IP address 'UDP:[FE80::10CB:D578:4895:CA1B%en1]:50843' chip[EM] Flushed pending ack for MessageCounter:42972678 on exchange 29843r chip[SC] Received Sigma1 msg chip[SC] Found MRP parameters in the message chip[SC] Peer assigned session key ID 32338 chip[SC] CASE matched destination ID: fabricIndex 2, NodeID 0x000000001B3B4DCE chip[SC] Including MRP parameters chip[EM] <<< [E:29843r M:95217216 (Ack:42972678)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASEchip[IN] (U) Sending msg 95217216 to IP address 'UDP:[FE80::10CB:D578:4895:CA1B%en1]:50843' chip[SC] Sent Sigma2 msg chip[DL] Long dispatch time: 1118 ms, for event type 3 wifid:I(77958):chan_bcn_to_evt:prevent sleep ,beacon loss cnt6 wifid:I(78052):mm_check_beacon:receive bcn,beacon_loss_cnt 7 chip[EM] >>> [E:29843r M:42972679 (Ack:95217216)] (U) Msg RX from 0:BB473A798143A962 [0000] --- Type 0000:32 (SecureChannel:CAchip[EM] Found matching exchange: 29843r, Delegate: 0x3006facc chip[EM] Rxd Ack; Removing MessageCounter:95217216 from Retrans Table on exchange 29843r chip[EM] <<< [E:29843r M:95217217 (Ack:42972679)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:Stanchip[IN] (U) Sending msg 95217217 to IP address 'UDP:[FE80::10CB:D578:4895:CA1B%en1]:50843' chip[EM] Flushed pending ack for MessageCounter:42972679 on exchange 29843r chip[SC] Received Sigma3 msg chip[SC] Certificate's mNotBeforeTime (719042573) is after current time (78) chip[SC] Certificate's mNotBeforeTime (719042573) is after current time (78) put key:f/2/s/0D865360B3CB47FB put key:g/s/ibzP/36WohSsHy7S/OFEnQ== put key:g/sri chip[SC] Sending status report. Protocol code 0, exchange 29843 chip[EM] <<< [E:29843r M:95217218 (Ack:42972679)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:Statchip[IN] (U) Sending msg 95217218 to IP address 'UDP:[FE80::10CB:D578:4895:CA1B%en1]:50843' chip[SC] SecureSession[0x3006d7f8]: Moving from state 'kEstablishing' --> 'kActive' chip[IN] SecureSession[0x3006d7f8]: Activated - Type:2 LSID:6156 chip[IN] New secure session activated for device <0D865360B3CB47FB, 2>, LSID:6156 PSID:32338! chip[IN] CASE Session established to peer: <0D865360B3CB47FB, 2> chip[IN] CASE Server enabling CASE session setups chip[IN] SecureSession[0x3006d8b0]: Allocated Type:2 LSID:6158 chip[SC] Allocated SecureSession (0x3006d8b0) - waiting for Sigma1 msg chip[DL] Long dispatch time: 1540 ms, for event type 3 chip[IN] Received a duplicate message with MessageCounter:42972679 on exchange 29843r chip[EM] >>> [E:29843r M:42972679 (Ack:95217216)] (U) Msg RX from 0:BB473A798143A962 [0000] --- Type 0000:32 (SecureChannel:CAchip[EM] Found matching exchange: 29843r, Delegate: (nil) chip[EM] Forcing tx of solitary ack for duplicate MessageCounter:42972679 on exchange 29843r chip[EM] <<< [E:29843r M:95217219 (Ack:42972679)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:Stanchip[IN] (U) Sending msg 95217219 to IP address 'UDP:[FE80::10CB:D578:4895:CA1B%en1]:50843' chip[EM] >>> [E:29844r M:45854686] (S) Msg RX from 2:0D865360B3CB47FB [F103] --- Type 0001:08 (IM:InvokeCommandRequest) chip[EM] Handling via exchange: 29844r, Delegate: 0x30063b04 chip[DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0004 chip[FS] GeneralCommissioning: Received CommissioningComplete put key:g/fs/c put key:f/2/m chip[FP] Metadata for Fabric 0x2 persisted to storage. put key:f/2/o put key:f/2/n [bk_clean_data] [791] No Such Name put key:f/2/r chip[TS] Committing Last Known Good Time to storage: 2022-10-21T09:36:43 put key:g/lkgt put key:g/fidx chip[ZCL] OpCreds: Fabric index 0x2 was committed to storage. Compressed Fabric Id 0x102FE41D15C8F103, FabricId 00000000000000chip[FS] GeneralCommissioning: Successfully commited pending fabric data chip[FS] Fail-safe cleanly disarmed chip[DMG] Endpoint 0, Cluster 0x0000_0030 update version to 62720431 chip[ZCL] Unknown cluster ID: 0x0000_0030 chip[DMG] Command handler moving to [ Preparing] chip[DMG] Command handler moving to [AddingComm] chip[DMG] Command handler moving to [AddedComma] chip[DMG] Decreasing reference count for CommandHandler, remaining 0 chip[EM] <<< [E:29844r M:127721567 (Ack:45854686)] (S) Msg TX to 2:0D865360B3CB47FB [F103] --- Type 0001:09 (IM:InvokeCommandRchip[IN] (S) Sending msg 127721567 on secure session with LSID: 6156 chip[DMG] Command handler moving to [CommandSen] chip[DMG] Command handler moving to [AwaitingDe] chip[DL] Long dispatch time: 140 ms, for event type 3 chip[EM] >>> [E:29843r M:42972680 (Ack:95217218)] (U) Msg RX from 0:BB473A798143A962 [0000] --- Type 0000:10 (SecureChannel:Stchip[EM] Found matching exchange: 29843r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:95217218 from Retrans Table on exchange 29843r chip[DL] _OnPlatformEvent default: event->Type = 32781 chip[SVR] Commissioning completed successfully chip[DIS] Updating services using commissioning mode 0 chip[DIS] CHIP minimal mDNS started advertising. chip[DL] Using wifi MAC for hostname chip[DIS] Advertise operational node F322B19FA0F52BF8-00000000A9004E92 chip[DIS] Responding with _matter._tcp.local chip[DIS] Responding with F322B19FA0F52BF8-00000000A9004E92._matter._tcp.local chip[DIS] Responding with F322B19FA0F52BF8-00000000A9004E92._matter._tcp.local chip[DIS] Responding with C8478C0C9AB7.local chip[DIS] Responding with C8478C0C9AB7.local chip[DIS] Responding with _IF322B19FA0F52BF8._sub._matter._tcp.local chip[DIS] CHIP minimal mDNS configured as 'Operational device'; instance name: F322B19FA0F52BF8-00000000A9004E92. chip[DIS] mDNS service published: _matter._tcp chip[DL] Using wifi MAC for hostname chip[DIS] Advertise operational node 102FE41D15C8F103-000000001B3B4DCE chip[DIS] Responding with _matter._tcp.local chip[DIS] Responding with 102FE41D15C8F103-000000001B3B4DCE._matter._tcp.local chip[DIS] Responding with 102FE41D15C8F103-000000001B3B4DCE._matter._tcp.local chip[DIS] Responding with C8478C0C9AB7.local chip[DIS] Responding with C8478C0C9AB7.local chip[DIS] Responding with _I102FE41D15C8F103._sub._matter._tcp.local chip[DIS] CHIP minimal mDNS configured as 'Operational device'; instance name: 102FE41D15C8F103-000000001B3B4DCE. chip[DIS] mDNS service published: _matter._tcp chip[DL] Using wifi MAC for hostname chip[DIS] Advertise commission parameter vendorID=4930 productID=1001 discriminator=3840/15 cm=0 chip[DIS] Responding with _matterc._udp.local chip[DIS] Responding with 62CF9B53131F2A42._matterc._udp.local chip[DIS] Responding with C8478C0C9AB7.local chip[DIS] Responding with C8478C0C9AB7.local chip[DIS] Responding with _V4930._sub._matterc._udp.local chip[DIS] Responding with _S15._sub._matterc._udp.local chip[DIS] Responding with _L3840._sub._matterc._udp.local chip[DIS] Responding with 62CF9B53131F2A42._matterc._udp.local chip[DIS] CHIP minimal mDNS configured as 'Commissionable node device'; instance name: 62CF9B53131F2A42. chip[DIS] mDNS service published: _matterc._udp chip[IN] Expiring all PASE sessions chip[IN] SecureSession[0x3006d688]: MarkForEviction Type:1 LSID:6157 chip[SC] SecureSession[0x3006d688]: Moving from state 'kActive' --> 'kPendingEviction' chip[IN] SecureSession[0x3006d688]: Released - Type:1 LSID:6157 chip[SWU] Device commissioned, schedule a default provider query chip[ZCL] Commissioning complete, notify platform driver to persist network credentials. chip[NP] BekenWiFiDriver::CommitConfiguration
put key:wifi-ssid put key:wifi-pass chip[ZCL] DeviceEventCallback, event->Type:32781
chip[ZCL] Commissioning complete chip[DL] Long dispatch time: 304 ms, for event type 32781 chip[EM] >>> [E:29844r M:45854687 (Ack:127721567)] (S) Msg RX from 2:0D865360B3CB47FB [F103] --- Type 0000:10 (SecureChannel:Schip[EM] Found matching exchange: 29844r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:127721567 from Retrans Table on exchange 29844r chip[EM] >>> [E:29845r M:45854688] (S) Msg RX from 2:0D865360B3CB47FB [F103] --- Type 0001:02 (IM:ReadRequest) chip[EM] Handling via exchange: 29845r, Delegate: 0x30063b04 chip[IM] Received Read request chip[DMG] IM RH moving to [GeneratingReports] chip[DMG] Building Reports for ReadHandler with LastReportGeneration = 4294967293 DirtyGeneration = 0 chip[DMG] RE:Run Cluster 28, Attribute f is dirty chip[DMG] Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_000F (expanded=0) chip[DMG] <RE> Sending report (payload has 33 bytes)... chip[EM] <<< [E:29845r M:127721568 (Ack:45854688)] (S) Msg TX to 2:0D865360B3CB47FB [F103] --- Type 0001:05 (IM:ReportData) chip[IN] (S) Sending msg 127721568 on secure session with LSID: 6156 chip[DMG] <RE> OnReportConfirm: NumReports = 0 chip[DMG] <RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages chip[DMG] IM RH moving to [AwaitingDestruction] chip[DMG] All ReadHandler-s are clean, clear GlobalDirtySet chip[EM] >>> [E:29845r M:45854689 (Ack:127721568)] (S) Msg RX from 2:0D865360B3CB47FB [F103] --- Type 0000:10 (SecureChannel:Schip[EM] Found matching exchange: 29845r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:127721568 from Retrans Table on exchange 29845r chip[EM] >>> [E:29846r M:45854690] (S) Msg RX from 2:0D865360B3CB47FB [F103] --- Type 0001:02 (IM:ReadRequest) chip[EM] Handling via exchange: 29846r, Delegate: 0x30063b04 chip[IM] Received Read request chip[DMG] IM RH moving to [GeneratingReports] chip[DMG] Building Reports for ReadHandler with LastReportGeneration = 4294967293 DirtyGeneration = 0 chip[DMG] RE:Run Cluster 3e, Attribute 1 is dirty chip[DMG] Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_0001 (expanded=0) chip[DMG] <RE> Sending report (payload has 151 bytes)... chip[EM] <<< [E:29846r M:127721569 (Ack:45854690)] (S) Msg TX to 2:0D865360B3CB47FB [F103] --- Type 0001:05 (IM:ReportData) chip[IN] (S) Sending msg 127721569 on secure session with LSID: 6156 chip[DMG] <RE> OnReportConfirm: NumReports = 0 chip[DMG] <RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages chip[DMG] IM RH moving to [AwaitingDestruction] chip[DMG] All ReadHandler-s are clean, clear GlobalDirtySet chip[EM] >>> [E:29846r M:45854691 (Ack:127721569)] (S) Msg RX from 2:0D865360B3CB47FB [F103] --- Type 0000:10 (SecureChannel:Schip[EM] Found matching exchange: 29846r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:127721569 from Retrans Table on exchange 29846r chip[EM] >>> [E:29847r M:45854692] (S) Msg RX from 2:0D865360B3CB47FB [F103] --- Type 0001:02 (IM:ReadRequest) chip[EM] Handling via exchange: 29847r, Delegate: 0x30063b04 chip[IM] Received Read request chip[DMG] IM RH moving to [GeneratingReports] chip[DMG] Building Reports for ReadHandler with LastReportGeneration = 4294967293 DirtyGeneration = 0 chip[DMG] RE:Run Cluster 1d, Attribute 3 is dirty chip[DMG] Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0003 (expanded=0) chip[DMG] <RE> Sending report (payload has 64 bytes)... chip[EM] <<< [E:29847r M:127721570 (Ack:45854692)] (S) Msg TX to 2:0D865360B3CB47FB [F103] --- Type 0001:05 (IM:ReportData) chip[IN] (S) Sending msg 127721570 on secure session with LSID: 6156 chip[DMG] <RE> OnReportConfirm: NumReports = 0 chip[DMG] <RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages chip[DMG] IM RH moving to [AwaitingDestruction] chip[DMG] All ReadHandler-s are clean, clear GlobalDirtySet chip[EM] >>> [E:29847r M:45854693 (Ack:127721570)] (S) Msg RX from 2:0D865360B3CB47FB [F103] --- Type 0000:10 (SecureChannel:Schip[EM] Found matching exchange: 29847r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:127721570 from Retrans Table on exchange 29847r chip[EM] >>> [E:29848r M:45854694] (S) Msg RX from 2:0D865360B3CB47FB [F103] --- Type 0001:02 (IM:ReadRequest) chip[EM] Handling via exchange: 29848r, Delegate: 0x30063b04 chip[IM] Received Read request chip[DMG] IM RH moving to [GeneratingReports] chip[DMG] Building Reports for ReadHandler with LastReportGeneration = 4294967293 DirtyGeneration = 0 chip[DMG] RE:Run Cluster 1d, Attribute 0 is dirty chip[DMG] Reading attribute: Cluster=0x0000_001D Endpoint=1 AttributeId=0x0000_0000 (expanded=0) chip[DMG] <RE> Sending report (payload has 71 bytes)... chip[EM] <<< [E:29848r M:127721571 (Ack:45854694)] (S) Msg TX to 2:0D865360B3CB47FB [F103] --- Type 0001:05 (IM:ReportData) chip[IN] (S) Sending msg 127721571 on secure session with LSID: 6156 chip[DMG] <RE> OnReportConfirm: NumReports = 0 chip[DMG] <RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages chip[DMG] IM RH moving to [AwaitingDestruction] chip[DMG] All ReadHandler-s are clean, clear GlobalDirtySet chip[EM] >>> [E:29848r M:45854695 (Ack:127721571)] (S) Msg RX from 2:0D865360B3CB47FB [F103] --- Type 0000:10 (SecureChannel:Schip[EM] Found matching exchange: 29848r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:127721571 from Retrans Table on exchange 29848r chip[EM] >>> [E:29849r M:45854696] (S) Msg RX from 2:0D865360B3CB47FB [F103] --- Type 0001:02 (IM:ReadRequest) chip[EM] Handling via exchange: 29849r, Delegate: 0x30063b04 chip[IM] Received Read request chip[DMG] IM RH moving to [GeneratingReports] chip[DMG] Building Reports for ReadHandler with LastReportGeneration = 4294967293 DirtyGeneration = 0 chip[DMG] RE:Run Cluster 1d, Attribute 1 is dirty chip[DMG] Reading attribute: Cluster=0x0000_001D Endpoint=1 AttributeId=0x0000_0001 (expanded=0) chip[DMG] <RE> Sending report (payload has 148 bytes)... chip[EM] <<< [E:29849r M:127721572 (Ack:45854696)] (S) Msg TX to 2:0D865360B3CB47FB [F103] --- Type 0001:05 (IM:ReportData) chip[IN] (S) Sending msg 127721572 on secure session with LSID: 6156 chip[DMG] <RE> OnReportConfirm: NumReports = 0 chip[DMG] <RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages chip[DMG] IM RH moving to [AwaitingDestruction] chip[DMG] All ReadHandler-s are clean, clear GlobalDirtySet chip[EM] >>> [E:29849r M:45854697 (Ack:127721572)] (S) Msg RX from 2:0D865360B3CB47FB [F103] --- Type 0000:10 (SecureChannel:Schip[EM] Found matching exchange: 29849r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:127721572 from Retrans Table on exchange 29849r chip[EM] >>> [E:29850r M:45854698] (S) Msg RX from 2:0D865360B3CB47FB [F103] --- Type 0001:02 (IM:ReadRequest) chip[EM] Handling via exchange: 29850r, Delegate: 0x30063b04 chip[IM] Received Read request chip[DMG] IM RH moving to [GeneratingReports] chip[DMG] Building Reports for ReadHandler with LastReportGeneration = 4294967293 DirtyGeneration = 0 chip[DMG] RE:Run Cluster 6, Attribute fffc is dirty chip[DMG] Reading attribute: Cluster=0x0000_0006 Endpoint=1 AttributeId=0x0000_FFFC (expanded=0) chip[DMG] <RE> Sending report (payload has 37 bytes)... chip[EM] <<< [E:29850r M:127721573 (Ack:45854698)] (S) Msg TX to 2:0D865360B3CB47FB [F103] --- Type 0001:05 (IM:ReportData) chip[IN] (S) Sending msg 127721573 on secure session with LSID: 6156 chip[DMG] <RE> OnReportConfirm: NumReports = 0 chip[DMG] <RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages chip[DMG] IM RH moving to [AwaitingDestruction] chip[DMG] All ReadHandler-s are clean, clear GlobalDirtySet chip[EM] >>> [E:29850r M:45854699 (Ack:127721573)] (S) Msg RX from 2:0D865360B3CB47FB [F103] --- Type 0000:10 (SecureChannel:Schip[EM] Found matching exchange: 29850r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:127721573 from Retrans Table on exchange 29850r chip[EM] >>> [E:22191r M:46817720] (U) Msg RX from 0:71510A3D13708E4B [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1) chip[EM] Handling via exchange: 22191r, Delegate: 0x3006fab0 chip[IN] CASE Server received Sigma1 message. Starting handshake. EC 0x300706b8 chip[IN] CASE Server disabling CASE session setups chip[EM] <<< [E:22191r M:95217220 (Ack:46817720)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:Stanchip[IN] (U) Sending msg 95217220 to IP address 'UDP:[FE80::10CB:D578:4895:CA1B%en1]:49481' chip[EM] Flushed pending ack for MessageCounter:46817720 on exchange 22191r chip[SC] Received Sigma1 msg chip[SC] Found MRP parameters in the message chip[SC] Peer assigned session key ID 48324 chip[SC] CASE matched destination ID: fabricIndex 1, NodeID 0x00000000A9004E92 chip[SC] Including MRP parameters chip[EM] <<< [E:22191r M:95217221 (Ack:46817720)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASEchip[IN] (U) Sending msg 95217221 to IP address 'UDP:[FE80::10CB:D578:4895:CA1B%en1]:49481' chip[SC] Sent Sigma2 msg chip[DL] Long dispatch time: 1124 ms, for event type 3 chip[EM] >>> [E:22191r M:46817721 (Ack:95217221)] (U) Msg RX from 0:71510A3D13708E4B [0000] --- Type 0000:32 (SecureChannel:CAchip[EM] Found matching exchange: 22191r, Delegate: 0x3006facc chip[EM] Rxd Ack; Removing MessageCounter:95217221 from Retrans Table on exchange 22191r chip[EM] <<< [E:22191r M:95217222 (Ack:46817721)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:Stanchip[IN] (U) Sending msg 95217222 to IP address 'UDP:[FE80::10CB:D578:4895:CA1B%en1]:49481' chip[EM] Flushed pending ack for MessageCounter:46817721 on exchange 22191r chip[SC] Received Sigma3 msg chip[SC] Certificate's mNotBeforeTime (719042542) is after current time (82) chip[SC] Certificate's mNotBeforeTime (719042542) is after current time (82) wifid:I(84000):chan_bcn_to_evt:prevent sleep ,beacon loss cnt6 put key:f/1/s/61F81323C6104D18 put key:g/s/LKm6dCtfPl3XBdLwMd6tPA== put key:g/sri chip[SC] Sending status report. Protocol code 0, exchange 22191 chip[EM] <<< [E:22191r M:95217223 (Ack:46817721)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:Statchip[IN] (U) Sending msg 95217223 to IP address 'UDP:[FE80::10CB:D578:4895:CA1B%en1]:49481' chip[SC] SecureSession[0x3006d8b0]: Moving from state 'kEstablishing' --> 'kActive' chip[IN] SecureSession[0x3006d8b0]: Activated - Type:2 LSID:6158 chip[IN] New secure session activated for device <61F81323C6104D18, 1>, LSID:6158 PSID:48324! chip[IN] CASE Session established to peer: <61F81323C6104D18, 1> chip[IN] CASE Server enabling CASE session setups chip[IN] SecureSession[0x3006d688]: Allocated Type:2 LSID:6159 chip[SC] Allocated SecureSession (0x3006d688) - waiting for Sigma1 msg chip[DL] Long dispatch time: 1540 ms, for event type 3 chip[EM] >>> [E:22191r M:46817722 (Ack:95217223)] (U) Msg RX from 0:71510A3D13708E4B [0000] --- Type 0000:10 (SecureChannel:Stchip[EM] Found matching exchange: 22191r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:95217223 from Retrans Table on exchange 22191r chip[EM] >>> [E:22192r M:264404140] (S) Msg RX from 1:61F81323C6104D18 [2BF8] --- Type 0001:08 (IM:InvokeCommandRequest) chip[EM] Handling via exchange: 22192r, Delegate: 0x30063b04 chip[DMG] Received command for Endpoint=0 Cwifid:I(84608):mm_check_beacon:receive bcn,beacon_loss_cnt 12 luster=0x0000_003E Command=0x0000_0009 chip[ZCL] OpCreds: Received an UpdateFabricLabel command put key:f/1/m chip[FP] Metadata for Fabric 0x1 persisted to storage. chip[DMG] Endpoint 0, Cluster 0x0000_003E update version to 23dd3dab chip[DMG] Command handler moving to [ Preparing] chip[DMG] Command handler moving to [AddingComm] chip[DMG] Command handler moving to [AddedComma] chip[DMG] Decreasing reference count for CommandHandler, remaining 0 chip[EM] <<< [E:22192r M:136743765 (Ack:264404140)] (S) Msg TX to 1:61F81323C6104D18 [2BF8] --- Type 0001:09 (IM:InvokeCommandchip[IN] (S) Sending msg 136743765 on secure session with LSID: 6158 chip[DMG] Command handler moving to [CommandSen] chip[DMG] Command handler moving to [AwaitingDe] chip[EM] >>> [E:22192r M:264404141 (Ack:136743765)] (S) Msg RX from 1:61F81323C6104D18 [2BF8] --- Type 0000:10 (SecureChannel:chip[EM] Found matching exchange: 22192r, Delegate: (nil) chip[EM] Rxd Ack; Removing MessageCounter:136743765 from Retrans Table on exchange 22192r wifid:I(88198):chan_bcn_to_evt:prevent sleep ,beacon loss cnt6 wifid:I(88394):mm_check_beacon:receive bcn,beacon_loss_cnt 8 wifid:I(101306):chan_bcn_to_evt:prevent sleep ,beacon loss cnt6 wifid:I(101606):mm_check_beacon:receive bcn,beacon_loss_cnt 9 chip[SWU] No suitable OTA Provider candidate found chip[SWU] No provider available wifid:I(110420):chan_bcn_to_evt:prevent sleep ,beacon loss cnt6 wifid:I(110720):mm_check_beacon:receive bcn,beacon_loss_cnt 9
@pan-apple @vivien-apple Hi, I add some log to this issue, could you give some advice?
@carol-apple @nivi-apple @woody-apple are more likely to be useful here....
@bzbarsky-apple Thanks for your advice, when I update the Hompod to version 16.1, then HomeKit can control the light now. @sam-gabbay you can try this method.