Xshell 6 (Build 0149) Copyright (c) 2002 NetSarang Computer, Inc. All rights reserved. Type `help' to learn how to use Xshell prompt. [C:\~]$ Connecting to COM4... Connected. uart:~$ uart:~$ uart:~$ uart:~$ I: Factory Reset Triggered. Release button within 3000ms to cancel. I: Factory Reset triggered I: 36300 [TS]Pending Last Known Good Time: 2022-10-17T10:31:31 I: 36306 [TS]Previous Last Known Good Time: 2022-10-17T10:31:31 I: 36312 [TS]Reverted Last Known Good Time to previous value D: 36317 [ZCL]Emitting ShutDown event D: 36321 [EVL]LogEvent event number: 0x0000000000020002 priority: 2, endpoint id: 0x0 cluster id: 0x0000_0028 event id: 0x1 Sys timestamp: 0x0000000000008DE1 D: 36335 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 36341 [DL]Performing factory reset I: 36368 [DL]Erasing Thread persistent info... I: nRF5 802154 radio initialized I: 4 Sectors of 4096 bytes I: alloc wra: 1, d78 I: data wra: 1, 1d0 ooting Zephyr OS build v3.1.99-ncs1 *** I: Init CHIP stack 32muart:~$ I: 228 [DL]BLE address: C8:39:B7:1B:4B:14 I: SoftDevice Controller build revision: I: f2 e7 5f 6f 23 a2 f3 e8 |.._o#... I: 10 2f c3 35 9e d7 1d fe |./.5.... I: 8f 80 42 f9 |..B. I: 251 [DL]OpenThread SED interval set to 1000ms I: 258 [DL]OpenThread started: OK I: 261 [DL]Setting OpenThread device type to SLEEPY END DEVICE I: 267 [SVR]Server initializing... D: 270 [FP]Initializing FabricTable from persistent storage I: 276 [TS]Last Known Good Time: [unknown] I: 280 [TS]Setting Last Known Good Time to firmware build time 2022-10-17T10:31:31 I: 292 [DMG]AccessControl: initializing I: 295 [DMG]Examples::AccessControlDelegate::Init I: 300 [DMG]AccessControl: setting I: 303 [DMG]DefaultAclStorage: initializing I: 307 [DMG]DefaultAclStorage: 0 entries loaded D: 311 [IN]UDP::Init bind&listen port=5540 E: 315 [IN]SO_REUSEPORT failed: 109 D: 318 [IN]UDP::Init bound to port=5540 D: 322 [IN]BLEBase::Init - setting/overriding transport D: 327 [IN]TransportMgr initialized D: 337 [DL]Using Thread extended MAC for hostname. I: 346 [ZCL]Using ZAP configuration... D: 350 [DMG]Failed to read stored attribute (0, 0x0000_0028, 0x0000_0005: a0 D: 357 [DMG]Failed to read stored attribute (0, 0x0000_0028, 0x0000_0010: a0 I: 365 [DMG]AccessControlCluster: initializing D: 370 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 1c59f80b D: 376 [DL]Boot reason: 6 D: 378 [ZCL]GeneralDiagnostics: OnDeviceReboot D: 382 [DMG]Endpoint 0, Cluster 0x0000_0033 update version to 7bb9fb36 D: 389 [EVL]LogEvent event number: 0x0000000000000000 priority: 2, endpoint id: 0x0 cluster id: 0x0000_0033 event id: 0x3 Sys timestamp: 0x0000000000000185 I: 403 [ZCL]Initiating Admin Commissioning cluster. I: 407 [ZCL]Door Lock server initialized I: 411 [ZCL]Door Lock cluster initialized at endpoint #1 D: 416 [DMG]Endpoint 1, Cluster 0x0000_0101 update version to b26ffded D: 423 [DMG]Endpoint 1, Cluster 0x0000_0101 update version to b26ffdee D: 429 [DMG]Endpoint 1, Cluster 0x0000_0101 update version to b26ffdef D: 435 [DMG]Endpoint 1, Cluster 0x0000_0101 update version to b26ffdf0 D: 442 [DMG]Endpoint 1, Cluster 0x0000_0101 update version to b26ffdf1 D: 448 [DMG]Endpoint 1, Cluster 0x0000_0101 update version to b26ffdf2 D: 455 [DMG]Endpoint 1, Cluster 0x0000_0101 update version to b26ffdf3 D: 461 [DMG]Endpoint 1, Cluster 0x0000_0101 update version to b26ffdf4 I: 467 [DIS]Updating services using commissioning mode 0 D: 472 [DL]Using Thread extended MAC for hostname. D: 477 [DL]Using Thread extended MAC for hostname. I: 482 [DIS]Advertise commission parameter vendorID=65521 productID=32774 discriminator=3847/15 cm=0 E: 491 [DIS]Failed to advertise extended commissionable node: 3 D: 497 [DIS]Scheduling extended discovery timeout in 900s E: 502 [DIS]Failed to finalize service update: 1c I: 507 [DIS]Delaying proxy of operational discovery: missing delegate I: 513 [IN]CASE Server enabling CASE session setups D: 518 [IN]SecureSession[0x200038d0]: Allocated Type:2 LSID:21254 D: 524 [SC]Allocated SecureSession (0x200038d0) - waiting for Sigma1 msg I: 530 [SVR]Joining Multicast groups D: 533 [ZCL]Emitting StartUp event D: 537 [EVL]LogEvent event number: 0x0000000000000001 priority: 2, endpoint id: 0x0 cluster id: 0x0000_0028 event id: 0x0 Sys timestamp: 0x0000000000000218 I: 551 [SVR]Server Listening... I: 553 [DL]Device Configuration: I: 557 [DL] Serial Number: 11223344556677889900 I: 561 [DL] Vendor Id: 65521 (0xFFF1) I: 565 [DL] Product Id: 32774 (0x8006) I: 569 [DL] Hardware Version: 0 I: 572 [DL] Setup Pin Code (0 for UNKNOWN/ERROR): 20202021 I: 578 [DL] Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3847 (0xF07) I: 585 [DL] Manufacturing Date: (not set) I: 589 [DL] Device Type: 65535 (0xFFFF) I: 594 [SVR]SetupQRCode: [MT:8IXS1MBW17KA0648G00] I: 598 [SVR]Copy/paste the below URL in a browser to see the QR Code: I: 604 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A8IXS1MBW17KA0648G00 I: 613 [SVR]Manual pairing code: [34970112332] I: 618 [DL]CHIP task running I: 621 [DIS]Updating services using commissioning mode 0 D: 626 [DL]Using Thread extended MAC for hostname. D: 631 [DL]Using Thread extended MAC for hostname. I: 636 [DIS]Advertise commission parameter vendorID=65521 productID=32774 discriminator=3847/15 cm=0 E: 645 [DIS]Failed to advertise extended commissionable node: 3 E: 651 [DIS]Failed to finalize service update: 1c D: 655 [DMG]Endpoint 1, Cluster 0x0000_0101 update version to b26ffdf5 uart:~$ uart:~$ uart:~$ uart:~$ uart:~$ D: 78679 [IN]SecureSession[0x20003988]: Allocated Type:1 LSID:21255 D: 78685 [SC]Assigned local session key ID 21255 D: 78690 [SC]Waiting for PBKDF param request D: 78694 [DL]CHIPoBLE advertising set to on I: 78698 [DIS]Updating services using commissioning mode 1 D: 78703 [DL]Using Thread extended MAC for hostname. D: 78708 [DL]Using Thread extended MAC for hostname. I: 78714 [DIS]Advertise commission parameter vendorID=65521 productID=32774 discriminator=3847/15 cm=1 E: 78723 [DIS]Failed to advertise commissionable node: 3 E: 78728 [DIS]Failed to finalize service update: 1c I: 78735 [DL]CHIPoBLE advertising started I: 78740 [DL]NFC Tag emulation started I: 96127 [DL]BLE connection established (ConnId: 0x00) I: 96132 [DL]Current number of connections: 1/1 I: 96136 [DL]CHIPoBLE advertising stopped I: 96140 [DL]NFC Tag emulation stopped D: 97136 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 97143 [BLE]local and remote recv window sizes = 5 I: 97148 [BLE]selected BTP version 4 I: 97152 [BLE]using BTP fragment sizes rx 128 / tx 128. D: 97158 [DL]ConnId: 0x00, New CCCD value: 0x0002 D: 97163 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 6) D: 97171 [IN]BLE EndPoint 0x2000f758 Connection Complete I: 97176 [DL]CHIPoBLE connection established (ConnId: 0x00, GATT MTU: 131) D: 97293 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 97443 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 97451 [EM]Received message of type 0x20 with protocolId (0, 0) and MessageCounter:236853315 on exchange 44825r D: 97461 [EM]Handling via exchange: 44825r, Delegate: 0x20005ab4 D: 97467 [SC]Received PBKDF param request D: 97471 [SC]Peer assigned session ID 32409 D: 97475 [SC]Found MRP parameters in the message D: 97479 [SC]Including MRP parameters in PBKDF param response I: 97485 [IN]Prepared unauthenticated message 0x2002c128 to 0x0000000000000000 (0) of type 0x21 and protocolId (0, 0) on exchange 44825r with MessageCounter:98896300. I: 97500 [IN]Sending unauthenticated msg 0x2002c128 with MessageCounter:98896300 to 0x0000000000000000 at monotonic time: 0000000000017CDC msec D: 97513 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 97521 [SC]Sent PBKDF param response D: 97593 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 97601 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 14) D: 97693 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 97701 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 97709 [EM]Received message of type 0x22 with protocolId (0, 0) and MessageCounter:236853316 on exchange 44825r D: 97719 [EM]Found matching exchange: 44825r, Delegate: 0x20005ab4 D: 97725 [SC]Received spake2p msg1 I: 99586 [IN]Prepared unauthenticated message 0x2002c0b8 to 0x0000000000000000 (0) of type 0x23 and protocolId (0, 0) on exchange 44825r with MessageCounter:98896301. I: 99601 [IN]Sending unauthenticated msg 0x2002c0b8 with MessageCounter:98896301 to 0x0000000000000000 at monotonic time: 0000000000018511 msec D: 99614 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 99622 [SC]Sent spake2p msg2 E: 99624 [DL]Long dispatch time: 1923 ms, for event type 16388 D: 99693 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 99701 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 6) D: 99793 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 99843 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 99851 [EM]Received message of type 0x24 with protocolId (0, 0) and MessageCounter:236853317 on exchange 44825r D: 99861 [EM]Found matching exchange: 44825r, Delegate: 0x20005ab4 D: 99867 [SC]Received spake2p msg3 D: 99870 [SC]Sending status report. Protocol code 0, exchange 44825 I: 99877 [IN]Prepared unauthenticated message 0x2002c140 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 44825r with MessageCounter:98896302. I: 99892 [IN]Sending unauthenticated msg 0x2002c140 with MessageCounter:98896302 to 0x0000000000000000 at monotonic time: 0000000000018633 msec D: 99904 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 35) I: 99913 [SC]SecureSession[0x20003988]: Moving from state 'kEstablishing' --> 'kActive' D: 99921 [IN]SecureSession[0x20003988]: Activated - Type:1 LSID:21255 D: 99927 [IN]New secure session activated for device , LSID:21255 PSID:32409! I: 99936 [SVR]Commissioning completed session establishment step I: 99942 [DIS]Updating services using commissioning mode 0 D: 99947 [DL]Using Thread extended MAC for hostname. D: 99952 [DL]Using Thread extended MAC for hostname. I: 99958 [DIS]Advertise commission parameter vendorID=65521 productID=32774 discriminator=3847/15 cm=0 E: 99967 [DIS]Failed to advertise extended commissionable node: 3 D: 99973 [DIS]Scheduling extended discovery timeout in 900s E: 99978 [DIS]Failed to finalize service update: 1c D: 99983 [DL]CHIPoBLE advertising set to off I: 99987 [SVR]Device completed Rendezvous process E: 99992 [DL]Long dispatch time: 148 ms, for event type 16388 D: 99998 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 100006 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 100014 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:220195784 on exchange 44826r D: 100024 [EM]Handling via exchange: 44826r, Delegate: 0x2000d124 D: 100030 [IM]Received Read request D: 100034 [DMG]IM RH moving to [GeneratingReports] D: 100038 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 100047 [DMG] Cluster 28, Attribute 2 is dirty D: 100052 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0002 (expanded=0) D: 100061 [DMG] Sending report (payload has 37 bytes)... I: 100068 [IN]Prepared secure message 0x2002c2d8 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 44826r with MessageCounter:6386731. I: 100082 [IN]Sending encrypted msg 0x2002c2d8 with MessageCounter:6386731 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000000186F1 msec D: 100095 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72) D: 100102 [DMG] OnReportConfirm: NumReports = 0 D: 100107 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 100114 [DMG]IM RH moving to [AwaitingDestruction] D: 100119 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 100244 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 100252 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 100259 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:220195785 on exchange 44827r D: 100270 [EM]Handling via exchange: 44827r, Delegate: 0x2000d124 D: 100275 [IM]Received Read request D: 100279 [DMG]IM RH moving to [GeneratingReports] D: 100284 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 100293 [DMG] Cluster 28, Attribute 4 is dirty D: 100298 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0004 (expanded=0) D: 100307 [DMG] Sending report (payload has 37 bytes)... I: 100313 [IN]Prepared secure message 0x2002c2d8 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 44827r with MessageCounter:6386732. I: 100327 [IN]Sending encrypted msg 0x2002c2d8 with MessageCounter:6386732 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000000187E7 msec D: 100340 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72) D: 100348 [DMG] OnReportConfirm: NumReports = 0 D: 100353 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 100360 [DMG]IM RH moving to [AwaitingDestruction] D: 100365 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 100444 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 100451 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 100459 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:220195786 on exchange 44828r D: 100470 [EM]Handling via exchange: 44828r, Delegate: 0x2000d124 D: 100475 [IM]Received Read request D: 100479 [DMG]IM RH moving to [GeneratingReports] D: 100484 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 100493 [DMG] Cluster 3e, Attribute 2 is dirty D: 100498 [DMG]Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_0002 (expanded=0) D: 100507 [DMG] Sending report (payload has 36 bytes)... I: 100513 [IN]Prepared secure message 0x2002c2d8 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 44828r with MessageCounter:6386733. I: 100527 [IN]Sending encrypted msg 0x2002c2d8 with MessageCounter:6386733 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000000188AF msec D: 100540 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 100548 [DMG] OnReportConfirm: NumReports = 0 D: 100553 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 100560 [DMG]IM RH moving to [AwaitingDestruction] D: 100565 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 100644 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 100652 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 100659 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:220195787 on exchange 44829r D: 100670 [EM]Handling via exchange: 44829r, Delegate: 0x2000d124 D: 100675 [IM]Received Read request D: 100679 [DMG]IM RH moving to [GeneratingReports] D: 100684 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 100693 [DMG] Cluster 3e, Attribute 3 is dirty D: 100698 [DMG]Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_0003 (expanded=0) D: 100707 [DMG] Sending report (payload has 36 bytes)... I: 100713 [IN]Prepared secure message 0x2002c2d8 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 44829r with MessageCounter:6386734. I: 100727 [IN]Sending encrypted msg 0x2002c2d8 with MessageCounter:6386734 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000018977 msec D: 100740 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 100748 [DMG] OnReportConfirm: NumReports = 0 D: 100753 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 100760 [DMG]IM RH moving to [AwaitingDestruction] D: 100765 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 100844 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 100851 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 100859 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:220195788 on exchange 44830r D: 100870 [EM]Handling via exchange: 44830r, Delegate: 0x2000d124 D: 100875 [IM]Received Read request D: 100879 [DMG]IM RH moving to [GeneratingReports] D: 100884 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 100893 [DMG] Cluster 1d, Attribute 1 is dirty D: 100898 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0001 (expanded=0) D: 100908 [DMG] Sending report (payload has 428 bytes)... I: 100916 [IN]Prepared secure message 0x2002c2d8 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 44830r with MessageCounter:6386735. I: 100930 [IN]Sending encrypted msg 0x2002c2d8 with MessageCounter:6386735 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000018A42 msec D: 100943 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 100951 [DMG] OnReportConfirm: NumReports = 0 D: 100955 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 100963 [DMG]IM RH moving to [AwaitingDestruction] D: 100967 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 101043 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 101051 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 101143 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 101151 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 101293 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 101301 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 85) D: 101393 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 101444 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 101544 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 101551 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:220195789 on exchange 44831r D: 101561 [EM]Handling via exchange: 44831r, Delegate: 0x2000d124 D: 101567 [IM]Received Read request D: 101571 [DMG]IM RH moving to [GeneratingReports] D: 101576 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 101585 [DMG] Cluster 31, Attribute fffc is dirty D: 101590 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFC (expanded=0) D: 101600 [DMG] Sending report (payload has 37 bytes)... I: 101606 [IN]Prepared secure message 0x2002c2d8 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 44831r with MessageCounter:6386736. I: 101620 [IN]Sending encrypted msg 0x2002c2d8 with MessageCounter:6386736 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000018CF4 msec D: 101632 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72) D: 101640 [DMG] OnReportConfirm: NumReports = 0 D: 101645 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 101652 [DMG]IM RH moving to [AwaitingDestruction] D: 101657 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 101703 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 102603 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 102611 [EM]Received message of type 0xa with protocolId (0, 1) and MessageCounter:220195790 on exchange 44832r D: 102621 [EM]Handling via exchange: 44832r, Delegate: 0x2000d124 D: 102627 [DMG]Got Timed Request with timeout 10000: handler 0x2000d520 exchange 44832r I: 102636 [IN]Prepared secure message 0x2002c0a8 to 0xFFFFFFFB00000000 (0) of type 0x1 and protocolId (0, 1) on exchange 44832r with MessageCounter:6386737. I: 102650 [IN]Sending encrypted msg 0x2002c0a8 with MessageCounter:6386737 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000000190FA msec D: 102662 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 43) D: 102670 [DMG]Timed Request time limit 0x000000000001B81E: handler 0x2000d520 exchange 44832r D: 102738 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 102746 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 102754 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:220195791 on exchange 44832r D: 102765 [EM]Found matching exchange: 44832r, Delegate: 0x2000d520 D: 102771 [DMG]Timed following action arrived at 0x0000000000019173: handler 0x2000d520 exchange 44832r D: 102780 [DMG]Handing timed invoke to IM engine: handler 0x2000d520 exchange 44832r D: 102788 [DMG]Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000 I: 102796 [FS]GeneralCommissioning: Received ArmFailSafe (120s) D: 102802 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 1c59f80c D: 102808 [DMG]Command handler moving to [ Preparing] D: 102813 [DMG]Command handler moving to [AddingComm] D: 102818 [DMG]Command handler moving to [AddedComma] D: 102823 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 102830 [IN]Prepared secure message 0x2002c128 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 44832r with MessageCounter:6386738. I: 102845 [IN]Sending encrypted msg 0x2002c128 with MessageCounter:6386738 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000000191BC msec D: 102857 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 102865 [DMG]Command handler moving to [CommandSen] D: 102870 [DMG]Command handler moving to [AwaitingDe] E: 102875 [DL]Long dispatch time: 128 ms, for event type 16388 D: 102919 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 102926 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 102934 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:220195792 on exchange 44833r D: 102944 [EM]Handling via exchange: 44833r, Delegate: 0x2000d124 D: 102950 [IM]Received Read request D: 102954 [DMG]IM RH moving to [GeneratingReports] D: 102959 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 102968 [DMG] Cluster 30, Attribute 3 is dirty D: 102973 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0003 (expanded=0) D: 102982 [DMG] Sending report (payload has 36 bytes)... I: 102988 [IN]Prepared secure message 0x2002c2d8 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 44833r with MessageCounter:6386739. I: 103002 [IN]Sending encrypted msg 0x2002c2d8 with MessageCounter:6386739 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000001925A msec D: 103015 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 103023 [DMG] OnReportConfirm: NumReports = 0 D: 103028 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 103035 [DMG]IM RH moving to [AwaitingDestruction] D: 103040 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 103099 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 103106 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 103114 [EM]Received message of type 0xa with protocolId (0, 1) and MessageCounter:220195793 on exchange 44834r D: 103124 [EM]Handling via exchange: 44834r, Delegate: 0x2000d124 D: 103130 [DMG]Got Timed Request with timeout 10000: handler 0x2000d520 exchange 44834r I: 103139 [IN]Prepared secure message 0x2002c0a8 to 0xFFFFFFFB00000000 (0) of type 0x1 and protocolId (0, 1) on exchange 44834r with MessageCounter:6386740. I: 103153 [IN]Sending encrypted msg 0x2002c0a8 with MessageCounter:6386740 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000000192F1 msec D: 103166 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 43) D: 103173 [DMG]Timed Request time limit 0x000000000001BA15: handler 0x2000d520 exchange 44834r D: 103233 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 103241 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 103249 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:220195794 on exchange 44834r D: 103259 [EM]Found matching exchange: 44834r, Delegate: 0x2000d520 D: 103266 [DMG]Timed following action arrived at 0x0000000000019361: handler 0x2000d520 exchange 44834r D: 103275 [DMG]Handing timed invoke to IM engine: handler 0x2000d520 exchange 44834r D: 103283 [DMG]Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0002 D: 103298 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 1c59f80d D: 103305 [DMG]Command handler moving to [ Preparing] D: 103310 [DMG]Command handler moving to [AddingComm] D: 103314 [DMG]Command handler moving to [AddedComma] D: 103319 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 103327 [IN]Prepared secure message 0x2002c128 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 44834r with MessageCounter:6386741. I: 103341 [IN]Sending encrypted msg 0x2002c128 with MessageCounter:6386741 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000000193AD msec D: 103354 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 103361 [DMG]Command handler moving to [CommandSen] D: 103366 [DMG]Command handler moving to [AwaitingDe] E: 103371 [DL]Long dispatch time: 130 ms, for event type 16388 D: 103414 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 103421 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 103429 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:220195795 on exchange 44835r D: 103440 [EM]Handling via exchange: 44835r, Delegate: 0x2000d124 D: 103446 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 I: 103454 [ZCL]OpCreds: Certificate Chain request received for DAC D: 103460 [DMG]Command handler moving to [ Preparing] D: 103465 [DMG]Command handler moving to [AddingComm] D: 103469 [DMG]Command handler moving to [AddedComma] D: 103474 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 103484 [IN]Prepared secure message 0x2002c1a0 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 44835r with MessageCounter:6386742. I: 103498 [IN]Sending encrypted msg 0x2002c1a0 with MessageCounter:6386742 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000001944A msec D: 103511 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 103519 [DMG]Command handler moving to [CommandSen] D: 103524 [DMG]Command handler moving to [AwaitingDe] E: 103528 [DL]Long dispatch time: 107 ms, for event type 16388 D: 103593 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 103601 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 103683 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 103691 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 103773 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 103781 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 103864 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 103871 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 103879 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 56) D: 103954 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 103961 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 103969 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:220195796 on exchange 44836r D: 103980 [EM]Handling via exchange: 44836r, Delegate: 0x2000d124 D: 103986 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 I: 103994 [ZCL]OpCreds: Certificate Chain request received for PAI D: 104000 [DMG]Command handler moving to [ Preparing] D: 104005 [DMG]Command handler moving to [AddingComm] D: 104009 [DMG]Command handler moving to [AddedComma] D: 104014 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 104024 [IN]Prepared secure message 0x2002c1a0 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 44836r with MessageCounter:6386743. I: 104038 [IN]Sending encrypted msg 0x2002c1a0 with MessageCounter:6386743 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000019666 msec D: 104051 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 104058 [DMG]Command handler moving to [CommandSen] D: 104063 [DMG]Command handler moving to [AwaitingDe] E: 104068 [DL]Long dispatch time: 107 ms, for event type 16388 D: 104133 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 104141 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 104223 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 104231 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 104313 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 104321 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 104404 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 104412 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 104419 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 28) D: 104538 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 104546 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 104554 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:220195797 on exchange 44837r D: 104565 [EM]Handling via exchange: 44837r, Delegate: 0x2000d124 D: 104571 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0000 I: 104579 [ZCL]OpCreds: Received an AttestationRequest command I: 104615 [ZCL]OpCreds: AttestationRequest successful. D: 104620 [DMG]Command handler moving to [ Preparing] D: 104625 [DMG]Command handler moving to [AddingComm] D: 104630 [DMG]Command handler moving to [AddedComma] D: 104635 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 104645 [IN]Prepared secure message 0x2002c1a0 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 44837r with MessageCounter:6386744. I: 104659 [IN]Sending encrypted msg 0x2002c1a0 with MessageCounter:6386744 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000000198D3 msec D: 104672 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 104680 [DMG]Command handler moving to [CommandSen] D: 104684 [DMG]Command handler moving to [AwaitingDe] E: 104689 [DL]Long dispatch time: 143 ms, for event type 16388 D: 104763 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 104771 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 104898 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 104906 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 104988 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 104996 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 105079 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 105086 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 105094 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 105168 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 105176 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 92) D: 105258 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 105266 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 105274 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:220195798 on exchange 44838r D: 105285 [EM]Handling via exchange: 44838r, Delegate: 0x2000d124 D: 105291 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0004 I: 105299 [ZCL]OpCreds: Received a CSRRequest command D: 105304 [ZCL]OpCreds: Finding fabric with fabricIndex 0x0 I: 105494 [ZCL]OpCreds: AllocatePendingOperationalKey succeeded I: 105531 [ZCL]OpCreds: CSRRequest successful. D: 105535 [DMG]Command handler moving to [ Preparing] D: 105540 [DMG]Command handler moving to [AddingComm] D: 105545 [DMG]Command handler moving to [AddedComma] D: 105550 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 105558 [IN]Prepared secure message 0x2002c1a0 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 44838r with MessageCounter:6386745. I: 105572 [IN]Sending encrypted msg 0x2002c1a0 with MessageCounter:6386745 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000019C64 msec D: 105585 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 105593 [DMG]Command handler moving to [CommandSen] D: 105598 [DMG]Command handler moving to [AwaitingDe] E: 105602 [DL]Long dispatch time: 336 ms, for event type 16388 D: 105663 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 105671 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 105753 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 105761 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 105843 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 105851 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3) D: 105934 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 105941 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 107013 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 107021 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:220195799 on exchange 44839r D: 107031 [EM]Handling via exchange: 44839r, Delegate: 0x2000d124 D: 107037 [IM]Received Read request D: 107041 [DMG]IM RH moving to [GeneratingReports] D: 107046 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 107055 [DMG] Cluster 3e, Attribute 1 is dirty D: 107060 [DMG]Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_0001 (expanded=0) D: 107069 [DMG] Sending report (payload has 36 bytes)... I: 107075 [IN]Prepared secure message 0x2002c2d8 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 44839r with MessageCounter:6386746. I: 107089 [IN]Sending encrypted msg 0x2002c2d8 with MessageCounter:6386746 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000001A251 msec D: 107102 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 107109 [DMG] OnReportConfirm: NumReports = 0 D: 107114 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 107122 [DMG]IM RH moving to [AwaitingDestruction] D: 107126 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 107193 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 107201 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 107284 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 107374 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 107383 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:220195800 on exchange 44840r D: 107393 [EM]Handling via exchange: 44840r, Delegate: 0x2000d124 D: 107399 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B I: 107407 [ZCL]OpCreds: Received an AddTrustedRootCertificate command I: 107472 [ZCL]OpCreds: AddTrustedRootCertificate successful. D: 107477 [DMG]Command handler moving to [ Preparing] D: 107482 [DMG]Command handler moving to [AddingComm] D: 107487 [DMG]Command handler moving to [AddedComma] D: 107492 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 107499 [IN]Prepared secure message 0x2002c1a0 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 44840r with MessageCounter:6386747. I: 107513 [IN]Sending encrypted msg 0x2002c1a0 with MessageCounter:6386747 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000001A3F9 msec D: 107526 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 68) D: 107533 [DMG]Command handler moving to [CommandSen] D: 107538 [DMG]Command handler moving to [AwaitingDe] E: 107543 [DL]Long dispatch time: 169 ms, for event type 16388 D: 107598 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 107606 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 107689 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 107779 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 107869 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 107876 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3) D: 107958 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 107966 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 108049 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 108059 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:220195801 on exchange 44841r D: 108070 [EM]Handling via exchange: 44841r, Delegate: 0x2000d124 D: 108076 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0006 I: 108084 [ZCL]OpCreds: Received an AddNOC command I: 108091 [FP]Validating NOC chain I: 108210 [FP]NOC chain validation successful I: 108214 [FP]Added new fabric at index: 0x1 I: 108219 [FP]Assigned compressed fabric ID: 0x3199E9CFDD25901B, node ID: 0x00000000DC8882F6 I: 108227 [TS]Last Known Good Time: 2022-10-17T10:31:31 I: 108232 [TS]New proposed Last Known Good Time: 2022-10-17T02:37:07 I: 108238 [TS]Retaining current Last Known Good Time D: 108243 [DMG]Endpoint 0, Cluster 0x0000_003E update version to e0419b01 D: 108250 [DMG]Endpoint 0, Cluster 0x0000_003E update version to e0419b02 D: 108286 [EVL]LogEvent event number: 0x0000000000000002 priority: 1, endpoint id: 0x0 cluster id: 0x0000_001F event id: 0x0 Sys timestamp: 0x000000000001A6FE I: 108300 [ZCL]OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0xFFFFFFFD00010001 D: 108309 [DL]Using Thread extended MAC for hostname. I: 108314 [DIS]Advertise operational node 3199E9CFDD25901B-00000000DC8882F6 D: 108321 [DMG]Endpoint 0, Cluster 0x0000_003E update version to e0419b03 D: 108328 [DMG]Endpoint 0, Cluster 0x0000_003E update version to e0419b04 D: 108334 [DMG]Command handler moving to [ Preparing] D: 108339 [DMG]Command handler moving to [AddingComm] D: 108344 [DMG]Command handler moving to [AddedComma] I: 108349 [ZCL]OpCreds: successfully created fabric index 0x1 via AddNOC D: 108355 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 108363 [IN]Prepared secure message 0x2002c1a0 to 0xFFFFFFFB00000000 (1) of type 0x9 and protocolId (0, 1) on exchange 44841r with MessageCounter:6386748. I: 108377 [IN]Sending encrypted msg 0x2002c1a0 with MessageCounter:6386748 to 0xFFFFFFFB00000000 (1) at monotonic time: 000000000001A759 msec D: 108389 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 108397 [DMG]Command handler moving to [CommandSen] D: 108402 [DMG]Command handler moving to [AwaitingDe] E: 108407 [DL]Long dispatch time: 359 ms, for event type 16388 D: 108453 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 108461 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 108543 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 108552 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:220195802 on exchange 44842r D: 108562 [EM]Handling via exchange: 44842r, Delegate: 0x2000d124 D: 108568 [DMG]Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0003 D: 108590 [DMG]Command handler moving to [ Preparing] D: 108595 [DMG]Command handler moving to [AddingComm] D: 108600 [DMG]Command handler moving to [AddedComma] D: 108604 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 1c59f80e D: 108611 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 108619 [IN]Prepared secure message 0x2002c1a0 to 0xFFFFFFFB00000000 (1) of type 0x9 and protocolId (0, 1) on exchange 44842r with MessageCounter:6386749. I: 108633 [IN]Sending encrypted msg 0x2002c1a0 with MessageCounter:6386749 to 0xFFFFFFFB00000000 (1) at monotonic time: 000000000001A859 msec D: 108646 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 108653 [DMG]Command handler moving to [CommandSen] D: 108658 [DMG]Command handler moving to [AwaitingDe] E: 108663 [DL]Long dispatch time: 120 ms, for event type 16388 D: 108724 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 108731 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 108739 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:220195803 on exchange 44843r D: 108750 [EM]Handling via exchange: 44843r, Delegate: 0x2000d124 D: 108755 [IM]Received Read request D: 108759 [DMG]IM RH moving to [GeneratingReports] D: 108764 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 108773 [DMG] Cluster 31, Attribute 3 is dirty D: 108778 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_0003 (expanded=0) D: 108787 [DMG] Sending report (payload has 36 bytes)... I: 108793 [IN]Prepared secure message 0x2002c2d8 to 0xFFFFFFFB00000000 (1) of type 0x5 and protocolId (0, 1) on exchange 44843r with MessageCounter:6386750. I: 108807 [IN]Sending encrypted msg 0x2002c2d8 with MessageCounter:6386750 to 0xFFFFFFFB00000000 (1) at monotonic time: 000000000001A907 msec D: 108820 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 108828 [DMG] OnReportConfirm: NumReports = 0 D: 108833 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 108840 [DMG]IM RH moving to [AwaitingDestruction] D: 108845 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 108903 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 108911 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 108919 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:220195804 on exchange 44844r D: 108929 [EM]Handling via exchange: 44844r, Delegate: 0x2000d124 D: 108936 [DMG]Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0006 D: 108956 [DMG]Decreasing reference count for CommandHandler, remaining 1 D: 108963 [DL]OpenThread State Changed (Flags: 0x1017c100) D: 108968 [DL] Network Name: NEST-PAN-BFD8 D: 108972 [DL] PAN Id: 0xBFD8 D: 108975 [DL] Extended PAN Id: 0x4311AB3B79DBEA79 D: 108980 [DL] Channel: 22 D: 108983 [DL] Mesh Prefix: fd4f:2727:5e06::/64 D: 108988 [DL]OpenThread State Changed (Flags: 0x1100101d) D: 108994 [DL] Device Role: DETACHED D: 108997 [DL] Thread Unicast Addresses: D: 109001 [DL] fd4f:2727:5e06:0:3015:389c:5a27:eb68/64 valid D: 109007 [DL] fe80::74ef:7760:dedc:24ad/64 valid preferred I: 110583 [DL]SRP Client was started, detected server: fd4f:2727:5e06:0000:473a:1d06:8def:f7c5 D: 110592 [DL]OpenThread State Changed (Flags: 0x200002a4) D: 110754 [DL] Device Role: CHILD D: 110759 [DL] Partition Id: 0xA95283D E: 110801 [DL]Long dispatch time: 209 ms, for event type 32777 D: 110808 [DL]OpenThread State Changed (Flags: 0x00000001) D: 110814 [DL] Thread Unicast Addresses: D: 110818 [DL] fd23:7405:2b5e:1:4dfe:df27:6574:125/64 valid preferred D: 110826 [DL] fd4f:2727:5e06::ff:fe00:3401/64 valid rloc D: 110832 [DL] fd4f:2727:5e06:0:3015:389c:5a27:eb68/64 valid D: 110838 [DL] fe80::74ef:7760:dedc:24ad/64 valid preferred D: 110846 [DMG]Command handler moving to [ Preparing] D: 110851 [DMG]Command handler moving to [AddingComm] D: 110856 [DMG]Command handler moving to [AddedComma] D: 110861 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 1c59f80f D: 110868 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 110876 [IN]Prepared secure message 0x2002c390 to 0xFFFFFFFB00000000 (1) of type 0x9 and protocolId (0, 1) on exchange 44844r with MessageCounter:6386751. I: 110892 [IN]Sending encrypted msg 0x2002c390 with MessageCounter:6386751 to 0xFFFFFFFB00000000 (1) at monotonic time: 000000000001B12B msec D: 110904 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 70) D: 110913 [DMG]Command handler moving to [CommandSen] D: 110918 [DMG]Command handler moving to [AwaitingDe] D: 110924 [DL]Using Thread extended MAC for hostname. I: 110930 [DIS]Advertise operational node 3199E9CFDD25901B-00000000DC8882F6 I: 110938 [SVR]Operational advertising enabled D: 110973 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 111126 [DL]SRP update succeeded I: 111130 [DIS]Setting operational delegate post init I: 111138 [SWU]Stopping the watchdog timer I: 111141 [SWU]Starting the periodic query timer, timeout: 86400 seconds I: 111148 [DIS]Updating services using commissioning mode 0 D: 111153 [DL]Using Thread extended MAC for hostname. I: 111158 [DIS]Advertise operational node 3199E9CFDD25901B-00000000DC8882F6 I: 111165 [DL]advertising srp service: 3199E9CFDD25901B-00000000DC8882F6._matter._tcp D: 111173 [DL]Using Thread extended MAC for hostname. I: 111179 [DIS]Advertise commission parameter vendorID=65521 productID=32774 discriminator=3847/15 cm=0 I: 111224 [DL]advertising srp service: 732337CE029EF328._matterc._udp D: 111231 [DMG]Endpoint 0, Cluster 0x0000_002A update version to fa5fa47a D: 111239 [DMG]Endpoint 0, Cluster 0x0000_002A update version to fa5fa47b D: 111628 [DL]SRP update succeeded I: 111963 [DL]BLE GAP connection terminated (reason 0x13) I: 111969 [DL]Current number of connections: 0/1 I: 115153 [EM]Received message of type 0x30 with protocolId (0, 0) and MessageCounter:236853318 on exchange 44845r D: 115164 [EM]Handling via exchange: 44845r, Delegate: 0x20004540 I: 115169 [IN]CASE Server received Sigma1 message. Starting handshake. EC 0x20005250 I: 115177 [IN]CASE Server disabling CASE session setups D: 115182 [EM]Sending Standalone Ack for MessageCounter:236853318 on exchange 44845r I: 115190 [IN]Prepared unauthenticated message 0x2002c060 to 0x0000000000000000 (0) of type 0x10 and protocolId (0, 0) on exchange 44845r with MessageCounter:98896303. I: 115205 [IN]Sending unauthenticated msg 0x2002c060 with MessageCounter:98896303 to 0x0000000000000000 at monotonic time: 000000000001C205 msec D: 115219 [EM]Flushed pending ack for MessageCounter:236853318 on exchange 44845r I: 115227 [SC]Received Sigma1 msg D: 115230 [SC]Found MRP parameters in the message D: 115234 [SC]Peer assigned session key ID 32410 I: 115242 [SC]CASE matched destination ID: fabricIndex 1, NodeID 0x00000000DC8882F6 D: 115463 [SC]Including MRP parameters I: 115468 [IN]Prepared unauthenticated message 0x20005504 to 0x0000000000000000 (0) of type 0x31 and protocolId (0, 0) on exchange 44845r with MessageCounter:98896304. I: 115483 [IN]Sending unauthenticated msg 0x20005504 with MessageCounter:98896304 to 0x0000000000000000 at monotonic time: 000000000001C31A msec I: 115497 [DL]OpenThread SED interval set to 200ms I: 115502 [SC]Sent Sigma2 msg I: 115719 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:236853319 on exchange 44845r D: 115730 [EM]Found matching exchange: 44845r, Delegate: 0x2000455c D: 115738 [EM]Rxd Ack; Removing MessageCounter:98896304 from Retrans Table on exchange 44845r D: 115746 [EM]Removed CHIP MessageCounter:98896304 from RetransTable on exchange 44845r I: 115877 [EM]Received message of type 0x32 with protocolId (0, 0) and MessageCounter:236853320 on exchange 44845r D: 115887 [EM]Found matching exchange: 44845r, Delegate: 0x2000455c D: 115893 [EM]CHIP MessageCounter:98896304 not in RetransTable on exchange 44845r D: 115901 [EM]Sending Standalone Ack for MessageCounter:236853320 on exchange 44845r I: 115908 [IN]Prepared unauthenticated message 0x2002c048 to 0x0000000000000000 (0) of type 0x10 and protocolId (0, 0) on exchange 44845r with MessageCounter:98896305. I: 115924 [IN]Sending unauthenticated msg 0x2002c048 with MessageCounter:98896305 to 0x0000000000000000 at monotonic time: 000000000001C4D3 msec D: 115937 [EM]Flushed pending ack for MessageCounter:236853320 on exchange 44845r I: 115945 [SC]Received Sigma3 msg E: 115953 [SC]The device does not support GetClock_RealTimeMS() API: 3. Falling back to Last Known Good UTC Time D: 116153 [SC]Sending status report. Protocol code 0, exchange 44845 I: 116159 [IN]Prepared unauthenticated message 0x20005504 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 44845r with MessageCounter:98896306. I: 116174 [IN]Sending unauthenticated msg 0x20005504 with MessageCounter:98896306 to 0x0000000000000000 at monotonic time: 000000000001C5CE msec I: 116190 [SC]SecureSession[0x200038d0]: Moving from state 'kEstablishing' --> 'kActive' D: 116199 [IN]SecureSession[0x200038d0]: Activated - Type:2 LSID:21254 D: 116205 [IN]New secure session activated for device <0000000018EB5475, 1>, LSID:21254 PSID:32410! I: 116215 [IN]CASE Session established to peer: <0000000018EB5475, 1> I: 116221 [IN]CASE Server enabling CASE session setups D: 116227 [IN]SecureSession[0x20003a40]: Allocated Type:2 LSID:21256 D: 116233 [SC]Allocated SecureSession (0x20003a40) - waiting for Sigma1 msg I: 116475 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:236853321 on exchange 44845r D: 116485 [EM]Found matching exchange: 44845r, Delegate: (nil) D: 116491 [EM]Rxd Ack; Removing MessageCounter:98896306 from Retrans Table on exchange 44845r D: 116504 [EM]Removed CHIP MessageCounter:98896306 from RetransTable on exchange 44845r I: 116512 [DL]OpenThread SED interval set to 1000ms I: 116517 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:82063658 on exchange 44846r D: 116527 [EM]Handling via exchange: 44846r, Delegate: 0x2000d124 D: 116533 [IM]Received Read request D: 116537 [DMG]IM RH moving to [GeneratingReports] I: 116542 [DL]OpenThread SED interval set to 200ms D: 116546 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 116555 [DMG] Cluster 3c, Attribute 0 is dirty D: 116560 [DMG]Reading attribute: Cluster=0x0000_003C Endpoint=0 AttributeId=0x0000_0000 (expanded=0) D: 116569 [DMG] Sending report (payload has 36 bytes)... I: 116576 [IN]Prepared secure message 0x20005504 to 0x0000000018EB5475 (1) of type 0x5 and protocolId (0, 1) on exchange 44846r with MessageCounter:148867218. I: 116590 [IN]Sending encrypted msg 0x20005504 with MessageCounter:148867218 to 0x0000000018EB5475 (1) at monotonic time: 000000000001C76E msec D: 116604 [DMG] OnReportConfirm: NumReports = 0 D: 116609 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 116617 [DMG]IM RH moving to [AwaitingDestruction] D: 116622 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 116688 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:82063659 on exchange 44846r D: 116700 [EM]Found matching exchange: 44846r, Delegate: (nil) D: 116706 [EM]Rxd Ack; Removing MessageCounter:148867218 from Retrans Table on exchange 44846r D: 116714 [EM]Removed CHIP MessageCounter:148867218 from RetransTable on exchange 44846r I: 116722 [DL]OpenThread SED interval set to 1000ms I: 116727 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:82063660 on exchange 44847r D: 116737 [EM]Handling via exchange: 44847r, Delegate: 0x2000d124 D: 116743 [IM]Received Read request D: 116747 [DMG]IM RH moving to [GeneratingReports] I: 116752 [DL]OpenThread SED interval set to 200ms D: 116756 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 116765 [DMG] Cluster 1d, Attribute 3 is dirty D: 116770 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0003 (expanded=0) D: 116779 [DMG] Sending report (payload has 64 bytes)... I: 116786 [IN]Prepared secure message 0x20005504 to 0x0000000018EB5475 (1) of type 0x5 and protocolId (0, 1) on exchange 44847r with MessageCounter:148867219. I: 116800 [IN]Sending encrypted msg 0x20005504 with MessageCounter:148867219 to 0x0000000018EB5475 (1) at monotonic time: 000000000001C840 msec D: 116814 [DMG] OnReportConfirm: NumReports = 0 D: 116819 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 116827 [DMG]IM RH moving to [AwaitingDestruction] D: 116832 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 116902 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:82063661 on exchange 44847r D: 116912 [EM]Found matching exchange: 44847r, Delegate: (nil) D: 116920 [EM]Rxd Ack; Removing MessageCounter:148867219 from Retrans Table on exchange 44847r D: 116928 [EM]Removed CHIP MessageCounter:148867219 from RetransTable on exchange 44847r I: 116936 [DL]OpenThread SED interval set to 1000ms I: 116941 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:82063662 on exchange 44848r D: 116951 [EM]Handling via exchange: 44848r, Delegate: 0x2000d124 D: 116957 [IM]Received Read request D: 116961 [DMG]IM RH moving to [GeneratingReports] I: 116966 [DL]OpenThread SED interval set to 200ms D: 116970 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 116979 [DMG] Cluster 1d, Attribute 0 is dirty D: 116984 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0000 (expanded=0) D: 116993 [DMG] Sending report (payload has 70 bytes)... I: 117000 [IN]Prepared secure message 0x20005504 to 0x0000000018EB5475 (1) of type 0x5 and protocolId (0, 1) on exchange 44848r with MessageCounter:148867220. I: 117014 [IN]Sending encrypted msg 0x20005504 with MessageCounter:148867220 to 0x0000000018EB5475 (1) at monotonic time: 000000000001C916 msec D: 117028 [DMG] OnReportConfirm: NumReports = 0 D: 117033 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 117041 [DMG]IM RH moving to [AwaitingDestruction] D: 117046 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 117114 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:82063663 on exchange 44848r D: 117125 [EM]Found matching exchange: 44848r, Delegate: (nil) D: 117132 [EM]Rxd Ack; Removing MessageCounter:148867220 from Retrans Table on exchange 44848r D: 117140 [EM]Removed CHIP MessageCounter:148867220 from RetransTable on exchange 44848r I: 117148 [DL]OpenThread SED interval set to 1000ms I: 117160 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:82063664 on exchange 44849r D: 117170 [EM]Handling via exchange: 44849r, Delegate: 0x2000d124 D: 117176 [IM]Received Read request D: 117180 [DMG]IM RH moving to [GeneratingReports] I: 117184 [DL]OpenThread SED interval set to 200ms D: 117189 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 117198 [DMG] Cluster 1d, Attribute 1 is dirty D: 117203 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0001 (expanded=0) D: 117212 [DMG] Sending report (payload has 428 bytes)... I: 117220 [IN]Prepared secure message 0x20005504 to 0x0000000018EB5475 (1) of type 0x5 and protocolId (0, 1) on exchange 44849r with MessageCounter:148867221. I: 117235 [IN]Sending encrypted msg 0x20005504 with MessageCounter:148867221 to 0x0000000018EB5475 (1) at monotonic time: 000000000001C9F2 msec D: 117249 [DMG] OnReportConfirm: NumReports = 0 D: 117255 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 117262 [DMG]IM RH moving to [AwaitingDestruction] D: 117267 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 117532 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:82063665 on exchange 44849r D: 117542 [EM]Found matching exchange: 44849r, Delegate: (nil) D: 117548 [EM]Rxd Ack; Removing MessageCounter:148867221 from Retrans Table on exchange 44849r D: 117557 [EM]Removed CHIP MessageCounter:148867221 from RetransTable on exchange 44849r I: 117565 [DL]OpenThread SED interval set to 1000ms I: 117572 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:82063666 on exchange 44850r D: 117582 [EM]Handling via exchange: 44850r, Delegate: 0x2000d124 D: 117588 [IM]Received Read request D: 117592 [DMG]IM RH moving to [GeneratingReports] I: 117597 [DL]OpenThread SED interval set to 200ms D: 117601 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 117610 [DMG] Cluster 1d, Attribute 2 is dirty D: 117615 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0002 (expanded=0) D: 117624 [DMG] Sending report (payload has 64 bytes)... I: 117631 [IN]Prepared secure message 0x20005504 to 0x0000000018EB5475 (1) of type 0x5 and protocolId (0, 1) on exchange 44850r with MessageCounter:148867222. I: 117645 [IN]Sending encrypted msg 0x20005504 with MessageCounter:148867222 to 0x0000000018EB5475 (1) at monotonic time: 000000000001CB8D msec D: 117659 [DMG] OnReportConfirm: NumReports = 0 D: 117665 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 117672 [DMG]IM RH moving to [AwaitingDestruction] D: 117677 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 117948 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:82063667 on exchange 44850r D: 117959 [EM]Found matching exchange: 44850r, Delegate: (nil) D: 117964 [EM]Rxd Ack; Removing MessageCounter:148867222 from Retrans Table on exchange 44850r D: 117973 [EM]Removed CHIP MessageCounter:148867222 from RetransTable on exchange 44850r I: 117983 [DL]OpenThread SED interval set to 1000ms D: 117988 [IN]Received a duplicate message with MessageCounter:82063667 on exchange 44850r I: 118000 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:82063668 on exchange 44851r D: 118010 [EM]Handling via exchange: 44851r, Delegate: 0x2000d124 D: 118016 [IM]Received Read request D: 118020 [DMG]IM RH moving to [GeneratingReports] I: 118025 [DL]OpenThread SED interval set to 200ms D: 118029 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 118038 [DMG] Cluster 1d, Attribute 3 is dirty D: 118043 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=1 AttributeId=0x0000_0003 (expanded=0) D: 118052 [DMG] Sending report (payload has 36 bytes)... I: 118059 [IN]Prepared secure message 0x20005504 to 0x0000000018EB5475 (1) of type 0x5 and protocolId (0, 1) on exchange 44851r with MessageCounter:148867223. I: 118073 [IN]Sending encrypted msg 0x20005504 with MessageCounter:148867223 to 0x0000000018EB5475 (1) at monotonic time: 000000000001CD39 msec D: 118087 [DMG] OnReportConfirm: NumReports = 0 D: 118092 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 118100 [DMG]IM RH moving to [AwaitingDestruction] D: 118104 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 118396 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:82063669 on exchange 44851r D: 118406 [EM]Found matching exchange: 44851r, Delegate: (nil) D: 118412 [EM]Rxd Ack; Removing MessageCounter:148867223 from Retrans Table on exchange 44851r D: 118422 [EM]Removed CHIP MessageCounter:148867223 from RetransTable on exchange 44851r I: 118430 [DL]OpenThread SED interval set to 1000ms I: 118435 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:82063670 on exchange 44852r D: 118445 [EM]Handling via exchange: 44852r, Delegate: 0x2000d124 D: 118451 [IM]Received Read request D: 118455 [DMG]IM RH moving to [GeneratingReports] I: 118460 [DL]OpenThread SED interval set to 200ms D: 118464 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 118473 [DMG] Cluster 1d, Attribute 0 is dirty D: 118478 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=1 AttributeId=0x0000_0000 (expanded=0) D: 118487 [DMG] Sending report (payload has 70 bytes)... I: 118494 [IN]Prepared secure message 0x20005504 to 0x0000000018EB5475 (1) of type 0x5 and protocolId (0, 1) on exchange 44852r with MessageCounter:148867224. I: 118508 [IN]Sending encrypted msg 0x20005504 with MessageCounter:148867224 to 0x0000000018EB5475 (1) at monotonic time: 000000000001CEEC msec D: 118522 [DMG] OnReportConfirm: NumReports = 0 D: 118527 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 118536 [DMG]IM RH moving to [AwaitingDestruction] D: 118541 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 118610 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:82063671 on exchange 44852r D: 118621 [EM]Found matching exchange: 44852r, Delegate: (nil) D: 118628 [EM]Rxd Ack; Removing MessageCounter:148867224 from Retrans Table on exchange 44852r D: 118637 [EM]Removed CHIP MessageCounter:148867224 from RetransTable on exchange 44852r I: 118645 [DL]OpenThread SED interval set to 1000ms I: 118650 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:82063672 on exchange 44853r D: 118660 [EM]Handling via exchange: 44853r, Delegate: 0x2000d124 D: 118666 [IM]Received Read request D: 118670 [DMG]IM RH moving to [GeneratingReports] I: 118674 [DL]OpenThread SED interval set to 200ms D: 118679 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 118688 [DMG] Cluster 1d, Attribute 1 is dirty D: 118693 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=1 AttributeId=0x0000_0001 (expanded=0) D: 118702 [DMG] Sending report (payload has 93 bytes)... I: 118709 [IN]Prepared secure message 0x20005504 to 0x0000000018EB5475 (1) of type 0x5 and protocolId (0, 1) on exchange 44853r with MessageCounter:148867225. I: 118723 [IN]Sending encrypted msg 0x20005504 with MessageCounter:148867225 to 0x0000000018EB5475 (1) at monotonic time: 000000000001CFC3 msec D: 118737 [DMG] OnReportConfirm: NumReports = 0 D: 118743 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 118750 [DMG]IM RH moving to [AwaitingDestruction] D: 118756 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 118823 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:82063673 on exchange 44853r D: 118833 [EM]Found matching exchange: 44853r, Delegate: (nil) D: 118839 [EM]Rxd Ack; Removing MessageCounter:148867225 from Retrans Table on exchange 44853r D: 118849 [EM]Removed CHIP MessageCounter:148867225 from RetransTable on exchange 44853r I: 118857 [DL]OpenThread SED interval set to 1000ms I: 118863 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:82063674 on exchange 44854r D: 118873 [EM]Handling via exchange: 44854r, Delegate: 0x2000d124 D: 118879 [IM]Received Read request D: 118882 [DMG]IM RH moving to [GeneratingReports] I: 118887 [DL]OpenThread SED interval set to 200ms D: 118892 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 118900 [DMG] Cluster 1d, Attribute 2 is dirty D: 118906 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=1 AttributeId=0x0000_0002 (expanded=0) D: 118915 [DMG] Sending report (payload has 36 bytes)... I: 118921 [IN]Prepared secure message 0x20005504 to 0x0000000018EB5475 (1) of type 0x5 and protocolId (0, 1) on exchange 44854r with MessageCounter:148867226. I: 118935 [IN]Sending encrypted msg 0x20005504 with MessageCounter:148867226 to 0x0000000018EB5475 (1) at monotonic time: 000000000001D097 msec D: 118949 [DMG] OnReportConfirm: NumReports = 0 D: 118954 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 118962 [DMG]IM RH moving to [AwaitingDestruction] D: 118967 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 119238 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:82063675 on exchange 44854r D: 119249 [EM]Found matching exchange: 44854r, Delegate: (nil) D: 119254 [EM]Rxd Ack; Removing MessageCounter:148867226 from Retrans Table on exchange 44854r D: 119263 [EM]Removed CHIP MessageCounter:148867226 from RetransTable on exchange 44854r I: 119271 [DL]OpenThread SED interval set to 1000ms E: 125913 [BLE]ack recv timeout, closing ep 0x2000f758 D: 125918 [IN]Clearing BLE pending packets. I: 125922 [BLE]Releasing end point's BLE connection back to application. I: 125929 [DL]Closing BLE GATT connection (ConnId 00) uart:~$ I: 222802 [FS]Fail-safe timer expired E: 222805 [SVR]Failsafe timer expired D: 222808 [IN]SecureSession[0x20003988]: MarkForEviction Type:1 LSID:21255 I: 222815 [SC]SecureSession[0x20003988]: Moving from state 'kActive' --> 'kPendingEviction' D: 222823 [IN]SecureSession[0x20003988]: Released - Type:1 LSID:21255 E: 222829 [SVR]Commissioning failed (attempt 1): 32 D: 222837 [IN]SecureSession[0x20003988]: Allocated Type:1 LSID:21257 D: 222843 [SC]Assigned local session key ID 21257 D: 222847 [SC]Waiting for PBKDF param request D: 222851 [DL]CHIPoBLE advertising set to on I: 222855 [DIS]Updating services using commissioning mode 1 D: 222860 [DL]Using Thread extended MAC for hostname. I: 222865 [DIS]Advertise operational node 3199E9CFDD25901B-00000000DC8882F6 D: 222872 [DL]Using Thread extended MAC for hostname. I: 222878 [DIS]Advertise commission parameter vendorID=65521 productID=32774 discriminator=3847/15 cm=1 I: 222888 [DL]advertising srp service: 732337CE029EF328._matterc._udp E: 222894 [ZCL]OpCreds: Got FailSafeTimerExpired E: 222898 [ZCL]OpCreds: Proceeding to FailSafeCleanup on fail-safe expiry! D: 222941 [IN]Expiring all sessions for fabric 0x1!! D: 222946 [IN]SecureSession[0x200038d0]: MarkForEviction Type:2 LSID:21254 I: 222954 [SC]SecureSession[0x200038d0]: Moving from state 'kActive' --> 'kPendingEviction' D: 222962 [IN]SecureSession[0x200038d0]: Released - Type:2 LSID:21254 E: 222969 [FP]Reverting pending fabric data for fabric 0x1 D: 222975 [EVL]LogEvent event number: 0x0000000000000003 priority: 1, endpoint id: 0x0 cluster id: 0x0000_0028 event id: 0x2 Sys timestamp: 0x00000000000366FE D: 222989 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet E: 222996 [FP]Warning: metadata not found during delete of fabric 0x1 I: 223039 [FP]Fabric (0x1) deleted. I: 223042 [ZCL][OnFabricRemoved] Handling a fabric removal from the door lock server [endpointId=1,fabricIndex=1] I: 223054 [ZCL]Getting lock user 1: available I: 223058 [ZCL]Getting lock user 2: available I: 223063 [ZCL]Getting lock user 3: available I: 223067 [ZCL]Getting lock user 4: available I: 223071 [ZCL]Getting lock user 5: available I: 223075 [ZCL]Getting lock user 6: available I: 223079 [ZCL]Getting lock user 7: available I: 223083 [ZCL]Getting lock user 8: available I: 223087 [ZCL]Getting lock user 9: available I: 223091 [ZCL]Getting lock user 10: available I: 223096 [ZCL]Getting lock credential 1: available I: 223100 [ZCL]Getting lock credential 2: available I: 223105 [ZCL]Getting lock credential 3: available I: 223109 [ZCL]Getting lock credential 4: available I: 223114 [ZCL]Getting lock credential 5: available I: 223119 [ZCL]Getting lock credential 6: available I: 223123 [ZCL]Getting lock credential 7: available I: 223128 [ZCL]Getting lock credential 8: available I: 223132 [ZCL]Getting lock credential 9: available I: 223137 [ZCL]Getting lock credential 10: available E: 223143 [ZCL][clearFabricFromCredentials] Unable to clear fabric from credential - couldn't read credential from database [endpointId=1,credentialType=0,credentialIndex=0,fabricIdToRemove=1] I: 223160 [ZCL]UserLabel: Last Fabric index 0x1 was removed I: 223165 [ZCL]OpCreds: Fabric index 0x1 was removed D: 223171 [DL]SRP update succeeded D: 223175 [DMG]Endpoint 0, Cluster 0x0000_003E update version to e0419b05 D: 223182 [DMG]Endpoint 0, Cluster 0x0000_003E update version to e0419b06 I: 223212 [TS]Pending Last Known Good Time: 2022-10-17T10:31:31 I: 223218 [TS]Previous Last Known Good Time: 2022-10-17T10:31:31 I: 223224 [TS]Reverted Last Known Good Time to previous value D: 223230 [EVL]LogEvent event number: 0x0000000000000004 priority: 1, endpoint id: 0x0 cluster id: 0x0000_0028 event id: 0x2 Sys timestamp: 0x00000000000367FE D: 223244 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet E: 223251 [FP]Warning: metadata not found during delete of fabric 0x1 E: 223259 [ZCL]OpCreds: failed to delete fabric at index 1: d8 D: 223265 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 1c59f810 D: 223272 [ZCL]Failsafe timeout, tell platform driver to revert network credentials. I: 223279 [NP]Reverting Thread operational dataset E: 223292 [DL]Long dispatch time: 487 ms, for event type 32782 I: 223298 [FS]Fail-safe cleanly disarmed I: 223304 [DL]CHIPoBLE advertising started D: 223308 [DL]OpenThread State Changed (Flags: 0x11002046) D: 223313 [DL] Device Role: DISABLED D: 223316 [DL] Thread Unicast Addresses: D: 223320 [DL] fd23:7405:2b5e:1:4dfe:df27:6574:125/64 valid preferred D: 223328 [DL]OpenThread State Changed (Flags: 0x10000000) I: 223335 [DL]NFC Tag emulation started I: 253307 [DL]CHIPoBLE advertising mode changed to slow uart:~$