I: 213125 [EM]>>> [E:18692r S:54727 M:249432821] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:65)
I: 213140 [FS]GeneralCommissioning: Received ArmFailSafe (60s)
I: 213145 [DL]********************Attribute change on endpoint 0, clusterId: 48, attributeId: 0, type: 39, size: 8, value: 3********************
I: 213159 [EM]<<< [E:18692r S:54727 M:145503153] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
D: 213173 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 213252 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 213298 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 213305 [EM]>>> [E:18693r S:54727 M:249432822] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:70)
I: 213322 [DL]********************Attribute change on endpoint 0, clusterId: 48, attributeId: 0, type: 39, size: 8, value: 4********************
I: 213335 [EM]<<< [E:18693r S:54727 M:145503154] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
D: 213350 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 213432 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 213478 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 213485 [EM]>>> [E:18694r S:54727 M:249432823] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:72)
I: 213500 [TS]Last Known Good Time: 2023-10-14T01:16:48
I: 213505 [TS]New proposed Last Known Good Time: 2025-12-04T12:50:32
I: 213511 [TS]Updating Last Known Good Time to 2025-12-04T12:50:32
I: 213517 [-]*** Time Synchronization: 818167832169047 ***
I: 213523 [DL]********************Attribute change on endpoint 0, clusterId: 56, attributeId: 2, type: 48, size: 1, value: 2********************
I: 213536 [EM]<<< [E:18694r S:54727 M:145503155] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:63)
D: 213550 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 68)
D: 213612 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 213658 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 213665 [EM]>>> [E:18695r S:54727 M:249432824] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:62)
I: 213680 [ZCL]OpCreds: Certificate Chain request received for PAI
I: 213686 [EM]<<< [E:18695r S:54727 M:145503156] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:529)
D: 213701 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 213792 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 213800 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 213882 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 213890 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 50)
D: 213972 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 214018 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 214025 [EM]>>> [E:18696r S:54727 M:249432825] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:62)
I: 214040 [ZCL]OpCreds: Certificate Chain request received for DAC
I: 214046 [EM]<<< [E:18696r S:54727 M:145503157] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:555)
D: 214061 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 214152 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 214160 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 214242 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 214250 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 76)
D: 214332 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 214378 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 214386 [EM]>>> [E:18697r S:54727 M:249432826] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:94)
I: 214400 [ZCL]OpCreds: Received an AttestationRequest command
I: 214408 [ZCL]OpCreds: AttestationRequest successful.
I: 214413 [EM]<<< [E:18697r S:54727 M:145503158] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:415)
D: 214428 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 214512 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 214520 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 178)
D: 214602 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 214738 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 214746 [EM]>>> [E:18698r S:54727 M:249432827] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:94)
I: 214760 [ZCL]OpCreds: Received a CSRRequest command
I: 214768 [ZCL]OpCreds: AllocatePendingOperationalKey succeeded
I: 214775 [ZCL]OpCreds: CSRRequest successful.
I: 214779 [EM]<<< [E:18698r S:54727 M:145503159] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:393)
D: 214794 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 214872 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 214880 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 156)
D: 214962 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 215054 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 215144 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 215152 [EM]>>> [E:18699r S:54727 M:249432828] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:463)
I: 215166 [ZCL]OpCreds: Received an AddTrustedRootCertificate command
I: 215174 [ZCL]OpCreds: AddTrustedRootCertificate successful.
I: 215180 [EM]<<< [E:18699r S:54727 M:145503160] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:63)
D: 215195 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 68)
D: 215277 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 215324 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 215414 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 215594 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 215684 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 215691 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
I: 215699 [EM]>>> [E:18700r S:54727 M:249432829] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:865)
I: 215713 [ZCL]OpCreds: Received an AddNOC command
I: 215719 [FP]Validating NOC chain
I: 215727 [FP]NOC chain validation successful
I: 215731 [FP]Added new fabric at index: 0x1
I: 215735 [FP]Assigned compressed fabric ID: 0xC652644619EF8962, node ID: 0x0000000012344321
I: 215743 [TS]Last Known Good Time: 2025-12-04T12:50:32
I: 215748 [TS]New proposed Last Known Good Time: 2021-01-01T00:00:00
I: 215754 [TS]Retaining current Last Known Good Time
I: 215779 [ZCL]OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0x000000000001B669
D: 215787 [DL]Using Thread extended MAC for hostname.
I: 215792 [DIS]Advertise operational node C652644619EF8962-0000000012344321
E: 215799 [SVR]Operational advertising failed: 3
I: 215803 [ZCL]OpCreds: successfully created fabric index 0x1 via AddNOC
I: 215810 [EM]<<< [E:18700r S:54727 M:145503161] (S) Msg TX from 0000000000000000 to 1:FFFFFFFB00000000 [8962] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
E: 215825 [DL]Long dispatch time: 141 ms, for event type 16388
D: 215831 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 215839 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 70)
D: 215907 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 215954 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 215961 [EM]>>> [E:18701r S:54727 M:249432830] (S) Msg RX from 1:FFFFFFFB00000000 [8962] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:164)
I: 215978 [DL]********************Attribute change on endpoint 0, clusterId: 48, attributeId: 0, type: 39, size: 8, value: 23********************
I: 215991 [EM]<<< [E:18701r S:54727 M:145503162] (S) Msg TX from 0000000000000000 to 1:FFFFFFFB00000000 [8962] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
D: 216005 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 216087 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 216133 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 216140 [EM]>>> [E:18702r S:54727 M:249432831] (S) Msg RX from 1:FFFFFFFB00000000 [8962] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:65)
I: 216155 [FS]GeneralCommissioning: Received ArmFailSafe (94s)
I: 216161 [DL]********************Attribute change on endpoint 0, clusterId: 48, attributeId: 0, type: 39, size: 8, value: 25********************
I: 216174 [EM]<<< [E:18702r S:54727 M:145503163] (S) Msg TX from 0000000000000000 to 1:FFFFFFFB00000000 [8962] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
D: 216189 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 216267 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 216313 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 216321 [EM]>>> [E:18703r S:54727 M:249432832] (S) Msg RX from 1:FFFFFFFB00000000 [8962] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:73)
D: 216372 [DL]OpenThread State Changed (Flags: 0x1017c110)
D: 216378 [DL]   Network Name: DEMO-EP0
D: 216381 [DL]   PAN Id: 0x1234
D: 216384 [DL]   Extended PAN Id: 0x1111111122222222
D: 216389 [DL]   Channel: 15
D: 216391 [DL]   Mesh Prefix: fd52:28e6:b27c:6ed8::/64
D: 216400 [DL]OpenThread State Changed (Flags: 0x1100100d)
D: 216405 [DL]   Device Role: DETACHED
D: 216409 [DL]   Thread Unicast Addresses:
D: 216413 [DL]        fd52:28e6:b27c:6ed8:9145:7c90:93e7:aa6a/64 valid preferred
D: 216420 [DL]        fe80::703b:8af0:5004:1153/64 valid preferred
I: 218141 [DL]SRP Client was started, detected server: fd52:28e6:b27c:6ed8:bd39:e67d:1c13:a711
D: 218150 [DL]OpenThread State Changed (Flags: 0x200002a4)
D: 218155 [DL]   Device Role: CHILD
D: 218158 [DL]   Partition Id: 0x176E8973
D: 218164 [DL]OpenThread State Changed (Flags: 0x00000001)
D: 218170 [DL]   Thread Unicast Addresses:
D: 218173 [DL]        fd11:22::6a1b:1070:749a:fff8/64 valid preferred
D: 218180 [DL]        fd52:28e6:b27c:6ed8:0:ff:fe00:2401/64 valid preferred rloc
D: 218187 [DL]        fd52:28e6:b27c:6ed8:9145:7c90:93e7:aa6a/64 valid preferred
D: 218194 [DL]        fe80::703b:8af0:5004:1153/64 valid preferred
I: 218203 [DL]********************Attribute change on endpoint 0, clusterId: 48, attributeId: 0, type: 39, size: 8, value: 27********************
I: 218216 [EM]<<< [E:18703r S:54727 M:145503164] (S) Msg TX from 0000000000000000 to 1:FFFFFFFB00000000 [8962] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:65)
D: 218231 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 70)
D: 218238 [DL]Using Thread extended MAC for hostname.
I: 218243 [DIS]Advertise operational node C652644619EF8962-0000000012344321
E: 218252 [SVR]Operational advertising failed: 3
D: 218293 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 218462 [DL]SRP update succeeded
I: 218465 [SVR]Server initialization complete
I: 218469 [DIS]Updating services using commissioning mode 0
D: 218475 [DL]Using Thread extended MAC for hostname.
I: 218480 [DIS]Advertise operational node C652644619EF8962-0000000012344321
I: 218486 [DL]advertising srp service: C652644619EF8962-0000000012344321._matter._tcp
I: 218497 [IM]No subscriptions to resume
I: 218501 [SWU]Stopping the watchdog timer
I: 218505 [SWU]Starting the periodic query timer, timeout: 86400 seconds
I: 218511 [DL]********************Attribute change on endpoint 0, clusterId: 42, attributeId: 2, type: 48, size: 1, value: 1********************
I: 218524 [DL]********************Attribute change on endpoint 0, clusterId: 42, attributeId: 3, type: 32, size: 1, value: 255********************
D: 219598 [DL]SRP update succeeded
I: 219903 [EM]>>> [E:18704r S:0 M:9827807] (U) Msg RX from 0:6FF7E2EA5D223DAD [0000] to 0000000000000000 --- Type 0000:30 (SecureChannel:CASE_Sigma1) (B:196)
I: 219917 [IN]CASE Server received Sigma1 message . Starting handshake. EC 0x2000ad00
I: 219925 [EM]<<< [E:18704r S:0 M:68006845 (Ack:9827807)] (U) Msg TX from 0000000000000000 to 0:6FF7E2EA5D223DAD [0000] [UDP:[fd11:22::a8c6:4401:1461:890d]:40978] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
I: 219944 [SC]Received Sigma1 msg
I: 219951 [SC]CASE matched destination ID: fabricIndex 1, NodeID 0x0000000012344321
I: 219964 [EM]<<< [E:18704r S:0 M:68006846 (Ack:9827807)] (U) Msg TX from 0000000000000000 to 0:6FF7E2EA5D223DAD [0000] [UDP:[fd11:22::a8c6:4401:1461:890d]:40978] --- Type 0000:31 (SecureChannel:CASE_Sigma2) (B:1050)
I: 219984 [EM]??1 [E:18704r S:0 M:68006846] (U) Msg Retransmission to 0:0000000000000000 scheduled for 1838ms from now [State:Active II:500 AI:300 AT:4000]
I: 219999 [SC]Sent Sigma2 msg
I: 220261 [EM]>>> [E:18704r S:0 M:9827808 (Ack:68006846)] (U) Msg RX from 0:6FF7E2EA5D223DAD [0000] to 0000000000000000 --- Type 0000:32 (SecureChannel:CASE_Sigma3) (B:874)
I: 220277 [EM]<<< [E:18704r S:0 M:68006847 (Ack:9827808)] (U) Msg TX from 0000000000000000 to 0:6FF7E2EA5D223DAD [0000] [UDP:[fd11:22::a8c6:4401:1461:890d]:40978] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
I: 220296 [SC]Received Sigma3 msg
E: [LoadWaterUsage] Load water usage log failed
I: 220601 [EM]<<< [E:18704r S:0 M:68006848 (Ack:9827808)] (U) Msg TX from 0000000000000000 to 0:6FF7E2EA5D223DAD [0000] [UDP:[fd11:22::a8c6:4401:1461:890d]:40978] --- Type 0000:40 (SecureChannel:StatusReport) (B:34)
I: 220620 [EM]??1 [E:18704r S:0 M:68006848] (U) Msg Retransmission to 0:0000000000000000 scheduled for 1879ms from now [State:Active II:500 AI:300 AT:4000]
I: 220636 [SC]SecureSession[0x20008530, LSID:54728]: State change 'kEstablishing' --> 'kActive'
D: 220644 [IN]SecureSession[0x20008530]: Activated - Type:2 LSID:54728
D: 220651 [IN]New secure session activated for device <000000000001B669, 1>, LSID:54728 PSID:52535!
I: 220659 [IN]CASE Session established to peer: <000000000001B669, 1>
D: 220666 [IN]SecureSession[0x20008608]: Allocated Type:2 LSID:54729
E: 220672 [DL]Long dispatch time: 365 ms, for event type 2
I: 220706 [EM]>>> [E:18705r S:54728 M:5412314] (S) Msg RX from 1:000000000001B669 [8962] to 0000000012344321 --- Type 0001:08 (IM:InvokeCommandRequest) (B:59)
I: 220723 [FS]GeneralCommissioning: Received CommissioningComplete
I: 220871 [FP]Metadata for Fabric 0x1 persisted to storage.
I: 221533 [TS]Committing Last Known Good Time to storage: 2025-12-04T12:50:32
I: 221636 [ZCL]OpCreds: Fabric index 0x1 was committed to storage. Compressed Fabric Id 0xC652644619EF8962, FabricId 0000000000000001, NodeId 0000000012344321, VendorId 0xFFF1
I: 221726 [FS]GeneralCommissioning: Successfully committed pending fabric data
I: 221733 [FS]Fail-safe cleanly disarmed
I: 221736 [DL]********************Attribute change on endpoint 0, clusterId: 48, attributeId: 0, type: 39, size: 8, value: 0********************
I: 221750 [EM]<<< [E:18705r S:54728 M:177829630 (Ack:5412314)] (S) Msg TX from 0000000012344321 to 1:000000000001B669 [8962] [UDP:[fd11:22::a8c6:4401:1461:890d]:40978] --- Type 0001:09 (IM:InvokeCommandResponse) (B:70)
I: 221770 [EM]??1 [E:18705r S:54728 M:177829630] (S) Msg Retransmission to 1:000000000001B669 scheduled for 1887ms from now [State:Active II:500 AI:300 AT:4000]
D: 221784 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 221791 [SWU]Device commissioned, schedule a default provider query
I: 221798 [SVR]Commissioning completed successfully
I: 221803 [DIS]Updating services using commissioning mode 0
D: 221808 [DL]Using Thread extended MAC for hostname.
I: 221813 [DIS]Advertise operational node C652644619EF8962-0000000012344321
D: 221819 [DL]CHIPoBLE advertising set to off
D: 221824 [IN]Expiring all PASE sessions
D: 221827 [IN]SecureSession[0x20008458]: MarkForEviction Type:1 LSID:54727
I: 221834 [SC]SecureSession[0x20008458, LSID:54727]: State change 'kActive' --> 'kPendingEviction'
D: 221842 [IN]SecureSession[0x20008458]: Released - Type:1 LSID:54727
D: 221849 [IN]Clearing BLE pending packets.
I: 221853 [BLE]Releasing end point's BLE connection back to application.
I: 221860 [DL]Closing BLE GATT connection (ConnId 00)
E: 221938 [DL]Long dispatch time: 147 ms, for event type 32783
D: 221944 [DL]ConnId: 0x00, New CCCD value: 0x0000
I: 221948 [DL]********************Attribute change on endpoint 1, clusterId: 47, attributeId: 11, type: 35, size: 4, value: 2970********************
I: 221961 [DL]********************Attribute change on endpoint 1, clusterId: 47, attributeId: 12, type: 32, size: 1, value: 197********************
I: 221976 [EM]>>> [E:18704r S:0 M:9827809 (Ack:68006848)] (U) Msg RX from 0:6FF7E2EA5D223DAD [0000] to 0000000000000000 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
I: 221992 [DL]Current number of connections: 0/1
I: 221996 [DL]BLE GAP connection terminated (reason 0x16)
I: 222201 [EM]>>> [E:18705r S:54728 M:5412315 (Ack:177829630)] (S) Msg RX from 1:000000000001B669 [8962] to 0000000012344321 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
I: 232024 [EM]>>> [E:23391r S:0 M:23835024] (U) Msg RX from 0:993CA100DFF13639 [0000] to 0000000000000000 --- Type 0000:30 (SecureChannel:CASE_Sigma1) (B:196)
I: 232038 [IN]CASE Server received Sigma1 message . Starting handshake. EC 0x2000ad00
I: 232045 [EM]<<< [E:23391r S:0 M:68006849 (Ack:23835024)] (U) Msg TX from 0000000000000000 to 0:993CA100DFF13639 [0000] [UDP:[fd11:22::a8c6:4401:1461:890d]:50820] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
I: 232065 [SC]Received Sigma1 msg
I: 232071 [SC]CASE matched destination ID: fabricIndex 1, NodeID 0x0000000012344321
I: 232084 [EM]<<< [E:23391r S:0 M:68006850 (Ack:23835024)] (U) Msg TX from 0000000000000000 to 0:993CA100DFF13639 [0000] [UDP:[fd11:22::a8c6:4401:1461:890d]:50820] --- Type 0000:31 (SecureChannel:CASE_Sigma2) (B:1050)
I: 232104 [EM]??1 [E:23391r S:0 M:68006850] (U) Msg Retransmission to 0:0000000000000000 scheduled for 1838ms from now [State:Active II:500 AI:300 AT:4000]
I: 232119 [SC]Sent Sigma2 msg
I: 232399 [EM]>>> [E:23391r S:0 M:23835025 (Ack:68006850)] (U) Msg RX from 0:993CA100DFF13639 [0000] to 0000000000000000 --- Type 0000:32 (SecureChannel:CASE_Sigma3) (B:774)
I: 232415 [EM]<<< [E:23391r S:0 M:68006851 (Ack:23835025)] (U) Msg TX from 0000000000000000 to 0:993CA100DFF13639 [0000] [UDP:[fd11:22::a8c6:4401:1461:890d]:50820] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
I: 232435 [SC]Received Sigma3 msg
I: 232634 [EM]<<< [E:23391r S:0 M:68006852 (Ack:23835025)] (U) Msg TX from 0000000000000000 to 0:993CA100DFF13639 [0000] [UDP:[fd11:22::a8c6:4401:1461:890d]:50820] --- Type 0000:40 (SecureChannel:StatusReport) (B:34)
I: 232654 [EM]??1 [E:23391r S:0 M:68006852] (U) Msg Retransmission to 0:0000000000000000 scheduled for 1870ms from now [State:Active II:500 AI:300 AT:4000]
I: 232669 [SC]SecureSession[0x20008608, LSID:54729]: State change 'kEstablishing' --> 'kActive'
D: 232677 [IN]SecureSession[0x20008608]: Activated - Type:2 LSID:54729
D: 232684 [IN]New secure session activated for device <000000000001B669, 1>, LSID:54729 PSID:50231!
I: 232692 [IN]CASE Session established to peer: <000000000001B669, 1>
D: 232699 [IN]SecureSession[0x20008458]: Allocated Type:2 LSID:54730
E: 232705 [DL]Long dispatch time: 260 ms, for event type 2
I: 232727 [EM]>>> [E:23391r S:0 M:23835026 (Ack:68006852)] (U) Msg RX from 0:993CA100DFF13639 [0000] to 0000000000000000 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
I: 232759 [EM]>>> [E:23392r S:54729 M:212410331] (S) Msg RX from 1:000000000001B669 [8962] to 0000000012344321 --- Type 0001:02 (IM:ReadRequest) (B:42)
D: 232772 [IM]Received Read request
I: 232792 [EM]<<< [E:23392r S:54729 M:251812853 (Ack:212410331)] (S) Msg TX from 0000000012344321 to 1:000000000001B669 [8962] [UDP:[fd11:22::a8c6:4401:1461:890d]:50820] --- Type 0001:05 (IM:ReportData) (B:1186)
I: 232812 [EM]??1 [E:23392r S:54729 M:251812853] (S) Msg Retransmission to 1:000000000001B669 scheduled for 1865ms from now [State:Active II:500 AI:300 AT:4000]
I: 233704 [EM]>>> [E:23392r S:54729 M:212410332 (Ack:251812853)] (S) Msg RX from 1:000000000001B669 [8962] to 0000000012344321 --- Type 0001:01 (IM:StatusResponse) (B:42)
I: 233719 [IM]Received status response, status is 0x00
I: 233739 [EM]<<< [E:23392r S:54729 M:251812854 (Ack:212410332)] (S) Msg TX from 0000000012344321 to 1:000000000001B669 [8962] [UDP:[fd11:22::a8c6:4401:1461:890d]:50820] --- Type 0001:05 (IM:ReportData) (B:1208)
I: 233759 [EM]??1 [E:23392r S:54729 M:251812854] (S) Msg Retransmission to 1:000000000001B669 scheduled for 1867ms from now [State:Active II:500 AI:300 AT:4000]
I: 234646 [EM]>>> [E:23392r S:54729 M:212410333 (Ack:251812854)] (S) Msg RX from 1:000000000001B669 [8962] to 0000000012344321 --- Type 0001:01 (IM:StatusResponse) (B:42)
I: 234661 [IM]Received status response, status is 0x00
I: 234684 [EM]<<< [E:23392r S:54729 M:251812855 (Ack:212410333)] (S) Msg TX from 0000000012344321 to 1:000000000001B669 [8962] [UDP:[fd11:22::a8c6:4401:1461:890d]:50820] --- Type 0001:05 (IM:ReportData) (B:1198)
I: 234704 [EM]??1 [E:23392r S:54729 M:251812855] (S) Msg Retransmission to 1:000000000001B669 scheduled for 1861ms from now [State:Active II:500 AI:300 AT:4000]
I: 235582 [EM]>>> [E:23392r S:54729 M:212410334 (Ack:251812855)] (S) Msg RX from 1:000000000001B669 [8962] to 0000000012344321 --- Type 0001:01 (IM:StatusResponse) (B:42)
I: 235597 [IM]Received status response, status is 0x00
I: 235606 [EM]<<< [E:23392r S:54729 M:251812856 (Ack:212410334)] (S) Msg TX from 0000000012344321 to 1:000000000001B669 [8962] [UDP:[fd11:22::a8c6:4401:1461:890d]:50820] --- Type 0001:05 (IM:ReportData) (B:1141)
I: 235626 [EM]??1 [E:23392r S:54729 M:251812856] (S) Msg Retransmission to 1:000000000001B669 scheduled for 1884ms from now [State:Active II:500 AI:300 AT:4000]
I: 235988 [EM]>>> [E:23392r S:54729 M:212410335 (Ack:251812856)] (S) Msg RX from 1:000000000001B669 [8962] to 0000000012344321 --- Type 0001:01 (IM:StatusResponse) (B:42)
I: 236003 [IM]Received status response, status is 0x00
I: 236015 [EM]<<< [E:23392r S:54729 M:251812857 (Ack:212410335)] (S) Msg TX from 0000000012344321 to 1:000000000001B669 [8962] [UDP:[fd11:22::a8c6:4401:1461:890d]:50820] --- Type 0001:05 (IM:ReportData) (B:1184)
I: 236034 [EM]??1 [E:23392r S:54729 M:251812857] (S) Msg Retransmission to 1:000000000001B669 scheduled for 1875ms from now [State:Active II:500 AI:300 AT:4000]
I: 236645 [EM]>>> [E:23392r S:54729 M:212410336 (Ack:251812857)] (S) Msg RX from 1:000000000001B669 [8962] to 0000000012344321 --- Type 0001:01 (IM:StatusResponse) (B:42)
I: 236660 [IM]Received status response, status is 0x00
I: 236673 [EM]<<< [E:23392r S:54729 M:251812858 (Ack:212410336)] (S) Msg TX from 0000000012344321 to 1:000000000001B669 [8962] [UDP:[fd11:22::a8c6:4401:1461:890d]:50820] --- Type 0001:05 (IM:ReportData) (B:1187)
I: 236693 [EM]??1 [E:23392r S:54729 M:251812858] (S) Msg Retransmission to 1:000000000001B669 scheduled for 1868ms from now [State:Active II:500 AI:300 AT:4000]
I: 237586 [EM]>>> [E:23392r S:54729 M:212410337 (Ack:251812858)] (S) Msg RX from 1:000000000001B669 [8962] to 0000000012344321 --- Type 0001:01 (IM:StatusResponse) (B:42)
I: 237601 [IM]Received status response, status is 0x00
I: 237614 [EM]<<< [E:23392r S:54729 M:251812859 (Ack:212410337)] (S) Msg TX from 0000000012344321 to 1:000000000001B669 [8962] [UDP:[fd11:22::a8c6:4401:1461:890d]:50820] --- Type 0001:05 (IM:ReportData) (B:1203)
I: 237634 [EM]??1 [E:23392r S:54729 M:251812859] (S) Msg Retransmission to 1:000000000001B669 scheduled for 1831ms from now [State:Active II:500 AI:300 AT:4000]
I: 238521 [EM]>>> [E:23392r S:54729 M:212410338 (Ack:251812859)] (S) Msg RX from 1:000000000001B669 [8962] to 0000000012344321 --- Type 0001:01 (IM:StatusResponse) (B:42)
I: 238536 [IM]Received status response, status is 0x00
I: 238549 [EM]<<< [E:23392r S:54729 M:251812860 (Ack:212410338)] (S) Msg TX from 0000000012344321 to 1:000000000001B669 [8962] [UDP:[fd11:22::a8c6:4401:1461:890d]:50820] --- Type 0001:05 (IM:ReportData) (B:1207)
I: 238569 [EM]??1 [E:23392r S:54729 M:251812860] (S) Msg Retransmission to 1:000000000001B669 scheduled for 1884ms from now [State:Active II:500 AI:300 AT:4000]
I: 239461 [EM]>>> [E:23392r S:54729 M:212410339 (Ack:251812860)] (S) Msg RX from 1:000000000001B669 [8962] to 0000000012344321 --- Type 0001:01 (IM:StatusResponse) (B:42)
I: 239476 [IM]Received status response, status is 0x00
I: 239489 [EM]<<< [E:23392r S:54729 M:251812861 (Ack:212410339)] (S) Msg TX from 0000000012344321 to 1:000000000001B669 [8962] [UDP:[fd11:22::a8c6:4401:1461:890d]:50820] --- Type 0001:05 (IM:ReportData) (B:1181)
I: 239509 [EM]??1 [E:23392r S:54729 M:251812861] (S) Msg Retransmission to 1:000000000001B669 scheduled for 1888ms from now [State:Active II:500 AI:300 AT:4000]
I: 240377 [EM]>>> [E:23392r S:54729 M:212410340 (Ack:251812861)] (S) Msg RX from 1:000000000001B669 [8962] to 0000000012344321 --- Type 0001:01 (IM:StatusResponse) (B:42)
I: 240392 [IM]Received status response, status is 0x00
I: 240398 [EM]<<< [E:23392r S:54729 M:251812862 (Ack:212410340)] (S) Msg TX from 0000000012344321 to 1:000000000001B669 [8962] [UDP:[fd11:22::a8c6:4401:1461:890d]:50820] --- Type 0001:05 (IM:ReportData) (B:294)
I: 240417 [EM]??1 [E:23392r S:54729 M:251812862] (S) Msg Retransmission to 1:000000000001B669 scheduled for 1830ms from now [State:Active II:500 AI:300 AT:4000]
I: 241230 [EM]>>> [E:23392r S:54729 M:212410341 (Ack:251812862)] (S) Msg RX from 1:000000000001B669 [8962] to 0000000012344321 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
E: 251797 [SWU]No suitable OTA Provider candidate found
I: 251802 [SWU]No provider available
I: 260024 [DL]********************Attribute change on endpoint 1, clusterId: 47, attributeId: 11, type: 35, size: 4, value: 2988********************
I: 260037 [DL]********************Attribute change on endpoint 1, clusterId: 47, attributeId: 12, type: 32, size: 1, value: 198********************
I: 270030 [DL]********************Attribute change on endpoint 5, clusterId: 4294048769, attributeId: 4293984260, type: 41, size: 2, value: 2480********************
I: 330030 [DL]********************Attribute change on endpoint 5, clusterId: 4294048769, attributeId: 4293984260, type: 41, size: 2, value: 2470********************
I: 360030 [DL]********************Attribute change on endpoint 5, clusterId: 4294048769, attributeId: 4293984260, type: 41, size: 2, value: 2480********************
I: 390026 [DL]********************Attribute change on endpoint 1, clusterId: 47, attributeId: 11, type: 35, size: 4, value: 2995********************
I: 390039 [DL]********************Attribute change on endpoint 1, clusterId: 47, attributeId: 12, type: 32, size: 1, value: 199********************
I: 390053 [DL]********************Attribute change on endpoint 5, clusterId: 4294048769, attributeId: 4293984260, type: 41, size: 2, value: 2470********************
I: 455027 [DL]********************Attribute change on endpoint 1, clusterId: 47, attributeId: 11, type: 35, size: 4, value: 2988********************
I: 455040 [DL]********************Attribute change on endpoint 1, clusterId: 47, attributeId: 12, type: 32, size: 1, value: 198********************
D: 457408 [DL]OpenThread State Changed (Flags: 0x00000044)
D: 457413 [DL]   Device Role: DETACHED
I: 458480 [DL]SRP Client was stopped, because current server is no longer detected.
D: 458488 [DL]OpenThread State Changed (Flags: 0x200002a4)
D: 458494 [DL]   Device Role: CHILD
D: 458497 [DL]   Partition Id: 0x31E5E6EE
I: 458612 [DL]SRP Client was started, detected server: fd6f:d788:38b6:46e7:d395:6c3b:7883:b4ed
D: 458621 [DL]OpenThread State Changed (Flags: 0x00000200)
I: 469575 [EM]>>> [E:59239r S:0 M:79979811] (U) Msg RX from 0:2E991A1228AED5A9 [0000] to 0000000000000000 --- Type 0000:30 (SecureChannel:CASE_Sigma1) (B:196)
I: 469589 [IN]CASE Server received Sigma1 message . Starting handshake. EC 0x2000ad00
I: 469597 [EM]<<< [E:59239r S:0 M:68006853 (Ack:79979811)] (U) Msg TX from 0000000000000000 to 0:2E991A1228AED5A9 [0000] [UDP:[fd11:22::f18:2886:ad16:49d6]:35726] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
I: 469617 [SC]Received Sigma1 msg
I: 469623 [SC]CASE matched destination ID: fabricIndex 1, NodeID 0x0000000012344321
I: 469636 [EM]<<< [E:59239r S:0 M:68006854 (Ack:79979811)] (U) Msg TX from 0000000000000000 to 0:2E991A1228AED5A9 [0000] [UDP:[fd11:22::f18:2886:ad16:49d6]:35726] --- Type 0000:31 (SecureChannel:CASE_Sigma2) (B:1050)
I: 469656 [EM]??1 [E:59239r S:0 M:68006854] (U) Msg Retransmission to 0:0000000000000000 scheduled for 1861ms from now [State:Active II:500 AI:300 AT:4000]
I: 469671 [SC]Sent Sigma2 msg
I: 469918 [EM]>>> [E:59239r S:0 M:79979812 (Ack:68006854)] (U) Msg RX from 0:2E991A1228AED5A9 [0000] to 0000000000000000 --- Type 0000:32 (SecureChannel:CASE_Sigma3) (B:774)
I: 469933 [EM]<<< [E:59239r S:0 M:68006855 (Ack:79979812)] (U) Msg TX from 0000000000000000 to 0:2E991A1228AED5A9 [0000] [UDP:[fd11:22::f18:2886:ad16:49d6]:35726] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
I: 469953 [SC]Received Sigma3 msg
I: 470144 [EM]<<< [E:59239r S:0 M:68006856 (Ack:79979812)] (U) Msg TX from 0000000000000000 to 0:2E991A1228AED5A9 [0000] [UDP:[fd11:22::f18:2886:ad16:49d6]:35726] --- Type 0000:40 (SecureChannel:StatusReport) (B:34)
I: 470163 [EM]??1 [E:59239r S:0 M:68006856] (U) Msg Retransmission to 0:0000000000000000 scheduled for 1873ms from now [State:Active II:500 AI:300 AT:4000]
I: 470178 [SC]SecureSession[0x20008458, LSID:54730]: State change 'kEstablishing' --> 'kActive'
D: 470187 [IN]SecureSession[0x20008458]: Activated - Type:2 LSID:54730
D: 470193 [IN]New secure session activated for device <000000000001B669, 1>, LSID:54730 PSID:7873!
I: 470202 [IN]CASE Session established to peer: <000000000001B669, 1>
D: 470208 [IN]SecureSession[0x200086e0]: Allocated Type:2 LSID:54731
E: 470214 [DL]Long dispatch time: 250 ms, for event type 2
I: 470235 [EM]>>> [E:59240r S:54730 M:211712336] (S) Msg RX from 1:000000000001B669 [8962] to 0000000012344321 --- Type 0001:0A (IM:TimedRequest) (B:39)
I: 470248 [EM]<<< [E:59240r S:54730 M:60288203 (Ack:211712336)] (S) Msg TX from 0000000012344321 to 1:000000000001B669 [8962] [UDP:[fd11:22::f18:2886:ad16:49d6]:35726] --- Type 0001:01 (IM:StatusResponse) (B:42)
I: 470270 [EM]??1 [E:59240r S:54730 M:60288203] (S) Msg Retransmission to 1:000000000001B669 scheduled for 1882ms from now [State:Active II:500 AI:300 AT:4000]
I: 470284 [EM]>>> [E:59239r S:0 M:79979813 (Ack:68006856)] (U) Msg RX from 0:2E991A1228AED5A9 [0000] to 0000000000000000 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
E: 470322 [DL]SRP update error: timed out waiting on server response
I: 470351 [EM]>>> [E:59240r S:54730 M:211712337 (Ack:60288203)] (S) Msg RX from 1:000000000001B669 [8962] to 0000000012344321 --- Type 0001:08 (IM:InvokeCommandRequest) (B:209)
I: 470367 [ZCL]Received command to open commissioning window
D: 470373 [IN]SecureSession[0x200087b8]: Allocated Type:1 LSID:54732
I: 470379 [DIS]Updating services using commissioning mode 2
D: 470384 [DL]Using Thread extended MAC for hostname.
I: 470389 [DIS]Advertise operational node C652644619EF8962-0000000012344321
D: 470396 [DL]Using Thread extended MAC for hostname.
I: 470401 [DIS]Advertise commission parameter vendorID=4992 productID=17 discriminator=2178/08 cm=2 cp=0
I: 470410 [DL]advertising srp service: A8B9E1358598B091._matterc._udp
I: 470416 [ZCL]Commissioning window is now open
I: 470421 [EM]<<< [E:59240r S:54730 M:60288204 (Ack:211712337)] (S) Msg TX from 0000000012344321 to 1:000000000001B669 [8962] [UDP:[fd11:22::f18:2886:ad16:49d6]:35726] --- Type 0001:09 (IM:InvokeCommandResponse) (B:67)
I: 470441 [EM]??1 [E:59240r S:54730 M:60288204] (S) Msg Retransmission to 1:000000000001B669 scheduled for 1857ms from now [State:Active II:500 AI:300 AT:4000]
I: 470553 [EM]>>> [E:59240r S:54730 M:211712338 (Ack:60288204)] (S) Msg RX from 1:000000000001B669 [8962] to 0000000012344321 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
E: 473663 [DL]SRP update error: timed out waiting on server response
E: 478909 [DL]SRP update error: timed out waiting on server response
I: 480030 [DL]********************Attribute change on endpoint 5, clusterId: 4294048769, attributeId: 4293984260, type: 41, size: 2, value: 2480********************
E: 488155 [DL]SRP update error: timed out waiting on server response
E: 503485 [DL]SRP update error: timed out waiting on server response
I: 520028 [DL]********************Attribute change on endpoint 1, clusterId: 47, attributeId: 11, type: 35, size: 4, value: 2991********************
I: 520041 [DL]********************Attribute change on endpoint 1, clusterId: 47, attributeId: 12, type: 32, size: 1, value: 199********************
E: 529037 [DL]SRP update error: timed out waiting on server response
E: 572697 [DL]SRP update error: timed out waiting on server response
I: 585029 [DL]********************Attribute change on endpoint 1, clusterId: 47, attributeId: 11, type: 35, size: 4, value: 2995********************
E: 646799 [DL]SRP update error: timed out waiting on server response
I: 650030 [DL]********************Attribute change on endpoint 1, clusterId: 47, attributeId: 11, type: 35, size: 4, value: 2998********************
I: 650372 [SVR]Closing pairing window
D: 650375 [IN]SecureSession[0x200087b8]: Released - Type:1 LSID:54732
I: 650382 [DIS]Updating services using commissioning mode 0
D: 650387 [DL]Using Thread extended MAC for hostname.
I: 650392 [DIS]Advertise operational node C652644619EF8962-0000000012344321
I: 650398 [DL]removing srp service: A8B9E1358598B091._matterc._udp
