Matter ICD example (contact sensor example) not change to LIT mode with Apple home kit

[sangphan]

I build contact sensor example (use nrf connect sdk v3.2.1, nrf52840 chip) and try commissioning with apple home kit (use homepod mini), device commissioning succeed but cannot change to LIT mode

 00> rtt:~$
< ot pollperiod
00> ot pollperiod
00> 5000
00>
00> Done

i try difference way to commissioning (use chip tool with command: ./chip-tool pairing ble-thread....--icd-registration true ) it change to LIT mode

00> rtt:~$
< ot pollperiod
00> ot pollperiod
00> 236000 
00>
00> Done

So please let me known why LIT mode not work with  Apple homekit , and how to solve this problem

Thanks for your help

[Maria Gilje]

Hello, 

Do you have logging on for your device? If so, could you please share or check if the logs provide some useful information on what is going wrong when trying to change to LIT mode? 

If you have not already, please also check out the Short idle time and long idle time devices overview from the power consumption section of our Matter documentation. 

Best regards,

Maria

[sangphan]

Thanks Maria,

Here is my device log when commissioning with homekit

00> 
00> rtt:~$ *** Booting My Application v3.2.1 - unknown commit ***
00> *** Using nRF Connect SDK v3.2.1-d8887f6f32df ***
00> *** Using Zephyr OS v4.2.99-ec78104f1569 ***
00> I: 29 [DL]BLE address: D9:D7:4B:07:28:F0
00> I: 35 [DL]CHIP task running
00> I: Init CHIP stack
00> I: 36 [DL]OpenThread started: OK
00> I: 36 [DL]Setting OpenThread device type to SLEEPY END DEVICE
00> D: Registered new test event: 0xffffffff00000000
00> D: Registered new test event: 0xffffffff10000000
00> I: Successfully registered ICDManager as test event trigger handler
00> I: 39 [SVR]Initializing subscription resumption storage...
00> I: 40 [SVR]Server initializing...
00> I: 40 [TS]Last Known Good Time: 2023-10-14T01:16:48
00> I: 41 [DMG]AccessControl: initializing
00> I: 42 [DMG]Examples::AccessControlDelegate::Init
00> I: 42 [DMG]AccessControl: setting
00> I: 42 [DMG]DefaultAclStorage: initializing
00> I: 42 [DMG]DefaultAclStorage: 0 entries loaded
00> D: 42 [IN]UDP::Init bind&listen port=5540
00> D: 43 [IN]UDP::Init bound to port=5540
00> D: 43 [IN]BLEBase::Init - setting/overriding transport
00> D: 43 [IN]TransportMgr initialized
00> D: 51 [DL]Using Thread extended MAC for hostname.
00> I: 55 [ZCL]Using ZAP configuration...
00> D: 56 [DL]Boot reason: 1
00> I: 60 [DMG]AccessControlCluster: initializing
00> D: 62 [IN]SecureSession[0x20011ca8]: Allocated Type:1 LSID:7675
00> D: 62 [DL]CHIPoBLE advertising set to on
00> I: 62 [DIS]Updating services using commissioning mode 1
00> E: 62 [DIS]Failed to remove advertised services: 3
00> D: 63 [DL]Using Thread extended MAC for hostname.
00> D: 63 [DIS]DNS-SD Pairing Instruction not set
00> I: 63 [DIS]Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=1 cp=0 jf=0
00> E: 64 [DIS]Failed to advertise commissionable node: 3
00> E: 64 [DIS]Failed to finalize service update: 3
00> I: 64 [DIS]Updating services using commissioning mode 1
00> E: 64 [DIS]Failed to remove advertised services: 3
00> D: 65 [DL]Using Thread extended MAC for hostname.
00> D: 65 [DIS]DNS-SD Pairing Instruction not set
00> I: 65 [DIS]Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=1 cp=0 jf=0
00> E: 66 [DIS]Failed to advertise commissionable node: 3
00> E: 66 [DIS]Failed to finalize service update: 3
00> I: 66 [IN]CASE Server enabling CASE session setups
00> D: 67 [IN]SecureSession[0x20011d80]: Allocated Type:2 LSID:7676
00> I: 71 [SVR]Server Listening...
00> I: 71 [DL]Device Configuration:
00> I: 71 [DL]  Serial Number: 11223344556677889900
00> I: 72 [DL]  Vendor Id: 65521 (0xFFF1)
00> I: 72 [DL]  Product Id: 32768 (0x8000)
00> I: 72 [DL]  Product Name: Matter Contact Sensor
00> I: 72 [DL]  Hardware Version: 0
00> I: 72 [DL]  Setup Pin Code (0 for UNKNOWN/ERROR): 20202021
00> I: 73 [DL]  Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00)
00> I: 73 [DL]  Manufacturing Date: 2022-01-01
00> I: 73 [DL]  Device Type: 65535 (0xFFFF)
00> I: 74 [SVR]SetupQRCode: [MT:Y.K9042C00KA0648G00]
00> I: 74 [SVR]Copy/paste the below URL in a browser to see the QR Code:
00> I: 74 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3AY.K9042C00KA0648G00
00> I: 75 [SVR]Manual pairing code: [34970112332]
00> I: 77 [DL]CHIPoBLE advertising started
00> I: 19161 [DL]Current number of connections: 1/1
00> I: 19161 [DL]BLE connection established (ConnId: 0x00)
00> I: 19162 [DL]CHIPoBLE advertising stopped
00> D: 19864 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 19865 [BLE]local and remote recv window sizes = 5
00> I: 19865 [BLE]selected BTP version 4
00> I: 19865 [BLE]using BTP fragment sizes rx 244 / tx 244.
00> D: 19984 [DL]ConnId: 0x00, New CCCD value: 0x0002
00> D: 19985 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 6)
00> D: 19985 [IN]BLE EndPoint 0x2001c8bc Connection Complete
00> I: 19986 [DL]CHIPoBLE connection established (ConnId: 0x00, GATT MTU: 247)
00> D: 20044 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 20046 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 20046 [EM]>>> [E:16629r S:0 M:11225275] (U) Msg RX from 0:ACC83E0E6404583C [0000] to 0000000000000000 --- Type 0000:20 (SecureChannel:PBKDFParamRequest) (B:98)
00> I: 20048 [EM]<<< [E:16629r S:0 M:80704044] (U) Msg TX from 0000000000000000 to 0:ACC83E0E6404583C [0000] [BLE] --- Type 0000:21 (SecureChannel:PBKDFParamResponse) (B:154)
00> D: 20049 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 159)
00> I: 20050 [SVR]Commissioning session establishment step started
00> D: 20104 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 20105 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 20106 [EM]>>> [E:16629r S:0 M:11225276] (U) Msg RX from 0:ACC83E0E6404583C [0000] to 0000000000000000 --- Type 0000:22 (SecureChannel:PASE_Pake1) (B:92)
00> I: 20235 [EM]<<< [E:16629r S:0 M:80704045] (U) Msg TX from 0000000000000000 to 0:ACC83E0E6404583C [0000] [BLE] --- Type 0000:23 (SecureChannel:PASE_Pake2) (B:127)
00> D: 20236 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 132)
00> E: 20237 [DL]Long dispatch time: 132 ms, for event type 16388
00> D: 20284 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 20285 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 20286 [EM]>>> [E:16629r S:0 M:11225277] (U) Msg RX from 0:ACC83E0E6404583C [0000] to 0000000000000000 --- Type 0000:24 (SecureChannel:PASE_Pake3) (B:59)
00> I: 20287 [EM]<<< [E:16629r S:0 M:80704046] (U) Msg TX from 0000000000000000 to 0:ACC83E0E6404583C [0000] [BLE] --- Type 0000:40 (SecureChannel:StatusReport) (B:30)
00> D: 20288 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 35)
00> I: 20291 [SC]SecureSession[0x20011ca8, LSID:7675]: State change 'kEstablishing' --> 'kActive'
00> D: 20291 [IN]SecureSession[0x20011ca8]: Activated - Type:1 LSID:7675
00> D: 20291 [IN]New secure session activated for device <FFFFFFFB00000000, 0>, LSID:7675 PSID:51322!
00> I: 20292 [SVR]Commissioning completed session establishment step
00> I: 20292 [DIS]Updating services using commissioning mode 0
00> E: 20293 [DIS]Failed to remove advertised services: 3
00> E: 20293 [DIS]Failed to finalize service update: 3
00> D: 20293 [DL]CHIPoBLE advertising set to off
00> I: 20293 [SVR]Device completed Rendezvous process
00> D: 20344 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 20345 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 20346 [EM]>>> [E:16630r S:7675 M:208197364] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:51)
00> D: 20347 [IM]Received Read request
00> I: 20351 [EM]<<< [E:16630r S:7675 M:268263022] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:68)
00> D: 20352 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 73)
00> D: 20404 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 20435 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 20436 [EM]>>> [E:16631r S:7675 M:208197365] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:51)
00> D: 20437 [IM]Received Read request
00> I: 20441 [EM]<<< [E:16631r S:7675 M:268263023] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:94)
00> D: 20442 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 99)
00> D: 20524 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 20525 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 20526 [EM]>>> [E:16632r S:7675 M:208197366] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:52)
00> D: 20527 [IM]Received Read request
00> I: 20531 [EM]<<< [E:16632r S:7675 M:268263024] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:67)
00> D: 20532 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72)
00> D: 20644 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 20645 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 20646 [EM]>>> [E:16633r S:7675 M:208197367] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:51)
00> D: 20647 [IM]Received Read request
00> I: 20651 [EM]<<< [E:16633r S:7675 M:268263025] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:66)
00> D: 20652 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
00> D: 20764 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 20765 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 20766 [EM]>>> [E:16634r S:7675 M:208197368] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:52)
00> D: 20767 [IM]Received Read request
00> I: 20771 [EM]<<< [E:16634r S:7675 M:268263026] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:67)
00> D: 20772 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72)
00> D: 20884 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 20885 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 20886 [EM]>>> [E:16635r S:7675 M:208197369] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:54)
00> D: 20887 [IM]Received Read request
00> E: 20889 [DMG]Read request on unknown cluster - no data version available
00> E: 20890 [DMG]Fail to retrieve data, roll back and encode status on clusterId: 0x1349_FC00, attributeId: 0x0000_0001err = 5c3
00> I: 20892 [EM]<<< [E:16635r S:7675 M:268263027] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:66)
00> D: 20893 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
00> D: 21004 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 21005 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 21006 [EM]>>> [E:16636r S:7675 M:208197370] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:51)
00> D: 21007 [IM]Received Read request
00> I: 21011 [EM]<<< [E:16636r S:7675 M:268263028] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:99)
00> D: 21012 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 104)
00> D: 21124 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 21126 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 21127 [EM]>>> [E:16637r S:7675 M:208197371] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:136)
00> D: 21128 [IM]Received Read request
00> E: 21139 [DMG]Fail to retrieve data, roll back and encode status on clusterId: 0x0000_0030, attributeId: 0x0000_000Cerr = 586
00> I: 21161 [EM]<<< [E:16637r S:7675 M:268263029] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:253)
00> D: 21162 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
00> D: 21244 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 21245 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 16)
00> D: 21364 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 21366 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 21367 [EM]>>> [E:16638r S:7675 M:208197372] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:128)
00> D: 21368 [IM]Received Read request
00> I: 21393 [EM]<<< [E:16638r S:7675 M:268263030] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:402)
00> D: 21394 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
00> D: 21484 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 21485 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 165)
00> D: 21604 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 21605 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 21607 [EM]>>> [E:16639r S:7675 M:208197373] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:65)
00> I: 21609 [FS]GeneralCommissioning: Received ArmFailSafe (60s)
00> I: 21610 [EM]<<< [E:16639r S:7675 M:268263031] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
00> D: 21611 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
00> D: 21724 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 21725 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 21727 [EM]>>> [E:16640r S:7675 M:208197374] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:70)
00> I: 21742 [EM]<<< [E:16640r S:7675 M:268263032] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
00> D: 21743 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
00> D: 21844 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 21845 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 21847 [EM]>>> [E:16641r S:7675 M:208197375] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:62)
00> I: 21848 [ZCL]OpCreds: Certificate Chain request received for PAI
00> I: 21852 [EM]<<< [E:16641r S:7675 M:268263033] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:527)
00> D: 21853 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
00> D: 21964 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 21965 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
00> D: 22084 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 22085 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 48)
00> D: 22204 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 22205 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 22207 [EM]>>> [E:16642r S:7675 M:208197376] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:62)
00> I: 22208 [ZCL]OpCreds: Certificate Chain request received for DAC
00> I: 22212 [EM]<<< [E:16642r S:7675 M:268263034] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:557)
00> D: 22213 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
00> D: 22324 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 22325 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
00> D: 22504 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 22505 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 78)
00> D: 22624 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 22626 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 22627 [EM]>>> [E:16643r S:7675 M:208197377] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:94)
00> I: 22629 [ZCL]OpCreds: Received an AttestationRequest command
00> I: 22661 [ZCL]OpCreds: AttestationRequest successful.
00> I: 22665 [EM]<<< [E:16643r S:7675 M:268263035] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:716)
00> D: 22666 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
00> D: 22744 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 22745 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
00> D: 22864 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 22865 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 237)
00> D: 22984 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 22985 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 22987 [EM]>>> [E:16644r S:7675 M:208197378] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:65)
00> I: 22989 [FS]GeneralCommissioning: Received ArmFailSafe (60s)
00> I: 22990 [EM]<<< [E:16644r S:7675 M:268263036] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
00> D: 22991 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
00> D: 23104 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 24545 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 24547 [EM]>>> [E:16645r S:7675 M:208197379] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:94)
00> I: 24548 [ZCL]OpCreds: Received a CSRRequest command
00> I: 24604 [ZCL]OpCreds: AllocatePendingOperationalKey succeeded
00> I: 24635 [ZCL]OpCreds: CSRRequest successful.
00> I: 24637 [EM]<<< [E:16645r S:7675 M:268263037] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:391)
00> D: 24638 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
00> D: 24724 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 24725 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 154)
00> D: 24844 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 25087 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> D: 25205 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 25207 [EM]>>> [E:16646r S:7675 M:208197380] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:308)
00> I: 25209 [ZCL]OpCreds: Received an AddTrustedRootCertificate command
00> I: 25267 [ZCL]OpCreds: AddTrustedRootCertificate successful.
00> I: 25268 [EM]<<< [E:16646r S:7675 M:268263038] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:63)
00> D: 25269 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 68)
00> D: 25384 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 25387 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> D: 25506 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 25508 [EM]>>> [E:16647r S:7675 M:208197381] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:347)
00> I: 25510 [ZCL]OpCreds: Received an AddNOC command
00> I: 25512 [FP]Validating NOC chain
00> I: 25571 [FP]NOC chain validation successful
00> I: 25572 [FP]Added new fabric at index: 0x1
00> I: 25572 [FP]Assigned compressed fabric ID: 0xA897B7AA1ECB7911, node ID: 0x0000000075D78193
00> I: 25572 [TS]Last Known Good Time: 2023-10-14T01:16:48
00> I: 25573 [TS]New proposed Last Known Good Time: 2026-01-02T08:37:01
00> I: 25573 [TS]Updating pending Last Known Good Time to 2026-01-02T08:37:01
00> I: 25760 [ZCL]OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0x00000000CAAB417D
00> D: 25761 [DL]Using Thread extended MAC for hostname.
00> I: 25761 [DIS]Advertise operational node A897B7AA1ECB7911-0000000075D78193
00> E: 25761 [SVR]Operational advertising failed: 3
00> I: 25762 [ZCL]OpCreds: successfully created fabric index 0x1 via AddNOC
00> I: 25763 [EM]<<< [E:16647r S:7675 M:268263039] (S) Msg TX from 0000000000000000 to 1:FFFFFFFB00000000 [7911] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
00> D: 25764 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
00> E: 25765 [DL]Long dispatch time: 260 ms, for event type 16388
00> D: 25864 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 25866 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 25868 [EM]>>> [E:16648r S:7675 M:208197382] (S) Msg RX from 1:FFFFFFFB00000000 [7911] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:170)
00> I: 25885 [EM]<<< [E:16648r S:7675 M:268263040] (S) Msg TX from 0000000000000000 to 1:FFFFFFFB00000000 [7911] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
00> D: 25886 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
00> D: 25984 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 26105 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 26106 [EM]>>> [E:16649r S:7675 M:208197383] (S) Msg RX from 1:FFFFFFFB00000000 [7911] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:65)
00> I: 26108 [FS]GeneralCommissioning: Received ArmFailSafe (164s)
00> I: 26110 [EM]<<< [E:16649r S:7675 M:268263041] (S) Msg TX from 0000000000000000 to 1:FFFFFFFB00000000 [7911] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
00> D: 26111 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
00> D: 26224 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 26226 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 26227 [EM]>>> [E:16650r S:7675 M:208197384] (S) Msg RX from 1:FFFFFFFB00000000 [7911] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:73)
00> D: 26300 [DL]OpenThread State Changed (Flags: 0x1017c110)
00> D: 26301 [DL]   Network Name: ha-thread-4501
00> D: 26301 [DL]   PAN Id: 0x4501
00> D: 26301 [DL]   Extended PAN Id: 0xF1A16D6901D2F61D
00> D: 26301 [DL]   Channel: 15
00> D: 26302 [DL]   Mesh Prefix: fd25:f03e:3f6b:6161:0:0:0:0/64
00> D: 26303 [DL]OpenThread State Changed (Flags: 0x1100100d)
00> D: 26304 [DL]   Device Role: DETACHED
00> D: 26304 [DL]   Thread Unicast Addresses:
00> D: 26304 [DL]        fd25:f03e:3f6b:6161:4413:c474:25b2:8a8/64 valid preferred
00> D: 26305 [DL]        fe80:0:0:0:4832:bce5:8ba4:f2bf/64 valid preferred
00> I: 27755 [DL]SRP Client was started, detected server: fd25:f03e:3f6b:6161:0000:00ff:fe00:fc11
00> I: 27756 [ZCL]ThreadDiagnosticsDelegate: OnConnectionStatusChanged
00> D: 27756 [DL]OpenThread State Changed (Flags: 0x200002a4)
00> D: 27757 [DL]   Device Role: CHILD
00> D: 27757 [DL]   Partition Id: 0x425E691E
00> D: 27758 [DL]OpenThread State Changed (Flags: 0x00000001)
00> D: 27758 [DL]   Thread Unicast Addresses:
00> D: 27759 [DL]        fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2/64 valid preferred
00> D: 27759 [DL]        fd25:f03e:3f6b:6161:0:ff:fe00:4801/64 valid preferred rloc
00> D: 27760 [DL]        fd25:f03e:3f6b:6161:4413:c474:25b2:8a8/64 valid preferred
00> D: 27760 [DL]        fe80:0:0:0:4832:bce5:8ba4:f2bf/64 valid preferred
00> D: 27762 [DL]Thread Attached updating Multicast address
00> I: 27762 [SVR]Joining Multicast groups
00> I: 27764 [EM]<<< [E:16650r S:7675 M:268263042] (S) Msg TX from 0000000000000000 to 1:FFFFFFFB00000000 [7911] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:65)
00> D: 27764 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 70)
00> D: 27765 [DL]Using Thread extended MAC for hostname.
00> I: 27765 [DIS]Advertise operational node A897B7AA1ECB7911-0000000075D78193
00> E: 27766 [SVR]Operational advertising failed: 3
00> D: 27864 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
00> D: 28077 [DL]SRP update succeeded
00> I: 28077 [SVR]Server initialization complete
00> I: 28077 [DIS]Updating services using commissioning mode 0
00> D: 28078 [DL]Using Thread extended MAC for hostname.
00> I: 28078 [DIS]Advertise operational node A897B7AA1ECB7911-0000000075D78193
00> I: 28079 [DL]advertising srp service: A897B7AA1ECB7911-0000000075D78193._matter._tcp
00> I: 28095 [IM]No subscriptions to resume
00> I: 28099 [SWU]Stopping the watchdog timer
00> I: 28099 [SWU]Starting the periodic query timer, timeout: 86400 seconds
00> D: 28369 [DL]OpenThread State Changed (Flags: 0x00000200)
00> D: 28504 [DL]SRP update succeeded
00> D: 29041 [IN]UDP Message Received packet nb : 1 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 196
00> I: 29043 [EM]>>> [E:16651r S:0 M:11225278] (U) Msg RX from 0:F349DC3A8AD978EF [0000] to 0000000000000000 --- Type 0000:30 (SecureChannel:CASE_Sigma1) (B:196)
00> I: 29043 [IN]CASE Server received Sigma1 message . Starting handshake. EC 0x20014130
00> I: 29044 [EM]<<< [E:16651r S:0 M:80704047 (Ack:11225278)] (U) Msg TX from 0000000000000000 to 0:F349DC3A8AD978EF [0000] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
00> I: 29046 [SC]Received Sigma1 msg
00> I: 29053 [SC]CASE matched destination ID: fabricIndex 1, NodeID 0x0000000075D78193
00> I: 29138 [EM]<<< [E:16651r S:0 M:80704048 (Ack:11225278)] (U) Msg TX from 0000000000000000 to 0:F349DC3A8AD978EF [0000] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0000:31 (SecureChannel:CASE_Sigma2) (B:529)
00> I: 29140 [EM]??1 [E:16651r S:0 M:80704048] (U) Msg Retransmission to 0:0000000000000000 scheduled for 2358ms from now [State:Active II:500 AI:300 AT:4000]
00> I: 29141 [SC]Sent Sigma2 msg
00> D: 30223 [IN]UDP Message Received packet nb : 2 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 380
00> I: 30224 [EM]>>> [E:16651r S:0 M:11225279 (Ack:80704048)] (U) Msg RX from 0:F349DC3A8AD978EF [0000] to 0000000000000000 --- Type 0000:32 (SecureChannel:CASE_Sigma3) (B:380)
00> I: 30225 [EM]<<< [E:16651r S:0 M:80704049 (Ack:11225279)] (U) Msg TX from 0000000000000000 to 0:F349DC3A8AD978EF [0000] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
00> I: 30227 [SC]Received Sigma3 msg
00> E: 30232 [SC]The device does not support GetClock_RealTimeMS() API: 3.  Falling back to Last Known Good UTC Time
00> E: 30348 [DL]Long dispatch time: 115 ms, for event type 2
00> D: 30348 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
00> I: 30399 [EM]<<< [E:16651r S:0 M:80704050 (Ack:11225279)] (U) Msg TX from 0000000000000000 to 0:F349DC3A8AD978EF [0000] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0000:40 (SecureChannel:StatusReport) (B:34)
00> I: 30400 [EM]??1 [E:16651r S:0 M:80704050] (U) Msg Retransmission to 0:0000000000000000 scheduled for 2393ms from now [State:Active II:500 AI:300 AT:4000]
00> I: 30404 [SC]SecureSession[0x20011d80, LSID:7676]: State change 'kEstablishing' --> 'kActive'
00> D: 30404 [IN]SecureSession[0x20011d80]: Activated - Type:2 LSID:7676
00> D: 30404 [IN]New secure session activated for device <00000000CAAB417D, 1>, LSID:7676 PSID:51323!
00> I: 30405 [IN]CASE Session established to peer: <00000000CAAB417D, 1>
00> D: 30406 [IN]SecureSession[0x20011e58]: Allocated Type:2 LSID:7677
00> D: 31432 [IN]UDP Message Received packet nb : 3 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 59
00> I: 31434 [EM]>>> [E:16652r S:7676 M:267946447] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0001:08 (IM:InvokeCommandRequest) (B:59)
00> I: 31436 [FS]GeneralCommissioning: Received CommissioningComplete
00> D: 31443 [IN]UDP Message Received packet nb : 4 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 26
00> I: 31469 [FP]Metadata for Fabric 0x1 persisted to storage.
00> I: 31522 [TS]Committing Last Known Good Time to storage: 2026-01-02T08:37:01
00> I: 31541 [ZCL]OpCreds: Fabric index 0x1 was committed to storage. Compressed Fabric Id 0xA897B7AA1ECB7911, FabricId 00000000B72B81E4, NodeId 0000000075D78193, VendorId 0x1349
00> I: 31546 [FS]GeneralCommissioning: Successfully committed pending fabric data
00> I: 31546 [FS]Fail-safe cleanly disarmed
00> I: 31548 [EM]<<< [E:16652r S:7676 M:141595538 (Ack:267946447)] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:09 (IM:InvokeCommandResponse) (B:70)
00> I: 31550 [EM]??1 [E:16652r S:7676 M:141595538] (S) Msg Retransmission to 1:00000000CAAB417D scheduled for 2334ms from now [State:Active II:500 AI:300 AT:4000]
00> E: 31551 [DL]Long dispatch time: 118 ms, for event type 3
00> I: 31551 [EM]>>> [E:16651r S:0 M:11225280 (Ack:80704050)] (U) Msg RX from 0:F349DC3A8AD978EF [0000] to 0000000000000000 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
00> I: 31553 [SWU]Device commissioned, schedule a default provider query
00> I: 31553 [SVR]Commissioning completed successfully
00> I: 31553 [DIS]Updating services using commissioning mode 0
00> D: 31554 [DL]Using Thread extended MAC for hostname.
00> I: 31554 [DIS]Advertise operational node A897B7AA1ECB7911-0000000075D78193
00> D: 31555 [DL]CHIPoBLE advertising set to off
00> D: 31555 [IN]Expiring all PASE sessions
00> D: 31555 [IN]SecureSession[0x20011ca8]: MarkForEviction Type:1 LSID:7675
00> I: 31555 [SC]SecureSession[0x20011ca8, LSID:7675]: State change 'kActive' --> 'kPendingEviction'
00> D: 31556 [IN]SecureSession[0x20011ca8]: Released - Type:1 LSID:7675
00> D: 31556 [IN]Clearing BLE pending packets.
00> I: 31557 [BLE]Releasing end point's BLE connection back to application.
00> I: 31557 [DL]Closing BLE GATT connection (ConnId 00)
00> I: 31625 [DL]Current number of connections: 0/1
00> I: 31625 [DL]BLE GAP connection terminated (reason 0x16)
00> D: 31946 [IN]UDP Message Received packet nb : 5 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 34
00> I: 31948 [EM]>>> [E:16652r S:7676 M:267946448 (Ack:141595538)] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> D: 31970 [IN]UDP Message Received packet nb : 6 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 88
00> I: 31972 [EM]>>> [E:16653r S:7676 M:267946449] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0001:06 (IM:WriteRequest) (B:88)
00> D: 31972 [IM]Received Write request
00> I: 31982 [EM]<<< [E:16653r S:7676 M:141595539 (Ack:267946449)] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:07 (IM:WriteResponse) (B:62)
00> I: 31984 [EM]??1 [E:16653r S:7676 M:141595539] (S) Msg Retransmission to 1:00000000CAAB417D scheduled for 2350ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 32474 [IN]UDP Message Received packet nb : 7 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 34
00> I: 32476 [EM]>>> [E:16653r S:7676 M:267946450 (Ack:141595539)] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> D: 32487 [IN]UDP Message Received packet nb : 8 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 58
00> I: 32489 [EM]>>> [E:16654r S:7676 M:267946451] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0001:03 (IM:SubscribeRequest) (B:58)
00> D: 32490 [IM]Received Subscribe request
00> I: 32493 [DMG]Final negotiated min/max parameters: Min = 0s, Max = 300s
00> D: 32501 [IN]UDP Message Received packet nb : 9 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 51
00> I: 32528 [EM]>>> [E:16655r S:7676 M:267946452] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0001:02 (IM:ReadRequest) (B:51)
00> D: 32528 [IM]Received Read request
00> I: 32552 [EM]<<< [E:16654r S:7676 M:141595540 (Ack:267946451)] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:05 (IM:ReportData) (B:1209)
00> I: 32555 [EM]??1 [E:16654r S:7676 M:141595540] (S) Msg Retransmission to 1:00000000CAAB417D scheduled for 2403ms from now [State:Active II:500 AI:300 AT:4000]
00> I: 32561 [EM]<<< [E:16655r S:7676 M:141595541 (Ack:267946452)] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:05 (IM:ReportData) (B:162)
00> I: 32563 [EM]??1 [E:16655r S:7676 M:141595541] (S) Msg Retransmission to 1:00000000CAAB417D scheduled for 2351ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 33002 [IN]UDP Message Received packet nb : 10 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 33004 [EM]>>> [E:16654r S:7676 M:267946453 (Ack:141595540)] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 33005 [IM]Received status response, status is 0x00
00> D: 33014 [IN]UDP Message Received packet nb : 11 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 34
00> I: 33037 [EM]<<< [E:16654r S:7676 M:141595542 (Ack:267946453)] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:05 (IM:ReportData) (B:1206)
00> I: 33039 [EM]??1 [E:16654r S:7676 M:141595542] (S) Msg Retransmission to 1:00000000CAAB417D scheduled for 2350ms from now [State:Active II:500 AI:300 AT:4000]
00> I: 33041 [EM]>>> [E:16655r S:7676 M:267946454 (Ack:141595541)] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> D: 33514 [IN]UDP Message Received packet nb : 12 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 33516 [EM]>>> [E:16654r S:7676 M:267946455 (Ack:141595542)] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 33516 [IM]Received status response, status is 0x00
00> I: 33549 [EM]<<< [E:16654r S:7676 M:141595543 (Ack:267946455)] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:05 (IM:ReportData) (B:1206)
00> I: 33551 [EM]??1 [E:16654r S:7676 M:141595543] (S) Msg Retransmission to 1:00000000CAAB417D scheduled for 2389ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 34016 [IN]UDP Message Received packet nb : 13 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 34017 [EM]>>> [E:16654r S:7676 M:267946456 (Ack:141595543)] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 34018 [IM]Received status response, status is 0x00
00> I: 34053 [EM]<<< [E:16654r S:7676 M:141595544 (Ack:267946456)] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:05 (IM:ReportData) (B:1198)
00> I: 34056 [EM]??1 [E:16654r S:7676 M:141595544] (S) Msg Retransmission to 1:00000000CAAB417D scheduled for 2385ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 35015 [IN]UDP Message Received packet nb : 14 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 35017 [EM]>>> [E:16654r S:7676 M:267946457 (Ack:141595544)] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 35018 [IM]Received status response, status is 0x00
00> I: 35079 [EM]<<< [E:16654r S:7676 M:141595545 (Ack:267946457)] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:05 (IM:ReportData) (B:1189)
00> I: 35081 [EM]??1 [E:16654r S:7676 M:141595545] (S) Msg Retransmission to 1:00000000CAAB417D scheduled for 2358ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 35617 [IN]UDP Message Received packet nb : 15 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 35619 [EM]>>> [E:16654r S:7676 M:267946458 (Ack:141595545)] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 35620 [IM]Received status response, status is 0x00
00> I: 35686 [EM]<<< [E:16654r S:7676 M:141595546 (Ack:267946458)] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:05 (IM:ReportData) (B:1198)
00> I: 35689 [EM]??1 [E:16654r S:7676 M:141595546] (S) Msg Retransmission to 1:00000000CAAB417D scheduled for 2400ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 36119 [IN]UDP Message Received packet nb : 16 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 36121 [EM]>>> [E:16654r S:7676 M:267946459 (Ack:141595546)] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 36122 [IM]Received status response, status is 0x00
00> I: 36150 [EM]<<< [E:16654r S:7676 M:141595547 (Ack:267946459)] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:05 (IM:ReportData) (B:1204)
00> I: 36152 [EM]??1 [E:16654r S:7676 M:141595547] (S) Msg Retransmission to 1:00000000CAAB417D scheduled for 2380ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 36618 [IN]UDP Message Received packet nb : 17 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 36620 [EM]>>> [E:16654r S:7676 M:267946460 (Ack:141595547)] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 36621 [IM]Received status response, status is 0x00
00> I: 36627 [EM]<<< [E:16654r S:7676 M:141595548 (Ack:267946460)] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:05 (IM:ReportData) (B:301)
00> I: 36629 [EM]??1 [E:16654r S:7676 M:141595548] (S) Msg Retransmission to 1:00000000CAAB417D scheduled for 2355ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 37118 [IN]UDP Message Received packet nb : 18 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 37120 [EM]>>> [E:16654r S:7676 M:267946461 (Ack:141595548)] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 37121 [IM]Received status response, status is 0x00
00> I: 37123 [EM]<<< [E:16654r S:7676 M:141595549 (Ack:267946461)] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:04 (IM:SubscribeResponse) (B:49)
00> I: 37124 [EM]??1 [E:16654r S:7676 M:141595549] (S) Msg Retransmission to 1:00000000CAAB417D scheduled for 2405ms from now [State:Active II:500 AI:300 AT:4000]
00> I: 37125 [DMG]Registered a ReadHandler that will schedule a report between system Timestamp: 0x0000000000009105 and system Timestamp 0x00000000000524E5.
00> D: 37130 [IN]UDP Message Received packet nb : 19 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 51
00> I: 37133 [EM]>>> [E:16656r S:7676 M:267946462] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0001:02 (IM:ReadRequest) (B:51)
00> D: 37133 [IM]Received Read request
00> I: 37139 [EM]<<< [E:16656r S:7676 M:141595550 (Ack:267946462)] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:05 (IM:ReportData) (B:162)
00> I: 37141 [EM]??1 [E:16656r S:7676 M:141595550] (S) Msg Retransmission to 1:00000000CAAB417D scheduled for 2377ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 38136 [IN]UDP Message Received packet nb : 20 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 34
00> I: 38138 [EM]>>> [E:16654r S:7676 M:267946463 (Ack:141595549)] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> D: 38148 [IN]UDP Message Received packet nb : 21 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 34
00> I: 38150 [EM]>>> [E:16656r S:7676 M:267946464 (Ack:141595550)] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> D: 38161 [IN]UDP Message Received packet nb : 22 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 65
00> I: 38162 [EM]>>> [E:16657r S:7676 M:267946465] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0001:08 (IM:InvokeCommandRequest) (B:65)
00> I: 38164 [FS]GeneralCommissioning: Received ArmFailSafe (30s)
00> I: 38166 [EM]<<< [E:16657r S:7676 M:141595551 (Ack:267946465)] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:09 (IM:InvokeCommandResponse) (B:70)
00> I: 38168 [EM]??1 [E:16657r S:7676 M:141595551] (S) Msg Retransmission to 1:00000000CAAB417D scheduled for 2374ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 38662 [IN]UDP Message Received packet nb : 23 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 34
00> I: 38664 [EM]>>> [E:16657r S:7676 M:267946466 (Ack:141595551)] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> D: 38692 [IN]UDP Message Received packet nb : 24 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 94
00> I: 38693 [EM]>>> [E:16658r S:7676 M:267946467] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0001:08 (IM:InvokeCommandRequest) (B:94)
00> I: 38695 [ZCL]OpCreds: Received a CSRRequest command
00> I: 38751 [ZCL]OpCreds: AllocatePendingOperationalKey succeeded
00> I: 38781 [ZCL]OpCreds: CSRRequest successful.
00> I: 38784 [EM]<<< [E:16658r S:7676 M:141595552 (Ack:267946467)] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:09 (IM:InvokeCommandResponse) (B:396)
00> I: 38786 [EM]??1 [E:16658r S:7676 M:141595552] (S) Msg Retransmission to 1:00000000CAAB417D scheduled for 2339ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 39207 [IN]UDP Message Received packet nb : 25 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 34
00> I: 39209 [EM]>>> [E:16658r S:7676 M:267946468 (Ack:141595552)] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> D: 39268 [IN]UDP Message Received packet nb : 26 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 316
00> I: 39271 [EM]>>> [E:16659r S:7676 M:267946469] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0001:08 (IM:InvokeCommandRequest) (B:316)
00> I: 39273 [ZCL]OpCreds: Received an AddTrustedRootCertificate command
00> I: 39331 [ZCL]OpCreds: AddTrustedRootCertificate successful.
00> I: 39333 [EM]<<< [E:16659r S:7676 M:141595553 (Ack:267946469)] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:09 (IM:InvokeCommandResponse) (B:67)
00> I: 39334 [EM]??1 [E:16659r S:7676 M:141595553] (S) Msg Retransmission to 1:00000000CAAB417D scheduled for 2386ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 39769 [IN]UDP Message Received packet nb : 27 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 34
00> I: 39771 [EM]>>> [E:16659r S:7676 M:267946470 (Ack:141595553)] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> D: 39830 [IN]UDP Message Received packet nb : 28 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 349
00> I: 39833 [EM]>>> [E:16660r S:7676 M:267946471] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0001:08 (IM:InvokeCommandRequest) (B:349)
00> I: 39835 [ZCL]OpCreds: Received an AddNOC command
00> I: 39838 [FP]Validating NOC chain
00> I: 39897 [FP]NOC chain validation successful
00> I: 39897 [FP]Added new fabric at index: 0x2
00> I: 39897 [FP]Assigned compressed fabric ID: 0x68449805F555E1F7, node ID: 0x00000000B3CBCF4B
00> I: 39898 [TS]Last Known Good Time: 2026-01-02T08:37:01
00> I: 39898 [TS]New proposed Last Known Good Time: 2026-01-02T08:37:16
00> I: 39899 [TS]Updating pending Last Known Good Time to 2026-01-02T08:37:16
00> I: 39949 [ZCL]OpCreds: ACL entry created for Fabric index 0x2 CASE Admin Subject 0x000000003F82415C
00> D: 39949 [DL]Using Thread extended MAC for hostname.
00> I: 39949 [DIS]Advertise operational node A897B7AA1ECB7911-0000000075D78193
00> D: 39950 [DL]Using Thread extended MAC for hostname.
00> I: 39950 [DIS]Advertise operational node 68449805F555E1F7-00000000B3CBCF4B
00> I: 39951 [DL]advertising srp service: 68449805F555E1F7-00000000B3CBCF4B._matter._tcp
00> I: 39951 [ZCL]OpCreds: successfully created fabric index 0x2 via AddNOC
00> I: 39954 [EM]<<< [E:16660r S:7676 M:141595554 (Ack:267946471)] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:09 (IM:InvokeCommandResponse) (B:70)
00> I: 39956 [EM]??1 [E:16660r S:7676 M:141595554] (S) Msg Retransmission to 1:00000000CAAB417D scheduled for 2335ms from now [State:Active II:500 AI:300 AT:4000]
00> E: 39957 [DL]Long dispatch time: 125 ms, for event type 3
00> I: 39971 [EM]<<< [E:16127i S:7676 M:141595555] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:05 (IM:ReportData) (B:336)
00> I: 39973 [EM]??1 [E:16127i S:7676 M:141595555] (S) Msg Retransmission to 1:00000000CAAB417D scheduled for 2377ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 40708 [DL]SRP update succeeded
00> D: 40727 [IN]UDP Message Received packet nb : 29 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 34
00> I: 40728 [EM]>>> [E:16660r S:7676 M:267946472 (Ack:141595554)] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> D: 40741 [IN]UDP Message Received packet nb : 30 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 40742 [EM]>>> [E:16127i S:7676 M:267946473 (Ack:141595555)] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 40743 [IM]Received status response, status is 0x00
00> I: 40744 [EM]<<< [E:16127i S:7676 M:141595556 (Ack:267946473)] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> D: 41266 [IN]UDP Message Received packet nb : 31 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 196
00> I: 41267 [EM]>>> [E:16661r S:0 M:11225281] (U) Msg RX from 0:CB7E24C58C6B3676 [0000] to 0000000000000000 --- Type 0000:30 (SecureChannel:CASE_Sigma1) (B:196)
00> I: 41268 [IN]CASE Server received Sigma1 message . Starting handshake. EC 0x20014130
00> I: 41269 [EM]<<< [E:16661r S:0 M:80704051 (Ack:11225281)] (U) Msg TX from 0000000000000000 to 0:CB7E24C58C6B3676 [0000] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
00> I: 41271 [SC]Received Sigma1 msg
00> I: 41284 [SC]CASE matched destination ID: fabricIndex 2, NodeID 0x00000000B3CBCF4B
00> I: 41369 [EM]<<< [E:16661r S:0 M:80704052 (Ack:11225281)] (U) Msg TX from 0000000000000000 to 0:CB7E24C58C6B3676 [0000] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0000:31 (SecureChannel:CASE_Sigma2) (B:534)
00> I: 41371 [EM]??1 [E:16661r S:0 M:80704052] (U) Msg Retransmission to 0:0000000000000000 scheduled for 2338ms from now [State:Active II:500 AI:300 AT:4000]
00> I: 41372 [SC]Sent Sigma2 msg
00> E: 41372 [DL]Long dispatch time: 105 ms, for event type 3
00> D: 41823 [IN]UDP Message Received packet nb : 32 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 378
00> I: 41824 [EM]>>> [E:16661r S:0 M:11225282 (Ack:80704052)] (U) Msg RX from 0:CB7E24C58C6B3676 [0000] to 0000000000000000 --- Type 0000:32 (SecureChannel:CASE_Sigma3) (B:378)
00> I: 41825 [EM]<<< [E:16661r S:0 M:80704053 (Ack:11225282)] (U) Msg TX from 0000000000000000 to 0:CB7E24C58C6B3676 [0000] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
00> I: 41827 [SC]Received Sigma3 msg
00> E: 41831 [SC]The device does not support GetClock_RealTimeMS() API: 3.  Falling back to Last Known Good UTC Time
00> E: 41946 [DL]Long dispatch time: 114 ms, for event type 2
00> I: 41981 [EM]<<< [E:16661r S:0 M:80704054 (Ack:11225282)] (U) Msg TX from 0000000000000000 to 0:CB7E24C58C6B3676 [0000] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0000:40 (SecureChannel:StatusReport) (B:34)
00> I: 41983 [EM]??1 [E:16661r S:0 M:80704054] (U) Msg Retransmission to 0:0000000000000000 scheduled for 2397ms from now [State:Active II:500 AI:300 AT:4000]
00> I: 41986 [SC]SecureSession[0x20011e58, LSID:7677]: State change 'kEstablishing' --> 'kActive'
00> D: 41987 [IN]SecureSession[0x20011e58]: Activated - Type:2 LSID:7677
00> D: 41987 [IN]New secure session activated for device <000000003F82415C, 2>, LSID:7677 PSID:51324!
00> I: 41988 [IN]CASE Session established to peer: <000000003F82415C, 2>
00> D: 41989 [IN]SecureSession[0x20011ca8]: Allocated Type:2 LSID:7678
00> D: 42325 [IN]UDP Message Received packet nb : 33 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 59
00> I: 42327 [EM]>>> [E:16662r S:7677 M:242092586] (S) Msg RX from 2:000000003F82415C [E1F7] to 00000000B3CBCF4B --- Type 0001:08 (IM:InvokeCommandRequest) (B:59)
00> I: 42330 [FS]GeneralCommissioning: Received CommissioningComplete
00> D: 42338 [IN]UDP Message Received packet nb : 34 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 26
00> I: 42363 [FP]Metadata for Fabric 0x2 persisted to storage.
00> I: 42411 [TS]Committing Last Known Good Time to storage: 2026-01-02T08:37:16
00> I: 42419 [ZCL]OpCreds: Fabric index 0x2 was committed to storage. Compressed Fabric Id 0x68449805F555E1F7, FabricId 00000000CA992DF5, NodeId 00000000B3CBCF4B, VendorId 0x1384
00> I: 42424 [FS]GeneralCommissioning: Successfully committed pending fabric data
00> I: 42424 [FS]Fail-safe cleanly disarmed
00> I: 42426 [EM]<<< [E:16662r S:7677 M:2498354 (Ack:242092586)] (S) Msg TX from 00000000B3CBCF4B to 2:000000003F82415C [E1F7] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:09 (IM:InvokeCommandResponse) (B:70)
00> I: 42428 [EM]??1 [E:16662r S:7677 M:2498354] (S) Msg Retransmission to 2:000000003F82415C scheduled for 2337ms from now [State:Active II:500 AI:300 AT:4000]
00> E: 42429 [DL]Long dispatch time: 103 ms, for event type 3
00> I: 42430 [EM]>>> [E:16661r S:0 M:11225283 (Ack:80704054)] (U) Msg RX from 0:CB7E24C58C6B3676 [0000] to 0000000000000000 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
00> I: 42431 [SWU]Device commissioned, schedule a default provider query
00> D: 42845 [IN]UDP Message Received packet nb : 35 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 34
00> I: 42847 [EM]>>> [E:16662r S:7677 M:242092587 (Ack:2498354)] (S) Msg RX from 2:000000003F82415C [E1F7] to 00000000B3CBCF4B --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> D: 42859 [IN]UDP Message Received packet nb : 36 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 51
00> I: 42860 [EM]>>> [E:16663r S:7677 M:242092588] (S) Msg RX from 2:000000003F82415C [E1F7] to 00000000B3CBCF4B --- Type 0001:02 (IM:ReadRequest) (B:51)
00> D: 42861 [IM]Received Read request
00> I: 42866 [EM]<<< [E:16663r S:7677 M:2498355 (Ack:242092588)] (S) Msg TX from 00000000B3CBCF4B to 2:000000003F82415C [E1F7] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:05 (IM:ReportData) (B:90)
00> I: 42868 [EM]??1 [E:16663r S:7677 M:2498355] (S) Msg Retransmission to 2:000000003F82415C scheduled for 2394ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 43359 [IN]UDP Message Received packet nb : 37 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 34
00> I: 43360 [EM]>>> [E:16663r S:7677 M:242092589 (Ack:2498355)] (S) Msg RX from 2:000000003F82415C [E1F7] to 00000000B3CBCF4B --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> D: 45871 [IN]UDP Message Received packet nb : 38 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 77
00> I: 45872 [EM]>>> [E:16664r S:7676 M:267946474] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0001:08 (IM:InvokeCommandRequest) (B:77)
00> I: 45874 [ZCL]OpCreds: Received an UpdateFabricLabel command
00> I: 45879 [FP]Metadata for Fabric 0x1 persisted to storage.
00> I: 45881 [EM]<<< [E:16664r S:7676 M:141595557 (Ack:267946474)] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:09 (IM:InvokeCommandResponse) (B:70)
00> I: 45882 [EM]??1 [E:16664r S:7676 M:141595557] (S) Msg Retransmission to 1:00000000CAAB417D scheduled for 2374ms from now [State:Active II:500 AI:300 AT:4000]
00> I: 45896 [EM]<<< [E:16128i S:7676 M:141595558] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:05 (IM:ReportData) (B:269)
00> I: 45898 [EM]??1 [E:16128i S:7676 M:141595558] (S) Msg Retransmission to 1:00000000CAAB417D scheduled for 2362ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 46374 [IN]UDP Message Received packet nb : 39 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 34
00> I: 46376 [EM]>>> [E:16664r S:7676 M:267946475 (Ack:141595557)] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> D: 46387 [IN]UDP Message Received packet nb : 40 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 46388 [EM]>>> [E:16128i S:7676 M:267946476 (Ack:141595558)] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 46389 [IM]Received status response, status is 0x00
00> I: 46391 [EM]<<< [E:16128i S:7676 M:141595559 (Ack:267946476)] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> D: 46911 [IN]UDP Message Received packet nb : 41 SrcAddr : fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140[65444] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 196
00> I: 46912 [EM]>>> [E:65075r S:0 M:132275328] (U) Msg RX from 0:F15A71C0EF2CA885 [0000] to 0000000000000000 --- Type 0000:30 (SecureChannel:CASE_Sigma1) (B:196)
00> I: 46912 [IN]CASE Server received Sigma1 message . Starting handshake. EC 0x20014130
00> I: 46913 [EM]<<< [E:65075r S:0 M:80704055 (Ack:132275328)] (U) Msg TX from 0000000000000000 to 0:F15A71C0EF2CA885 [0000] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
00> I: 46915 [SC]Received Sigma1 msg
00> I: 46923 [SC]CASE matched destination ID: fabricIndex 1, NodeID 0x0000000075D78193
00> I: 47009 [EM]<<< [E:65075r S:0 M:80704056 (Ack:132275328)] (U) Msg TX from 0000000000000000 to 0:F15A71C0EF2CA885 [0000] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0000:31 (SecureChannel:CASE_Sigma2) (B:529)
00> I: 47011 [EM]??1 [E:65075r S:0 M:80704056] (U) Msg Retransmission to 0:0000000000000000 scheduled for 2400ms from now [State:Active II:500 AI:300 AT:4000]
00> I: 47012 [SC]Sent Sigma2 msg
00> E: 47013 [DL]Long dispatch time: 101 ms, for event type 3
00> D: 47468 [IN]UDP Message Received packet nb : 42 SrcAddr : fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140[65444] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 373
00> I: 47469 [EM]>>> [E:65075r S:0 M:132275329 (Ack:80704056)] (U) Msg RX from 0:F15A71C0EF2CA885 [0000] to 0000000000000000 --- Type 0000:32 (SecureChannel:CASE_Sigma3) (B:373)
00> I: 47471 [EM]<<< [E:65075r S:0 M:80704057 (Ack:132275329)] (U) Msg TX from 0000000000000000 to 0:F15A71C0EF2CA885 [0000] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
00> I: 47472 [SC]Received Sigma3 msg
00> E: 47478 [SC]The device does not support GetClock_RealTimeMS() API: 3.  Falling back to Last Known Good UTC Time
00> E: 47593 [DL]Long dispatch time: 114 ms, for event type 2
00> I: 47723 [EM]<<< [E:65075r S:0 M:80704058 (Ack:132275329)] (U) Msg TX from 0000000000000000 to 0:F15A71C0EF2CA885 [0000] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0000:40 (SecureChannel:StatusReport) (B:34)
00> I: 47725 [EM]??1 [E:65075r S:0 M:80704058] (U) Msg Retransmission to 0:0000000000000000 scheduled for 2396ms from now [State:Active II:500 AI:300 AT:4000]
00> I: 47728 [SC]SecureSession[0x20011ca8, LSID:7678]: State change 'kEstablishing' --> 'kActive'
00> D: 47729 [IN]SecureSession[0x20011ca8]: Activated - Type:2 LSID:7678
00> D: 47729 [IN]New secure session activated for device <000000004B1A4F21, 1>, LSID:7678 PSID:28403!
00> I: 47729 [IN]CASE Session established to peer: <000000004B1A4F21, 1>
00> D: 47730 [IN]SecureSession[0x20011f30]: Allocated Type:2 LSID:7679
00> E: 47731 [DL]Long dispatch time: 137 ms, for event type 2
00> D: 47973 [IN]UDP Message Received packet nb : 43 SrcAddr : fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140[65444] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 51
00> I: 47975 [EM]>>> [E:65076r S:7678 M:159653197] (S) Msg RX from 1:000000004B1A4F21 [7911] to 0000000075D78193 --- Type 0001:02 (IM:ReadRequest) (B:51)
00> D: 47976 [IM]Received Read request
00> I: 47981 [EM]<<< [E:65076r S:7678 M:233495939 (Ack:159653197)] (S) Msg TX from 0000000075D78193 to 1:000000004B1A4F21 [7911] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0001:05 (IM:ReportData) (B:70)
00> I: 47982 [EM]??1 [E:65076r S:7678 M:233495939] (S) Msg Retransmission to 1:000000004B1A4F21 scheduled for 2D: 47985 [IN]UDP Message Received packet nb : 44 SrcAddr : fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140[65444] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 26
00> 332ms from now [State:Active II:500 AI:300 AT:4000]
00> I: 48011 [EM]>>> [E:65075r S:0 M:132275330 (Ack:80704058)] (U) Msg RX from 0:F15A71C0EF2CA885 [0000] to 0000000000000000 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
00> D: 48526 [IN]UDP Message Received packet nb : 45 SrcAddr : fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140[65444] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 58
00> I: 48528 [EM]>>> [E:65077r S:7678 M:159653198] (S) Msg RX from 1:000000004B1A4F21 [7911] to 0000000075D78193 --- Type 0001:03 (IM:SubscribeRequest) (B:58)
00> D: 48529 [IM]Received Subscribe request
00> I: 48532 [DMG]Final negotiated min/max parameters: Min = 0s, Max = 300s
00> D: 48542 [IN]UDP Message Received packet nb : 46 SrcAddr : fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140[65444] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 34
00> I: 48574 [EM]>>> [E:65076r S:7678 M:159653199 (Ack:233495939)] (S) Msg RX from 1:000000004B1A4F21 [7911] to 0000000075D78193 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> I: 48603 [EM]<<< [E:65077r S:7678 M:233495940 (Ack:159653198)] (S) Msg TX from 0000000075D78193 to 1:000000004B1A4F21 [7911] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0001:05 (IM:ReportData) (B:1196)
00> I: 48606 [EM]??1 [E:65077r S:7678 M:233495940] (S) Msg Retransmission to 1:000000004B1A4F21 scheduled for 2370ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 49039 [IN]UDP Message Received packet nb : 47 SrcAddr : fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140[65444] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 49041 [EM]>>> [E:65077r S:7678 M:159653200 (Ack:233495940)] (S) Msg RX from 1:000000004B1A4F21 [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 49042 [IM]Received status response, status is 0x00
00> I: 49063 [EM]<<< [E:65077r S:7678 M:233495941 (Ack:159653200)] (S) Msg TX from 0000000075D78193 to 1:000000004B1A4F21 [7911] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0001:05 (IM:ReportData) (B:1198)
00> I: 49066 [EM]??1 [E:65077r S:7678 M:233495941] (S) Msg Retransmission to 1:000000004B1A4F21 scheduled for 2363ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 49542 [IN]UDP Message Received packet nb : 48 SrcAddr : fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140[65444] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 49544 [EM]>>> [E:65077r S:7678 M:159653201 (Ack:233495941)] (S) Msg RX from 1:000000004B1A4F21 [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 49545 [IM]Received status response, status is 0x00
00> I: 49578 [EM]<<< [E:65077r S:7678 M:233495942 (Ack:159653201)] (S) Msg TX from 0000000075D78193 to 1:000000004B1A4F21 [7911] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0001:05 (IM:ReportData) (B:1189)
00> I: 49580 [EM]??1 [E:65077r S:7678 M:233495942] (S) Msg Retransmission to 1:000000004B1A4F21 scheduled for 2401ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 50037 [IN]UDP Message Received packet nb : 49 SrcAddr : fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140[65444] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 50039 [EM]>>> [E:65077r S:7678 M:159653202 (Ack:233495942)] (S) Msg RX from 1:000000004B1A4F21 [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 50040 [IM]Received status response, status is 0x00
00> I: 50076 [EM]<<< [E:65077r S:7678 M:233495943 (Ack:159653202)] (S) Msg TX from 0000000075D78193 to 1:000000004B1A4F21 [7911] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0001:05 (IM:ReportData) (B:1209)
00> I: 50078 [EM]??1 [E:65077r S:7678 M:233495943] (S) Msg Retransmission to 1:000000004B1A4F21 scheduled for 2378ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 50537 [IN]UDP Message Received packet nb : 50 SrcAddr : fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140[65444] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 50539 [EM]>>> [E:65077r S:7678 M:159653203 (Ack:233495943)] (S) Msg RX from 1:000000004B1A4F21 [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 50540 [IM]Received status response, status is 0x00
00> I: 50580 [EM]<<< [E:65077r S:7678 M:233495944 (Ack:159653203)] (S) Msg TX from 0000000075D78193 to 1:000000004B1A4F21 [7911] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0001:05 (IM:ReportData) (B:1203)
00> I: 50582 [EM]??1 [E:65077r S:7678 M:233495944] (S) Msg Retransmission to 1:000000004B1A4F21 scheduled for 2389ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 51045 [IN]UDP Message Received packet nb : 51 SrcAddr : fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140[65444] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 51047 [EM]>>> [E:65077r S:7678 M:159653204 (Ack:233495944)] (S) Msg RX from 1:000000004B1A4F21 [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 51048 [IM]Received status response, status is 0x00
00> I: 51130 [EM]<<< [E:65077r S:7678 M:233495945 (Ack:159653204)] (S) Msg TX from 0000000075D78193 to 1:000000004B1A4F21 [7911] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0001:05 (IM:ReportData) (B:1185)
00> I: 51133 [EM]??1 [E:65077r S:7678 M:233495945] (S) Msg Retransmission to 1:000000004B1A4F21 scheduled for 2338ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 51538 [IN]UDP Message Received packet nb : 52 SrcAddr : fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140[65444] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 51540 [EM]>>> [E:65077r S:7678 M:159653205 (Ack:233495945)] (S) Msg RX from 1:000000004B1A4F21 [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 51541 [IM]Received status response, status is 0x00
00> I: 51603 [EM]<<< [E:65077r S:7678 M:233495946 (Ack:159653205)] (S) Msg TX from 0000000075D78193 to 1:000000004B1A4F21 [7911] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0001:05 (IM:ReportData) (B:1206)
00> I: 51605 [EM]??1 [E:65077r S:7678 M:233495946] (S) Msg Retransmission to 1:000000004B1A4F21 scheduled for 2407ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 52039 [IN]UDP Message Received packet nb : 53 SrcAddr : fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140[65444] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 52041 [EM]>>> [E:65077r S:7678 M:159653206 (Ack:233495946)] (S) Msg RX from 1:000000004B1A4F21 [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 52042 [IM]Received status response, status is 0x00
00> I: 52063 [EM]<<< [E:65077r S:7678 M:233495947 (Ack:159653206)] (S) Msg TX from 0000000075D78193 to 1:000000004B1A4F21 [7911] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0001:05 (IM:ReportData) (B:1078)
00> I: 52066 [EM]??1 [E:65077r S:7678 M:233495947] (S) Msg Retransmission to 1:000000004B1A4F21 scheduled for 2405ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 52539 [IN]UDP Message Received packet nb : 54 SrcAddr : fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140[65444] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 52541 [EM]>>> [E:65077r S:7678 M:159653207 (Ack:233495947)] (S) Msg RX from 1:000000004B1A4F21 [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 52543 [IM]Received status response, status is 0x00
00> I: 52544 [EM]<<< [E:65077r S:7678 M:233495948 (Ack:159653207)] (S) Msg TX from 0000000075D78193 to 1:000000004B1A4F21 [7911] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0001:04 (IM:SubscribeResponse) (B:49)
00> I: 52546 [EM]??1 [E:65077r S:7678 M:233495948] (S) Msg Retransmission to 1:000000004B1A4F21 scheduled for 2361ms from now [State:Active II:500 AI:300 AT:4000]
00> I: 52546 [DMG]Registered a ReadHandler that will schedule a report between system Timestamp: 0x000000000000CD42 and system Timestamp 0x0000000000056122.
00> D: 52571 [IN]UDP Message Received packet nb : 55 SrcAddr : fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140[65444] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 89
00> I: 52573 [EM]>>> [E:65078r S:7678 M:159653208] (S) Msg RX from 1:000000004B1A4F21 [7911] to 0000000075D78193 --- Type 0001:06 (IM:WriteRequest) (B:89)
00> D: 52574 [IM]Received Write request
00> I: 52591 [EM]<<< [E:65078r S:7678 M:233495949 (Ack:159653208)] (S) Msg TX from 0000000075D78193 to 1:000000004B1A4F21 [7911] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0001:07 (IM:WriteResponse) (B:84)
00> I: 52593 [EM]??1 [E:65078r S:7678 M:233495949] (S) Msg Retransmission to 1:000000004B1A4F21 scheduled for 2330ms from now [State:Active II:500 AI:300 AT:4000]
00> I: 52604 [EM]<<< [E:16129i S:7676 M:141595560] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:05 (IM:ReportData) (B:84)
00> I: 52606 [EM]??1 [E:16129i S:7676 M:141595560] (S) Msg Retransmission to 1:00000000CAAB417D scheduled for 2674ms from now [State:Idle II:500 AI:300 AT:4000]
00> D: 52617 [IN]UDP Message Received packet nb : 56 SrcAddr : fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140[65444] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 34
00> I: 52619 [EM]<<< [E:16130i S:7678 M:233495950] (S) Msg TX from 0000000075D78193 to 1:000000004B1A4F21 [7911] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0001:05 (IM:ReportData) (B:84)
00> I: 52621 [EM]??1 [E:16130i S:7678 M:233495950] (S) Msg Retransmission to 1:000000004B1A4F21 scheduled for 2393ms from now [State:Active II:500 AI:300 AT:4000]
00> I: 52623 [EM]>>> [E:65077r S:7678 M:159653209 (Ack:233495948)] (S) Msg RX from 1:000000004B1A4F21 [7911] to 0000000075D78193 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> D: 52638 [IN]UDP Message Received packet nb : 57 SrcAddr : fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140[65444] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 77
00> I: 52640 [EM]>>> [E:65079r S:7678 M:159653210] (S) Msg RX from 1:000000004B1A4F21 [7911] to 0000000075D78193 --- Type 0001:08 (IM:InvokeCommandRequest) (B:77)
00> I: 52642 [ZCL]OpCreds: Received an UpdateFabricLabel command
00> I: 52643 [FP]Metadata for Fabric 0x1 persisted to storage.
00> I: 52647 [EM]<<< [E:65079r S:7678 M:233495951 (Ack:159653210)] (S) Msg TX from 0000000075D78193 to 1:000000004B1A4F21 [7911] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0001:09 (IM:InvokeCommandResponse) (B:70)
00> I: 52649 [EM]??1 [E:65079r S:7678 M:233495951] (S) Msg Retransmission to 1:000000004B1A4F21 scheduled for 2407ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 52657 [IN]UDP Message Received packet nb : 58 SrcAddr : fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140[65444] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 34
00> I: 52659 [EM]>>> [E:65078r S:7678 M:159653211 (Ack:233495949)] (S) Msg RX from 1:000000004B1A4F21 [7911] to 0000000075D78193 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> D: 52713 [IN]UDP Message Received packet nb : 59 SrcAddr : fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140[65444] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 52714 [EM]>>> [E:16130i S:7678 M:159653212 (Ack:233495950)] (S) Msg RX from 1:000000004B1A4F21 [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 52716 [IM]Received status response, status is 0x00
00> I: 52717 [EM]<<< [E:16130i S:7678 M:233495952 (Ack:159653212)] (S) Msg TX from 0000000075D78193 to 1:000000004B1A4F21 [7911] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> D: 52728 [IN]UDP Message Received packet nb : 60 SrcAddr : fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140[65444] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 34
00> I: 52735 [EM]<<< [E:16131i S:7678 M:233495953] (S) Msg TX from 0000000075D78193 to 1:000000004B1A4F21 [7911] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0001:05 (IM:ReportData) (B:269)
00> I: 52737 [EM]??1 [E:16131i S:7678 M:233495953] (S) Msg Retransmission to 1:000000004B1A4F21 scheduled for 2388ms from now [State:Active II:500 AI:300 AT:4000]
00> I: 52739 [EM]>>> [E:65079r S:7678 M:159653213 (Ack:233495951)] (S) Msg RX from 1:000000004B1A4F21 [7911] to 0000000075D78193 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> D: 53229 [IN]UDP Message Received packet nb : 61 SrcAddr : fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140[65444] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 53231 [EM]>>> [E:16131i S:7678 M:159653214 (Ack:233495953)] (S) Msg RX from 1:000000004B1A4F21 [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 53232 [IM]Received status response, status is 0x00
00> I: 53233 [EM]<<< [E:16131i S:7678 M:233495954 (Ack:159653214)] (S) Msg TX from 0000000075D78193 to 1:000000004B1A4F21 [7911] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> D: 53241 [IN]UDP Message Received packet nb : 62 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 53243 [EM]>>> [E:16129i S:7676 M:267946477 (Ack:141595560)] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 53244 [IM]Received status response, status is 0x00
00> I: 53246 [EM]<<< [E:16129i S:7676 M:141595561 (Ack:267946477)] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> I: 53260 [EM]<<< [E:16132i S:7676 M:141595562] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:05 (IM:ReportData) (B:269)
00> I: 53262 [EM]??1 [E:16132i S:7676 M:141595562] (S) Msg Retransmission to 1:00000000CAAB417D scheduled for 2409ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 54242 [IN]UDP Message Received packet nb : 63 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 54244 [EM]>>> [E:16132i S:7676 M:267946478 (Ack:141595562)] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 54245 [IM]Received status response, status is 0x00
00> I: 54246 [EM]<<< [E:16132i S:7676 M:141595563 (Ack:267946478)] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> I: 72432 [SWU]Stopping the Periodic Query timer
00> I: 72432 [SWU]Starting the watchdog timer, timeout: 21600 seconds
00> D: 72433 [SWU]Establishing session to provider node ID 0x000000004B1A4F21 on fabric index 1
00> I: 72433 [DIS]Found an existing secure session to [1:000000004B1A4F21]!
00> D: 72434 [DIS]OperationalSessionSetup[1:000000004B1A4F21]: State change 1 --> 5
00> I: 72439 [EM]<<< [E:16133i S:7678 M:233495955] (S) Msg TX from 0000000075D78193 to 1:000000004B1A4F21 [7911] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0001:08 (IM:InvokeCommandRequest) (B:88)
00> I: 72441 [EM]??1 [E:16133i S:7678 M:233495955] (S) Msg Retransmission to 1:000000004B1A4F21 scheduled for 2620ms from now [State:Idle II:500 AI:300 AT:4000]
00> I: 72454 [EM]<<< [E:16134i S:7676 M:141595564] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:05 (IM:ReportData) (B:119)
00> I: 72456 [EM]??1 [E:16134i S:7676 M:141595564] (S) Msg Retransmission to 1:00000000CAAB417D scheduled for 2597ms from now [State:Idle II:500 AI:300 AT:4000]
00> I: 72468 [EM]<<< [E:16135i S:7678 M:233495956] (S) Msg TX from 0000000075D78193 to 1:000000004B1A4F21 [7911] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0001:05 (IM:ReportData) (B:119)
00> I: 72470 [EM]??1 [E:16135i S:7678 M:233495956] (S) Msg Retransmission to 1:000000004B1A4F21 scheduled for 2679ms from now [State:Idle II:500 AI:300 AT:4000]
00> D: 72515 [IN]UDP Message Received packet nb : 64 SrcAddr : fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140[65444] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 67
00> I: 72516 [EM]>>> [E:16133i S:7678 M:159653215 (Ack:233495955)] (S) Msg RX from 1:000000004B1A4F21 [7911] to 0000000075D78193 --- Type 0001:09 (IM:InvokeCommandResponse) (B:67)
00> I: 72518 [DMG]Received Command Response Data, Endpoint=0 Cluster=0x0000_0029 Command=0x0000_0001
00> D: 72518 [SWU]QueryImageResponse:
00> D: 72519 [SWU]  status: 2
00> I: 72520 [SWU]Stopping the watchdog timer
00> I: 72520 [SWU]Starting the periodic query timer, timeout: 86400 seconds
00> I: 72522 [EM]<<< [E:16133i S:7678 M:233495957 (Ack:159653215)] (S) Msg TX from 0000000075D78193 to 1:000000004B1A4F21 [7911] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> D: 72546 [IN]UDP Message Received packet nb : 65 SrcAddr : fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140[65444] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 72547 [EM]>>> [E:16135i S:7678 M:159653216 (Ack:233495956)] (S) Msg RX from 1:000000004B1A4F21 [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 72548 [IM]Received status response, status is 0x00
00> I: 72550 [EM]<<< [E:16135i S:7678 M:233495958 (Ack:159653216)] (S) Msg TX from 0000000075D78193 to 1:000000004B1A4F21 [7911] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> I: 72563 [EM]<<< [E:16136i S:7678 M:233495959] (S) Msg TX from 0000000075D78193 to 1:000000004B1A4F21 [7911] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0001:05 (IM:ReportData) (B:119)
00> I: 72565 [EM]??1 [E:16136i S:7678 M:233495959] (S) Msg Retransmission to 1:000000004B1A4F21 scheduled for 2384ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 72569 [IN]UDP Message Received packet nb : 66 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 72571 [EM]>>> [E:16134i S:7676 M:267946479 (Ack:141595564)] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 72572 [IM]Received status response, status is 0x00
00> I: 72574 [EM]<<< [E:16134i S:7676 M:141595565 (Ack:267946479)] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> I: 72588 [EM]<<< [E:16137i S:7676 M:141595566] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0001:05 (IM:ReportData) (B:119)
00> I: 72590 [EM]??1 [E:16137i S:7676 M:141595566] (S) Msg Retransmission to 1:00000000CAAB417D scheduled for 2347ms from now [State:Active II:500 AI:300 AT:4000]
00> D: 72600 [IN]UDP Message Received packet nb : 67 SrcAddr : fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140[65444] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 72602 [EM]>>> [E:16136i S:7678 M:159653217 (Ack:233495959)] (S) Msg RX from 1:000000004B1A4F21 [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 72603 [IM]Received status response, status is 0x00
00> I: 72605 [EM]<<< [E:16136i S:7678 M:233495960 (Ack:159653217)] (S) Msg TX from 0000000075D78193 to 1:000000004B1A4F21 [7911] [UDP:[fd1e:986b:3d9b:0:d87b:2ab9:ea1b:f140]:65444] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
00> D: 73101 [IN]UDP Message Received packet nb : 68 SrcAddr : 2403:e200:17a:e504:16f:d686:fa68:e43c[61057] DestAddr : fd1e:986b:3d9b:0:c65f:9350:f17a:3bc2[5540] Payload Length 42
00> I: 73102 [EM]>>> [E:16137i S:7676 M:267946480 (Ack:141595566)] (S) Msg RX from 1:00000000CAAB417D [7911] to 0000000075D78193 --- Type 0001:01 (IM:StatusResponse) (B:42)
00> I: 73103 [IM]Received status response, status is 0x00
00> I: 73104 [EM]<<< [E:16137i S:7676 M:141595567 (Ack:267946480)] (S) Msg TX from 0000000075D78193 to 1:00000000CAAB417D [7911] [UDP:[2403:e200:17a:e504:16f:d686:fa68:e43c]:61057] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
  < ot hep
00> ot hep
00> Error 35: InvalidCommand
00> 
00> rtt:~$ 
  < ot help
00> ot help
00> bbr
00> 
00> bufferinfo
00> 
00> ccathreshold
00> 
00> channel
00> 
00> childsupervision
00> 
00> childtimeout
00> 
00> coap
00> 
00> counters
00> 
00> csl
00> 
00> dataset
00> 
00> debug
00> 
00> detach
00> 
00> discover
00> 
00> dns
00> 
00> domainname
00> 
00> dua
00> 
00> eui64
00> 
00> extaddr
00> 
00> extpanid
00> 
00> factoryreset
00> 
00> fem
00> 
00> ifconfig
00> 
00> instanceid
00> 
00> ipaddr
00> 
00> ipmaddr
00> 
00> keysequence
00> 
00> leaderdata
00> 
00> log
00> 
00> mac
00> 
00> mode
00> 
00> multiradio
00> 
00> netdata
00> 
00> netstat
00> 
00> networkdiagnostic
00> 
00> networkkey
00> 
00> networkkeyref
00> 
00> networkname
00> 
00> panid
00> 
00> parent
00> 
00> ping
00> 
00> platform
00> 
00> pollperiod
00> 
00> promiscuous
00> 
00> rcp
00> 
00> region
00> 
00> reset
00> 
00> rloc16
00> 
00> scan
00> 
00> singleton
00> 
00> srp
00> 
00> state
00> 
00> thread
00> 
00> txpower
00> 
00> udp
00> 
00> unsecureport
00> 
00> uptime
00> 
00> vendor
00> 
00> version
00> 
00> Done
00> 
00> rtt:~$ 
  < ot pollperiod
00> ot pollperiod
00> 5000
00> 
00> Done
00> 
00> rtt:~$ 

 

[Susheel Nuguru]

Hi Sang, 

Can you make sure if the ICD is enabled in your build 
(CONFIG_CHIP_ENABLE_ICD_SUPPORT=y, CONFIG_CHIP_ICD_LIT_SUPPORT=y).

If you need LIT with HomeKit only, then I think it depends on HomeKit support for ICD registration. Please try with the latest iOS/HomePod firmware, or use chip-tool to perform ICD registration after HomeKit commissioning.

[sangphan]

Hi Susheel,

I build example from Nordic It already have (check on .config)

CONFIG_CHIP_ENABLE_ICD_SUPPORT=y

CONFIG_CHIP_ICD_LIT_SUPPORT=y

I dont know why Homekit isn't performing ICD registration with my device. (I check my homepod  mni, it have newest firmware 26.2)

By the way, i dont know how to use chip-tool to perform ICD registration after HomeKit commissioning 

I try command: ./chip-tool pairing code <node_id> <apple_share_code> but not work 

Cold u guide me "use chip-tool to perform ICD registration after HomeKit commissioning."

Thank alot

 

[Susheel Nuguru]

I did not use it myself but here is the documentation I know of about interactive mode with chip-tool https://docs.nordicsemi.com/bundle/ncs-latest/page/matter/chip_tool_guide.html#interactive-mode 

The intro does not show much, but there is an example on how to subscribe to events and attributes later in the guide: https://docs.nordicsemi.com/bundle/ncs-latest/page/matter/chip_tool_guide.html#subscribing-to-event…

sangphan said:

I dont know why Homekit isn't performing ICD registration with my device. (I check my homepod  mni, it have newest firmware 26.2)

This seems to be controller behavior. If the controller doesn’t register as an ICD client, the device must stay in SIT. That’s exactly what you’re seeing. The fact that chip-tool can trigger LIT confirms your firmware should be fine. Apple’s controller may not implement ICD registration yet for this device type, I am not sure.