I: 30663 [DL]CHIPoBLE advertising mode changed to slow I: 407958 [DL]BLE connection established (ConnId: 0x00) I: 407963 [DL]Current number of connections: 1/1 I: 407968 [DL]CHIPoBLE advertising stopped I: 407971 [DL]NFC Tag emulation stopped D: 408948 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 408955 [BLE]local and remote recv window sizes = 5 I: 408960 [BLE]selected BTP version 4 I: 408963 [BLE]using BTP fragment sizes rx 244 / tx 244. D: 409068 [DL]ConnId: 0x00, New CCCD value: 0x0002 D: 409072 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 6) D: 409080 [IN]BLE EndPoint 0x20011c00 Connection Complete I: 409085 [DL]CHIPoBLE connection established (ConnId: 0x00, GATT MTU: 247) D: 409248 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 409338 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 409346 [EM]Received message of type 0x20 with protocolId (0, 0) and MessageCounter:222164225 on exchange 49031r D: 409356 [EM]Handling via exchange: 49031r, Delegate: 0x20005754 D: 409362 [SC]Received PBKDF param request D: 409366 [SC]Peer assigned session ID 28885 D: 409369 [SC]Found MRP parameters in the message D: 409374 [SC]Including MRP parameters in PBKDF param response I: 409380 [IN]Prepared unauthenticated message 0x2002ef20 to 0x0000000000000000 (0) of type 0x21 and protocolId (0, 0) on exchange 49031r with MessageCounte. I: 409396 [IN]Sending unauthenticated msg 0x2002ef20 with MessageCounter:240044632 to 0x0000000000000000 at monotonic time: 0000000000063F33 msec D: 409408 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 140) D: 409416 [SC]Sent PBKDF param response D: 409473 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 409518 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 409526 [EM]Received message of type 0x22 with protocolId (0, 0) and MessageCounter:222164226 on exchange 49031r D: 409536 [EM]Found matching exchange: 49031r, Delegate: 0x20005754 D: 409542 [SC]Received spake2p msg1 I: 411524 [IN]Prepared unauthenticated message 0x2002eeb0 to 0x0000000000000000 (0) of type 0x23 and protocolId (0, 0) on exchange 49031r with MessageCounte. I: 411539 [IN]Sending unauthenticated msg 0x2002eeb0 with MessageCounter:240044633 to 0x0000000000000000 at monotonic time: 0000000000064793 msec D: 411552 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 132) D: 411560 [SC]Sent spake2p msg2 E: 411563 [DL]Long dispatch time: 2045 ms, for event type 16388 D: 411723 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 411768 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 411775 [EM]Received message of type 0x24 with protocolId (0, 0) and MessageCounter:222164227 on exchange 49031r D: 411785 [EM]Found matching exchange: 49031r, Delegate: 0x20005754 D: 411791 [SC]Received spake2p msg3 D: 411795 [SC]Sending status report. Protocol code 0, exchange 49031 I: 411801 [IN]Prepared unauthenticated message 0x2002ef38 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 49031r with MessageCounte. I: 411817 [IN]Sending unauthenticated msg 0x2002ef38 with MessageCounter:240044634 to 0x0000000000000000 at monotonic time: 00000000000648A8 msec D: 411829 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 35) I: 411838 [SC]SecureSession[0x20003570]: Moving from state 'kEstablishing' --> 'kActive' D: 411846 [IN]SecureSession[0x20003570]: Activated - Type:1 LSID:63222 D: 411852 [IN]New secure session activated for device , LSID:63222 PSID:28885! I: 411861 [SVR]Commissioning completed session establishment step I: 411867 [DIS]Updating services using commissioning mode 0 D: 411872 [DL]Using Thread extended MAC for hostname. D: 411878 [DL]Using Thread extended MAC for hostname. I: 411883 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=0 E: 411892 [DIS]Failed to advertise extended commissionable node: 3 D: 411898 [DIS]Scheduling extended discovery timeout in 900s E: 411904 [DIS]Failed to finalize service update: 1c D: 411908 [DL]CHIPoBLE advertising set to off I: 411913 [SVR]Device completed Rendezvous process E: 411917 [DL]Long dispatch time: 149 ms, for event type 16388 D: 411948 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 412083 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 412091 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:164278656 on exchange 49032r D: 412101 [EM]Handling via exchange: 49032r, Delegate: 0x2000f5cc D: 412107 [IM]Received Read request D: 412113 [DMG]IM RH moving to [GeneratingReports] D: 412118 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 412126 [DMG] Cluster 31, Attribute 3 is dirty D: 412132 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_0003 (expanded=1) D: 412141 [DMG] Cluster 28, Attribute 4 is dirty D: 412146 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0004 (expanded=0) D: 412155 [DMG] Cluster 28, Attribute 2 is dirty D: 412160 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0002 (expanded=0) D: 412169 [DMG] Cluster 30, Attribute 3 is dirty D: 412175 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0003 (expanded=0) D: 412184 [DMG] Cluster 30, Attribute 2 is dirty D: 412189 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0002 (expanded=0) D: 412198 [DMG] Cluster 30, Attribute 1 is dirty D: 412203 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0001 (expanded=0) D: 412212 [DMG] Cluster 30, Attribute 0 is dirty D: 412217 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0000 (expanded=0) D: 412226 [DMG] Cluster 31, Attribute fffc is dirty D: 412232 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFC (expanded=1) D: 412241 [DMG] Sending report (payload has 228 bytes)... I: 412248 [IN]Prepared secure message 0x2002f0d0 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 49032r with MessageCounter:15252699. I: 412262 [IN]Sending encrypted msg 0x2002f0d0 with MessageCounter:152526994 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000064A66 msec D: 412275 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 412282 [DMG] OnReportConfirm: NumReports = 0 D: 412287 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 412294 [DMG]IM RH moving to [AwaitingDestruction] D: 412299 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 412577 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 412585 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 21) D: 412713 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 412721 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 412729 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:164278657 on exchange 49033r D: 412739 [EM]Handling via exchange: 49033r, Delegate: 0x2000f5cc D: 412745 [DMG]Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000 I: 412753 [FS]GeneralCommissioning: Received ArmFailSafe (60s) D: 412759 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 848f1f2b D: 412765 [DMG]Command handler moving to [ Preparing] D: 412770 [DMG]Command handler moving to [AddingComm] D: 412775 [DMG]Command handler moving to [AddedComma] D: 412780 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 412787 [IN]Prepared secure message 0x2002ef98 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 49033r with MessageCounter:15252699. I: 412801 [IN]Sending encrypted msg 0x2002ef98 with MessageCounter:152526995 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000064C81 msec D: 412814 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 412822 [DMG]Command handler moving to [CommandSen] D: 412826 [DMG]Command handler moving to [AwaitingDe] E: 412831 [DL]Long dispatch time: 110 ms, for event type 16388 D: 412938 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 413028 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 413036 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:164278658 on exchange 49034r D: 413046 [EM]Handling via exchange: 49034r, Delegate: 0x2000f5cc D: 413052 [DMG]Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0002 D: 413078 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 848f1f2c D: 413085 [DMG]Command handler moving to [ Preparing] D: 413089 [DMG]Command handler moving to [AddingComm] D: 413094 [DMG]Command handler moving to [AddedComma] D: 413099 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 413106 [IN]Prepared secure message 0x2002ef98 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 49034r with MessageCounter:15252699. I: 413121 [IN]Sending encrypted msg 0x2002ef98 with MessageCounter:152526996 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000064DC1 msec D: 413134 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 413141 [DMG]Command handler moving to [CommandSen] D: 413146 [DMG]Command handler moving to [AwaitingDe] E: 413151 [DL]Long dispatch time: 123 ms, for event type 16388 D: 413208 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 413216 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 413224 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:164278659 on exchange 49035r D: 413234 [EM]Handling via exchange: 49035r, Delegate: 0x2000f5cc D: 413241 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 I: 413248 [ZCL]OpCreds: Certificate Chain request received for PAI D: 413254 [DMG]Command handler moving to [ Preparing] D: 413259 [DMG]Command handler moving to [AddingComm] D: 413264 [DMG]Command handler moving to [AddedComma] D: 413269 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 413278 [IN]Prepared secure message 0x2002ef98 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 49035r with MessageCounter:15252699. I: 413292 [IN]Sending encrypted msg 0x2002ef98 with MessageCounter:152526997 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000064E6C msec D: 413305 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 413313 [DMG]Command handler moving to [CommandSen] D: 413318 [DMG]Command handler moving to [AwaitingDe] E: 413322 [DL]Long dispatch time: 106 ms, for event type 16388 D: 413388 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 413395 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 413523 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 413530 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 48) D: 413658 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 413666 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 413674 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:164278660 on exchange 49036r D: 413684 [EM]Handling via exchange: 49036r, Delegate: 0x2000f5cc D: 413690 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 I: 413698 [ZCL]OpCreds: Certificate Chain request received for DAC D: 413704 [DMG]Command handler moving to [ Preparing] D: 413709 [DMG]Command handler moving to [AddingComm] D: 413714 [DMG]Command handler moving to [AddedComma] D: 413719 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 413728 [IN]Prepared secure message 0x2002ef98 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 49036r with MessageCounter:15252699. I: 413742 [IN]Sending encrypted msg 0x2002ef98 with MessageCounter:152526998 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000006502E msec D: 413755 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 413763 [DMG]Command handler moving to [CommandSen] D: 413767 [DMG]Command handler moving to [AwaitingDe] E: 413772 [DL]Long dispatch time: 106 ms, for event type 16388 D: 413838 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 413845 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 413928 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 413935 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 77) D: 414018 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 414026 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 414034 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:164278661 on exchange 49037r D: 414044 [EM]Handling via exchange: 49037r, Delegate: 0x2000f5cc D: 414051 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0000 I: 414058 [ZCL]OpCreds: Received an AttestationRequest command I: 414094 [ZCL]OpCreds: AttestationRequest successful. D: 414099 [DMG]Command handler moving to [ Preparing] D: 414104 [DMG]Command handler moving to [AddingComm] D: 414109 [DMG]Command handler moving to [AddedComma] D: 414114 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 414124 [IN]Prepared secure message 0x2002ef98 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 49037r with MessageCounter:15252699. I: 414138 [IN]Sending encrypted msg 0x2002ef98 with MessageCounter:152526999 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000000651BA msec D: 414151 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 414159 [DMG]Command handler moving to [CommandSen] D: 414164 [DMG]Command handler moving to [AwaitingDe] E: 414168 [DL]Long dispatch time: 142 ms, for event type 16388 D: 414243 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 414250 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 414333 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 414340 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 237) D: 414467 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 414513 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 414521 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:164278662 on exchange 49038r D: 414531 [EM]Handling via exchange: 49038r, Delegate: 0x2000f5cc D: 414538 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0004 I: 414545 [ZCL]OpCreds: Received a CSRRequest command D: 414550 [ZCL]OpCreds: Finding fabric with fabricIndex 0x0 I: 414752 [ZCL]OpCreds: AllocatePendingOperationalKey succeeded I: 414788 [ZCL]OpCreds: CSRRequest successful. D: 414792 [DMG]Command handler moving to [ Preparing] D: 414797 [DMG]Command handler moving to [AddingComm] D: 414801 [DMG]Command handler moving to [AddedComma] D: 414806 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 414815 [IN]Prepared secure message 0x2002ef98 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 49038r with MessageCounter:15252700. I: 414829 [IN]Sending encrypted msg 0x2002ef98 with MessageCounter:152527000 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000006546D msec D: 414842 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 414850 [DMG]Command handler moving to [CommandSen] D: 414854 [DMG]Command handler moving to [AwaitingDe] E: 414859 [DL]Long dispatch time: 346 ms, for event type 16388 D: 414918 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 414925 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 138) D: 415008 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 415055 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 415143 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 415152 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:164278663 on exchange 49039r D: 415162 [EM]Handling via exchange: 49039r, Delegate: 0x2000f5cc D: 415168 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B I: 415176 [ZCL]OpCreds: Received an AddTrustedRootCertificate command I: 415239 [ZCL]OpCreds: AddTrustedRootCertificate successful. D: 415244 [DMG]Command handler moving to [ Preparing] D: 415249 [DMG]Command handler moving to [AddingComm] D: 415254 [DMG]Command handler moving to [AddedComma] D: 415259 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 415266 [IN]Prepared secure message 0x2002ef98 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 49039r with MessageCounter:15252700. I: 415280 [IN]Sending encrypted msg 0x2002ef98 with MessageCounter:152527001 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000065630 msec D: 415293 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 68) D: 415300 [DMG]Command handler moving to [CommandSen] D: 415305 [DMG]Command handler moving to [AwaitingDe] E: 415310 [DL]Long dispatch time: 167 ms, for event type 16388 D: 415413 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 415458 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 415548 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 415557 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:164278664 on exchange 49040r D: 415567 [EM]Handling via exchange: 49040r, Delegate: 0x2000f5cc D: 415574 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0006 I: 415582 [ZCL]OpCreds: Received an AddNOC command I: 415588 [FP]Validating NOC chain I: 415649 [FP]NOC chain validation successful I: 415653 [FP]Added new fabric at index: 0x1 I: 415657 [FP]Assigned compressed fabric ID: 0x66E25C03E0B81285, node ID: 0x000000000000000B I: 415665 [TS]Last Known Good Time: 2022-10-05T09:18:27 I: 415670 [TS]New proposed Last Known Good Time: 2021-06-10T00:00:00 I: 415676 [TS]Retaining current Last Known Good Time D: 415681 [DMG]Endpoint 0, Cluster 0x0000_003E update version to e42e51dc D: 415688 [DMG]Endpoint 0, Cluster 0x0000_003E update version to e42e51dd D: 415728 [EVL]LogEvent event number: 0x0000000000050002 priority: 1, endpoint id: 0x0 cluster id: 0x0000_001F event id: 0x0 Sys timestamp: 0x000000000006570 I: 415742 [ZCL]OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0x000000000001B669 D: 415751 [DL]Using Thread extended MAC for hostname. I: 415756 [DIS]Advertise operational node 66E25C03E0B81285-000000000000000B D: 415762 [DMG]Endpoint 0, Cluster 0x0000_003E update version to e42e51de D: 415769 [DMG]Endpoint 0, Cluster 0x0000_003E update version to e42e51df D: 415776 [DMG]Command handler moving to [ Preparing] D: 415781 [DMG]Command handler moving to [AddingComm] D: 415785 [DMG]Command handler moving to [AddedComma] I: 415790 [ZCL]OpCreds: successfully created fabric index 0x1 via AddNOC D: 415797 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 415804 [IN]Prepared secure message 0x2002ef98 to 0xFFFFFFFB00000000 (1) of type 0x9 and protocolId (0, 1) on exchange 49040r with MessageCounter:15252700. I: 415818 [IN]Sending encrypted msg 0x2002ef98 with MessageCounter:152527002 to 0xFFFFFFFB00000000 (1) at monotonic time: 000000000006584A msec D: 415831 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 415839 [DMG]Command handler moving to [CommandSen] D: 415843 [DMG]Command handler moving to [AwaitingDe] E: 415848 [DL]Long dispatch time: 300 ms, for event type 16388 D: 415953 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 415961 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 415969 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:164278665 on exchange 49041r D: 415979 [EM]Handling via exchange: 49041r, Delegate: 0x2000f5cc D: 415986 [DMG]Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0003 D: 416002 [DMG]Command handler moving to [ Preparing] D: 416007 [DMG]Command handler moving to [AddingComm] D: 416011 [DMG]Command handler moving to [AddedComma] D: 416016 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 848f1f2d D: 416023 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 416030 [IN]Prepared secure message 0x2002ef98 to 0xFFFFFFFB00000000 (1) of type 0x9 and protocolId (0, 1) on exchange 49041r with MessageCounter:15252700. I: 416045 [IN]Sending encrypted msg 0x2002ef98 with MessageCounter:152527003 to 0xFFFFFFFB00000000 (1) at monotonic time: 000000000006592D msec D: 416057 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 416065 [DMG]Command handler moving to [CommandSen] D: 416070 [DMG]Command handler moving to [AwaitingDe] E: 416075 [DL]Long dispatch time: 114 ms, for event type 16388 D: 416133 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 416141 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 416149 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:164278666 on exchange 49042r D: 416159 [EM]Handling via exchange: 49042r, Delegate: 0x2000f5cc D: 416165 [DMG]Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0006 D: 416186 [DMG]Decreasing reference count for CommandHandler, remaining 1 D: 416192 [DL]OpenThread State Changed (Flags: 0x1006c100) D: 416198 [DL] Network Name: OpenThread D: 416201 [DL] PAN Id: 0x5137 D: 416204 [DL] Extended PAN Id: 0x87ED341D9DEC80E4 D: 416209 [DL] Channel: 18 D: 416212 [DL] Mesh Prefix: fdde:ad00:beef::/64 D: 416217 [DL]OpenThread State Changed (Flags: 0x1100101d) D: 416222 [DL] Device Role: DETACHED D: 416226 [DL] Thread Unicast Addresses: D: 416230 [DL] fdde:ad00:beef:0:6604:7f8a:124f:ab0d/64 valid D: 416236 [DL] fe80::d0c3:a0fc:c55b:8d3a/64 valid preferred D: 418649 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3) D: 418787 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 421308 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 423816 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3) D: 424007 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 426527 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 426540 [DL]OpenThread State Changed (Flags: 0x0000b017) D: 426545 [DL] Device Role: DETACHED D: 426548 [DL] Network Name: OpenThread D: 426552 [DL] PAN Id: 0x1411 D: 426555 [DL] Extended PAN Id: 0x87ED341D9DEC80E4 D: 426560 [DL] Channel: 18 D: 426562 [DL] Mesh Prefix: fdde:ad00:beef::/64 D: 426567 [DL] Thread Unicast Addresses: D: 426571 [DL] fdde:ad00:beef:0:6604:7f8a:124f:ab0d/64 valid D: 426577 [DL] fe80::d0c3:a0fc:c55b:8d3a/64 valid preferred I: 428050 [DL]SRP Client was started, detected server: fd70:2607:fbec:b10c:7a6f:774a:512d:4358 D: 428059 [DL]OpenThread State Changed (Flags: 0x301932b7) D: 428233 [DL] Device Role: CHILD D: 428236 [DL] Network Name: OpenThread-1411 D: 428242 [DL] PAN Id: 0x1411 D: 428245 [DL] Extended PAN Id: 0x87ED341D9DEC80E4 D: 428250 [DL] Channel: 18 D: 428253 [DL] Mesh Prefix: fd70:2607:fbec:b10c::/64 D: 428259 [DL] Partition Id: 0x1F1DB766 D: 428263 [DL] Thread Unicast Addresses: D: 428266 [DL] fd6c:1211:8162:1:c44:b5b1:e907:5c60/64 valid preferred D: 428274 [DL] fd70:2607:fbec:b10c:0:ff:fe00:c01/64 valid rloc D: 428280 [DL] fd70:2607:fbec:b10c:6604:7f8a:124f:ab0d/64 valid D: 428287 [DL] fe80::d0c3:a0fc:c55b:8d3a/64 valid preferred E: 428337 [DL]Long dispatch time: 278 ms, for event type 32777 D: 428343 [DL]OpenThread State Changed (Flags: 0x00000001) D: 428349 [DL] Thread Unicast Addresses: D: 428353 [DL] fd6c:1211:8162:1:c44:b5b1:e907:5c60/64 valid preferred D: 428362 [DL] fd70:2607:fbec:b10c:0:ff:fe00:c01/64 valid rloc D: 428368 [DL] fd70:2607:fbec:b10c:6604:7f8a:124f:ab0d/64 valid D: 428375 [DL] fe80::d0c3:a0fc:c55b:8d3a/64 valid preferred D: 428382 [DMG]Command handler moving to [ Preparing] D: 428387 [DMG]Command handler moving to [AddingComm] D: 428393 [DMG]Command handler moving to [AddedComma] D: 428398 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 848f1f2e D: 428405 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 428414 [IN]Prepared secure message 0x2002f188 to 0xFFFFFFFB00000000 (1) of type 0x9 and protocolId (0, 1) on exchange 49042r with MessageCounter:15252700. I: 428429 [IN]Sending encrypted msg 0x2002f188 with MessageCounter:152527004 to 0xFFFFFFFB00000000 (1) at monotonic time: 000000000006898D msec D: 428443 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 70) D: 428451 [DMG]Command handler moving to [CommandSen] D: 428456 [DMG]Command handler moving to [AwaitingDe] D: 428460 [DL]Using Thread extended MAC for hostname. I: 428466 [DIS]Advertise operational node 66E25C03E0B81285-000000000000000B I: 428472 [SVR]Operational advertising enabled D: 428507 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 428528 [DL]SRP update succeeded I: 428531 [DIS]Setting operational delegate post init I: 428539 [SWU]Stopping the watchdog timer I: 428543 [SWU]Starting the periodic query timer, timeout: 86400 seconds I: 428549 [DIS]Updating services using commissioning mode 0 D: 428555 [DL]Using Thread extended MAC for hostname. I: 428560 [DIS]Advertise operational node 66E25C03E0B81285-000000000000000B I: 428567 [DL]advertising srp service: 66E25C03E0B81285-000000000000000B._matter._tcp D: 428575 [DL]Using Thread extended MAC for hostname. I: 428580 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=0 I: 428626 [DL]advertising srp service: 0F4869A6508596A3._matterc._udp D: 428633 [DMG]Endpoint 0, Cluster 0x0000_002A update version to ffb35b25 D: 428640 [DMG]Endpoint 0, Cluster 0x0000_002A update version to ffb35b26 D: 429534 [DL]SRP update succeeded D: 431027 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 433535 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3) D: 433637 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 436157 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 438665 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3) D: 438767 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 441287 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 443794 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3) D: 443852 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 446372 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 448879 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3) D: 448982 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 451502 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 454010 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3) D: 454067 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 456587 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 459095 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3) D: 459152 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 461672 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 464180 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3) D: 464282 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 466802 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 469309 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3) D: 469412 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 471932 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 472759 [FS]Fail-safe timer expired E: 472763 [SVR]Failsafe timer expired D: 472766 [IN]SecureSession[0x20003570]: MarkForEviction Type:1 LSID:63222 I: 472773 [SC]SecureSession[0x20003570]: Moving from state 'kActive' --> 'kPendingEviction' D: 472781 [IN]SecureSession[0x20003570]: Released - Type:1 LSID:63222 E: 472788 [SVR]Commissioning failed (attempt 1): 32 D: 472792 [IN]Clearing BLE pending packets. I: 472796 [BLE]Releasing end point's BLE connection back to application. I: 472803 [DL]Closing BLE GATT connection (ConnId 00) D: 472810 [IN]SecureSession[0x20003570]: Allocated Type:1 LSID:63224 D: 472816 [SC]Assigned local session key ID 63224 D: 472821 [SC]Waiting for PBKDF param request D: 472825 [DL]CHIPoBLE advertising set to on I: 472829 [DIS]Updating services using commissioning mode 1 D: 472834 [DL]Using Thread extended MAC for hostname. I: 472839 [DIS]Advertise operational node 66E25C03E0B81285-000000000000000B D: 472846 [DL]Using Thread extended MAC for hostname. I: 472852 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1 I: 472862 [DL]advertising srp service: 0F4869A6508596A3._matterc._udp E: 472868 [ZCL]OpCreds: Got FailSafeTimerExpired E: 472872 [ZCL]OpCreds: Proceeding to FailSafeCleanup on fail-safe expiry! D: 472916 [IN]Expiring all sessions for fabric 0x1!! E: 472920 [FP]Reverting pending fabric data for fabric 0x1 D: 472926 [EVL]LogEvent event number: 0x0000000000050003 priority: 1, endpoint id: 0x0 cluster id: 0x0000_0028 event id: 0x2 Sys timestamp: 0x00000000000737E D: 472940 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet E: 472947 [FP]Warning: metadata not found during delete of fabric 0x1 I: 473024 [FP]Fabric (0x1) deleted. I: 473028 [ZCL]OpCreds: Fabric index 0x1 was removed D: 473033 [DMG]Endpoint 0, Cluster 0x0000_003E update version to e42e51e0 D: 473040 [DMG]Endpoint 0, Cluster 0x0000_003E update version to e42e51e1 I: 473166 [TS]Pending Last Known Good Time: 2022-10-05T09:18:27 I: 473173 [TS]Previous Last Known Good Time: 2022-10-05T09:18:27 I: 473178 [TS]Reverted Last Known Good Time to previous value D: 473184 [EVL]LogEvent event number: 0x0000000000050004 priority: 1, endpoint id: 0x0 cluster id: 0x0000_0028 event id: 0x2 Sys timestamp: 0x000000000007380 D: 473198 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet E: 473205 [FP]Warning: metadata not found during delete of fabric 0x1 E: 473213 [ZCL]OpCreds: failed to delete fabric at index 1: d8 D: 473219 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 848f1f2f D: 473226 [ZCL]Failsafe timeout, tell platform driver to revert network credentials. I: 473233 [NP]Reverting Thread operational dataset E: 473244 [DL]Long dispatch time: 481 ms, for event type 32782 I: 473250 [FS]Fail-safe cleanly disarmed D: 473255 [DL]OpenThread State Changed (Flags: 0x11002046) D: 473260 [DL] Device Role: DISABLED D: 473263 [DL] Thread Unicast Addresses: D: 473267 [DL] fd6c:1211:8162:1:c44:b5b1:e907:5c60/64 valid preferred I: 473275 [DL]BLE GAP connection terminated (reason 0x16) I: 473280 [DL]Current number of connections: 0/1 I: 473286 [DL]CHIPoBLE advertising started I: 473291 [DL]NFC Tag emulation started I: 503290 [DL]CHIPoBLE advertising mode changed to slow