uart:~$ I: Factory Reset has been triggered. Release button within 3000 ms to cancel. I: Factory Reset triggered I: 26405 [TS]Pending Last Known Good Time: 2022-10-19T14:09:14 I: 26411 [TS]Previous Last Known Good Time: 2022-10-19T14:09:14 I: 26417 [TS]Reverted Last Known Good Time to previous value D: 26423 [ZCL]Emitting ShutDown event D: 26426 [EVL]LogEvent event number: 0x0000000000000002 priority: 2, endpoint id: 0x0 cluster id: 0x0000_0028 event id: 0x1 Sys timestamp: 0x000000000000673A D: 26440 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 26446 [DL]Performing factory reset I: 26461 [DL]Erasing Thread persistent info... I: nRF5 802154 radio initialized I: 4 Sectors of 4096 bytes I: alloc wra: 2, cb0 I: data wra: 2, 308 ooting Zephyr OS build v3.1.99-ncs1 *** I: Init CHIP stack 32muart:~$ I: 232 [DL]BLE address: D4:97:5D:6B:75:6B 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: 255 [DL]OpenThread SED interval set to 1000ms I: 264 [DL]OpenThread started: OK I: 267 [DL]Setting OpenThread device type to SLEEPY END DEVICE I: 274 [SVR]Server initializing... D: 277 [FP]Initializing FabricTable from persistent storage I: 283 [TS]Last Known Good Time: [unknown] I: 287 [TS]Setting Last Known Good Time to firmware build time 2022-10-19T14:09:14 I: 299 [DMG]AccessControl: initializing I: 303 [DMG]Examples::AccessControlDelegate::Init I: 307 [DMG]AccessControl: setting I: 311 [DMG]DefaultAclStorage: initializing I: 314 [DMG]DefaultAclStorage: 0 entries loaded D: 319 [IN]UDP::Init bind&listen port=5540 E: 323 [IN]SO_REUSEPORT failed: 109 D: 326 [IN]UDP::Init bound to port=5540 D: 330 [IN]BLEBase::Init - setting/overriding transport D: 334 [IN]TransportMgr initialized D: 346 [DL]Using Thread extended MAC for hostname. I: 355 [ZCL]Using ZAP configuration... D: 360 [DMG]Failed to read stored attribute (0, 0x0000_0028, 0x0000_0005: a0 D: 367 [DMG]Failed to read stored attribute (0, 0x0000_0028, 0x0000_0010: a0 I: 375 [DMG]AccessControlCluster: initializing D: 379 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to bdff0cdb D: 386 [DL]Boot reason: 6 D: 388 [ZCL]GeneralDiagnostics: OnDeviceReboot D: 392 [DMG]Endpoint 0, Cluster 0x0000_0033 update version to 788550d6 D: 399 [EVL]LogEvent event number: 0x0000000000000000 priority: 2, endpoint id: 0x0 cluster id: 0x0000_0033 event id: 0x3 Sys timestamp: 0x000000000000018F I: 413 [ZCL]Initiating Admin Commissioning cluster. D: 417 [DMG]Endpoint 1, Cluster 0x0000_0003 update version to f2661db3 D: 424 [DMG]Endpoint 1, Cluster 0x0000_0004 update version to 272bbd01 D: 430 [DMG]Endpoint 1, Cluster 0x0000_0004 update version to 272bbd02 I: 436 [DIS]Updating services using commissioning mode 0 D: 442 [DL]Using Thread extended MAC for hostname. D: 446 [DL]Using Thread extended MAC for hostname. I: 452 [DIS]Advertise commission parameter vendorID=65521 productID=32772 discriminator=4003/15 cm=0 E: 461 [DIS]Failed to advertise extended commissionable node: 3 D: 467 [DIS]Scheduling extended discovery timeout in 900s E: 472 [DIS]Failed to finalize service update: 1c I: 476 [DIS]Delaying proxy of operational discovery: missing delegate I: 482 [IN]CASE Server enabling CASE session setups D: 487 [IN]SecureSession[0x20003560]: Allocated Type:2 LSID:28613 D: 493 [SC]Allocated SecureSession (0x20003560) - waiting for Sigma1 msg I: 500 [SVR]Joining Multicast groups D: 503 [ZCL]Emitting StartUp event D: 506 [EVL]LogEvent event number: 0x0000000000000001 priority: 2, endpoint id: 0x0 cluster id: 0x0000_0028 event id: 0x0 Sys timestamp: 0x00000000000001FA I: 520 [SVR]Server Listening... I: 523 [DL]Device Configuration: I: 527 [DL] Serial Number: 11223344556677889900 I: 531 [DL] Vendor Id: 65521 (0xFFF1) I: 535 [DL] Product Id: 32772 (0x8004) I: 539 [DL] Hardware Version: 0 I: 543 [DL] Setup Pin Code (0 for UNKNOWN/ERROR): 20202021 I: 549 [DL] Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 4003 (0xFA3) I: 557 [DL] Manufacturing Date: (not set) I: 560 [DL] Device Type: 65535 (0xFFFF) I: 566 [SVR]SetupQRCode: [MT:4CT91S0.032B0648G00] I: 570 [SVR]Copy/paste the below URL in a browser to see the QR Code: I: 576 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A4CT91S0.032B0648G00 I: 585 [SVR]Manual pairing code: [34970112332] I: 591 [DL]CHIP task running I: 593 [DIS]Updating services using commissioning mode 0 D: 598 [DL]Using Thread extended MAC for hostname. D: 603 [DL]Using Thread extended MAC for hostname. I: 609 [DIS]Advertise commission parameter vendorID=65521 productID=32772 discriminator=4003/15 cm=0 E: 618 [DIS]Failed to advertise extended commissionable node: 3 E: 624 [DIS]Failed to finalize service update: 1c I: Initialize binding Handler I: 632 [SVR]Cannot load binding table: a0 I: Binding Table size: [0]: I: Enabling BLE advertising... D: 25238 [IN]SecureSession[0x20003618]: Allocated Type:1 LSID:28614 D: 25244 [SC]Assigned local session key ID 28614 D: 25248 [SC]Waiting for PBKDF param request D: 25252 [DL]CHIPoBLE advertising set to on I: 25256 [DIS]Updating services using commissioning mode 1 D: 25261 [DL]Using Thread extended MAC for hostname. D: 25267 [DL]Using Thread extended MAC for hostname. I: 25272 [DIS]Advertise commission parameter vendorID=65521 productID=32772 discriminator=4003/15 cm=1 E: 25282 [DIS]Failed to advertise commissionable node: 3 E: 25287 [DIS]Failed to finalize service update: 1c I: 25294 [DL]CHIPoBLE advertising started I: 25300 [DL]NFC Tag emulation started I: 43895 [DL]BLE connection established (ConnId: 0x00) I: 43900 [DL]Current number of connections: 1/1 I: 43904 [DL]CHIPoBLE advertising stopped I: 43908 [DL]NFC Tag emulation stopped D: 45019 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 45026 [BLE]local and remote recv window sizes = 5 I: 45031 [BLE]selected BTP version 4 I: 45035 [BLE]using BTP fragment sizes rx 128 / tx 128. D: 45042 [DL]ConnId: 0x00, New CCCD value: 0x0002 D: 45046 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 6) D: 45054 [IN]BLE EndPoint 0x2000f3c8 Connection Complete I: 45059 [DL]CHIPoBLE connection established (ConnId: 0x00, GATT MTU: 131) D: 45214 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 45304 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 45312 [EM]Received message of type 0x20 with protocolId (0, 0) and MessageCounter:140944385 on exchange 30940r D: 45322 [EM]Handling via exchange: 30940r, Delegate: 0x20005744 D: 45328 [SC]Received PBKDF param request D: 45331 [SC]Peer assigned session ID 37448 D: 45335 [SC]Found MRP parameters in the message D: 45340 [SC]Including MRP parameters in PBKDF param response I: 45346 [IN]Prepared unauthenticated message 0x2002be28 to 0x0000000000000000 (0) of type 0x21 and protocolId (0, 0) on exchange 30940r with MessageCounter:245520773. I: 45361 [IN]Sending unauthenticated msg 0x2002be28 with MessageCounter:245520773 to 0x0000000000000000 at monotonic time: 000000000000B131 msec D: 45374 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 45382 [SC]Sent PBKDF param response D: 45484 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 45492 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 14) D: 45709 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 45717 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 45725 [EM]Received message of type 0x22 with protocolId (0, 0) and MessageCounter:140944386 on exchange 30940r D: 45735 [EM]Found matching exchange: 30940r, Delegate: 0x20005744 D: 45741 [SC]Received spake2p msg1 I: 47706 [IN]Prepared unauthenticated message 0x2002bdb8 to 0x0000000000000000 (0) of type 0x23 and protocolId (0, 0) on exchange 30940r with MessageCounter:245520774. I: 47721 [IN]Sending unauthenticated msg 0x2002bdb8 with MessageCounter:245520774 to 0x0000000000000000 at monotonic time: 000000000000BA68 msec D: 47734 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 47741 [SC]Sent spake2p msg2 E: 47744 [DL]Long dispatch time: 2027 ms, for event type 16388 D: 47869 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 47877 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 6) D: 47960 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 47967 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 47975 [EM]Received message of type 0x24 with protocolId (0, 0) and MessageCounter:140944387 on exchange 30940r D: 47985 [EM]Found matching exchange: 30940r, Delegate: 0x20005744 D: 47991 [SC]Received spake2p msg3 D: 47994 [SC]Sending status report. Protocol code 0, exchange 30940 I: 48001 [IN]Prepared unauthenticated message 0x2002be40 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 30940r with MessageCounter:245520775. I: 48016 [IN]Sending unauthenticated msg 0x2002be40 with MessageCounter:245520775 to 0x0000000000000000 at monotonic time: 000000000000BB90 msec D: 48029 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 35) I: 48037 [SC]SecureSession[0x20003618]: Moving from state 'kEstablishing' --> 'kActive' D: 48045 [IN]SecureSession[0x20003618]: Activated - Type:1 LSID:28614 D: 48052 [IN]New secure session activated for device , LSID:28614 PSID:37448! I: 48060 [SVR]Commissioning completed session establishment step I: 48066 [DIS]Updating services using commissioning mode 0 D: 48072 [DL]Using Thread extended MAC for hostname. D: 48077 [DL]Using Thread extended MAC for hostname. I: 48082 [DIS]Advertise commission parameter vendorID=65521 productID=32772 discriminator=4003/15 cm=0 E: 48092 [DIS]Failed to advertise extended commissionable node: 3 D: 48098 [DIS]Scheduling extended discovery timeout in 900s E: 48104 [DIS]Failed to finalize service update: 1c D: 48108 [DL]CHIPoBLE advertising set to off I: 48113 [SVR]Device completed Rendezvous process E: 48117 [DL]Long dispatch time: 150 ms, for event type 16388 D: 48123 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 48130 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 48138 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:104985054 on exchange 30941r D: 48149 [EM]Handling via exchange: 30941r, Delegate: 0x2000cd94 D: 48154 [IM]Received Read request D: 48158 [DMG]IM RH moving to [GeneratingReports] D: 48163 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 48171 [DMG] Cluster 28, Attribute 2 is dirty D: 48176 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0002 (expanded=0) D: 48186 [DMG] Sending report (payload has 37 bytes)... I: 48192 [IN]Prepared secure message 0x2002bfd8 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 30941r with MessageCounter:163334052. I: 48206 [IN]Sending encrypted msg 0x2002bfd8 with MessageCounter:163334052 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000BC4E msec D: 48219 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72) D: 48226 [DMG] OnReportConfirm: NumReports = 0 D: 48231 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 48238 [DMG]IM RH moving to [AwaitingDestruction] D: 48243 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 48320 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 48327 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 48335 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:104985055 on exchange 30942r D: 48345 [EM]Handling via exchange: 30942r, Delegate: 0x2000cd94 D: 48351 [IM]Received Read request D: 48355 [DMG]IM RH moving to [GeneratingReports] D: 48359 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 48368 [DMG] Cluster 28, Attribute 4 is dirty D: 48373 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0004 (expanded=0) D: 48382 [DMG] Sending report (payload has 37 bytes)... I: 48388 [IN]Prepared secure message 0x2002bfd8 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 30942r with MessageCounter:163334053. I: 48403 [IN]Sending encrypted msg 0x2002bfd8 with MessageCounter:163334053 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000BD12 msec D: 48416 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72) D: 48423 [DMG] OnReportConfirm: NumReports = 0 D: 48428 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 48435 [DMG]IM RH moving to [AwaitingDestruction] D: 48440 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 48499 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 48589 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 48597 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:104985056 on exchange 30943r D: 48607 [EM]Handling via exchange: 30943r, Delegate: 0x2000cd94 D: 48613 [IM]Received Read request D: 48617 [DMG]IM RH moving to [GeneratingReports] D: 48621 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 48630 [DMG] Cluster 3e, Attribute 2 is dirty D: 48635 [DMG]Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_0002 (expanded=0) D: 48644 [DMG] Sending report (payload has 36 bytes)... I: 48650 [IN]Prepared secure message 0x2002bfd8 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 30943r with MessageCounter:163334054. I: 48664 [IN]Sending encrypted msg 0x2002bfd8 with MessageCounter:163334054 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000BE18 msec D: 48677 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 48685 [DMG] OnReportConfirm: NumReports = 0 D: 48690 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 48697 [DMG]IM RH moving to [AwaitingDestruction] D: 48702 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 48770 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 48777 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 48785 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:104985057 on exchange 30944r D: 48795 [EM]Handling via exchange: 30944r, Delegate: 0x2000cd94 D: 48801 [IM]Received Read request D: 48805 [DMG]IM RH moving to [GeneratingReports] D: 48809 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 48818 [DMG] Cluster 3e, Attribute 3 is dirty D: 48823 [DMG]Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_0003 (expanded=0) D: 48832 [DMG] Sending report (payload has 36 bytes)... I: 48838 [IN]Prepared secure message 0x2002bfd8 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 30944r with MessageCounter:163334055. I: 48852 [IN]Sending encrypted msg 0x2002bfd8 with MessageCounter:163334055 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000BED4 msec D: 48865 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 48873 [DMG] OnReportConfirm: NumReports = 0 D: 48877 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 48885 [DMG]IM RH moving to [AwaitingDestruction] D: 48889 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 48994 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 49040 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 49048 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:104985058 on exchange 30945r D: 49058 [EM]Handling via exchange: 30945r, Delegate: 0x2000cd94 D: 49063 [IM]Received Read request D: 49067 [DMG]IM RH moving to [GeneratingReports] D: 49072 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 49080 [DMG] Cluster 1d, Attribute 1 is dirty D: 49086 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0001 (expanded=0) D: 49095 [DMG] Sending report (payload has 512 bytes)... I: 49104 [IN]Prepared secure message 0x2002bfd8 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 30945r with MessageCounter:163334056. I: 49118 [IN]Sending encrypted msg 0x2002bfd8 with MessageCounter:163334056 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000BFDE msec D: 49131 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 49138 [DMG] OnReportConfirm: NumReports = 0 D: 49143 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 49150 [DMG]IM RH moving to [AwaitingDestruction] D: 49155 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 49219 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 49227 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 49354 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 49362 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 49444 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 49452 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 49535 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 49542 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 49549 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 43) D: 49625 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 49632 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 49640 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:104985059 on exchange 30946r D: 49650 [EM]Handling via exchange: 30946r, Delegate: 0x2000cd94 D: 49656 [IM]Received Read request D: 49660 [DMG]IM RH moving to [GeneratingReports] D: 49664 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 49673 [DMG] Cluster 31, Attribute fffc is dirty D: 49678 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFC (expanded=0) D: 49687 [DMG] Sending report (payload has 37 bytes)... I: 49694 [IN]Prepared secure message 0x2002bfd8 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 30946r with MessageCounter:163334057. I: 49708 [IN]Sending encrypted msg 0x2002bfd8 with MessageCounter:163334057 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000C22B msec D: 49721 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72) D: 49728 [DMG] OnReportConfirm: NumReports = 0 D: 49733 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 49740 [DMG]IM RH moving to [AwaitingDestruction] D: 49745 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 49804 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 50479 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 50487 [EM]Received message of type 0xa with protocolId (0, 1) and MessageCounter:104985060 on exchange 30947r D: 50497 [EM]Handling via exchange: 30947r, Delegate: 0x2000cd94 D: 50503 [DMG]Got Timed Request with timeout 10000: handler 0x2000d190 exchange 30947r I: 50511 [IN]Prepared secure message 0x2002bda8 to 0xFFFFFFFB00000000 (0) of type 0x1 and protocolId (0, 1) on exchange 30947r with MessageCounter:163334058. I: 50526 [IN]Sending encrypted msg 0x2002bda8 with MessageCounter:163334058 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000C55D msec D: 50538 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 43) D: 50546 [DMG]Timed Request time limit 0x000000000000EC82: handler 0x2000d190 exchange 30947r D: 50615 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 50622 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 50630 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:104985061 on exchange 30947r D: 50640 [EM]Found matching exchange: 30947r, Delegate: 0x2000d190 D: 50646 [DMG]Timed following action arrived at 0x000000000000C5D6: handler 0x2000d190 exchange 30947r D: 50655 [DMG]Handing timed invoke to IM engine: handler 0x2000d190 exchange 30947r D: 50663 [DMG]Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000 I: 50671 [FS]GeneralCommissioning: Received ArmFailSafe (120s) D: 50677 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to bdff0cdc D: 50683 [DMG]Command handler moving to [ Preparing] D: 50688 [DMG]Command handler moving to [AddingComm] D: 50693 [DMG]Command handler moving to [AddedComma] D: 50698 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 50705 [IN]Prepared secure message 0x2002be28 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 30947r with MessageCounter:163334059. I: 50719 [IN]Sending encrypted msg 0x2002be28 with MessageCounter:163334059 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000C61F msec D: 50732 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 50740 [DMG]Command handler moving to [CommandSen] D: 50744 [DMG]Command handler moving to [AwaitingDe] E: 50749 [DL]Long dispatch time: 127 ms, for event type 16388 D: 50795 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 50802 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 50810 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:104985062 on exchange 30948r D: 50820 [EM]Handling via exchange: 30948r, Delegate: 0x2000cd94 D: 50826 [IM]Received Read request D: 50830 [DMG]IM RH moving to [GeneratingReports] D: 50834 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 50843 [DMG] Cluster 30, Attribute 3 is dirty D: 50848 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0003 (expanded=0) D: 50857 [DMG] Sending report (payload has 36 bytes)... I: 50863 [IN]Prepared secure message 0x2002bfd8 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 30948r with MessageCounter:163334060. I: 50877 [IN]Sending encrypted msg 0x2002bfd8 with MessageCounter:163334060 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000C6BD msec D: 50891 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 50898 [DMG] OnReportConfirm: NumReports = 0 D: 50903 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 50910 [DMG]IM RH moving to [AwaitingDestruction] D: 50915 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 50975 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 50982 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 50990 [EM]Received message of type 0xa with protocolId (0, 1) and MessageCounter:104985063 on exchange 30949r D: 51000 [EM]Handling via exchange: 30949r, Delegate: 0x2000cd94 D: 51006 [DMG]Got Timed Request with timeout 10000: handler 0x2000d190 exchange 30949r I: 51014 [IN]Prepared secure message 0x2002bda8 to 0xFFFFFFFB00000000 (0) of type 0x1 and protocolId (0, 1) on exchange 30949r with MessageCounter:163334061. I: 51029 [IN]Sending encrypted msg 0x2002bda8 with MessageCounter:163334061 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000C754 msec D: 51041 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 43) D: 51049 [DMG]Timed Request time limit 0x000000000000EE79: handler 0x2000d190 exchange 30949r D: 51109 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 51117 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 51125 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:104985064 on exchange 30949r D: 51135 [EM]Found matching exchange: 30949r, Delegate: 0x2000d190 D: 51141 [DMG]Timed following action arrived at 0x000000000000C7C5: handler 0x2000d190 exchange 30949r D: 51150 [DMG]Handing timed invoke to IM engine: handler 0x2000d190 exchange 30949r D: 51158 [DMG]Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0002 D: 51174 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to bdff0cdd D: 51181 [DMG]Command handler moving to [ Preparing] D: 51186 [DMG]Command handler moving to [AddingComm] D: 51190 [DMG]Command handler moving to [AddedComma] D: 51195 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 51203 [IN]Prepared secure message 0x2002be28 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 30949r with MessageCounter:163334062. I: 51217 [IN]Sending encrypted msg 0x2002be28 with MessageCounter:163334062 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000C811 msec D: 51230 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 51237 [DMG]Command handler moving to [CommandSen] D: 51242 [DMG]Command handler moving to [AwaitingDe] E: 51247 [DL]Long dispatch time: 130 ms, for event type 16388 D: 51290 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 51297 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 51305 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:104985065 on exchange 30950r D: 51315 [EM]Handling via exchange: 30950r, Delegate: 0x2000cd94 D: 51321 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 I: 51329 [ZCL]OpCreds: Certificate Chain request received for DAC D: 51335 [DMG]Command handler moving to [ Preparing] D: 51340 [DMG]Command handler moving to [AddingComm] D: 51345 [DMG]Command handler moving to [AddedComma] D: 51350 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 51359 [IN]Prepared secure message 0x2002bea0 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 30950r with MessageCounter:163334063. I: 51373 [IN]Sending encrypted msg 0x2002bea0 with MessageCounter:163334063 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000C8AD msec D: 51386 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 51394 [DMG]Command handler moving to [CommandSen] D: 51399 [DMG]Command handler moving to [AwaitingDe] E: 51403 [DL]Long dispatch time: 106 ms, for event type 16388 D: 51514 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 51522 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 51604 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 51612 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 51694 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 51702 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 51785 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 51792 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 51800 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 58) D: 51875 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 51882 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 51890 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:104985066 on exchange 30951r D: 51900 [EM]Handling via exchange: 30951r, Delegate: 0x2000cd94 D: 51907 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 I: 51914 [ZCL]OpCreds: Certificate Chain request received for PAI D: 51920 [DMG]Command handler moving to [ Preparing] D: 51925 [DMG]Command handler moving to [AddingComm] D: 51930 [DMG]Command handler moving to [AddedComma] D: 51935 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 51944 [IN]Prepared secure message 0x2002bea0 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 30951r with MessageCounter:163334064. I: 51958 [IN]Sending encrypted msg 0x2002bea0 with MessageCounter:163334064 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000CAF6 msec D: 51971 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 51979 [DMG]Command handler moving to [CommandSen] D: 51983 [DMG]Command handler moving to [AwaitingDe] E: 51988 [DL]Long dispatch time: 106 ms, for event type 16388 D: 52054 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 52062 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 52144 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 52152 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 52234 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 52242 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 52324 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 52332 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 52339 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 28) D: 52414 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 52422 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 52430 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:104985067 on exchange 30952r D: 52440 [EM]Handling via exchange: 30952r, Delegate: 0x2000cd94 D: 52447 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0000 I: 52454 [ZCL]OpCreds: Received an AttestationRequest command I: 52490 [ZCL]OpCreds: AttestationRequest successful. D: 52495 [DMG]Command handler moving to [ Preparing] D: 52500 [DMG]Command handler moving to [AddingComm] D: 52505 [DMG]Command handler moving to [AddedComma] D: 52510 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 52520 [IN]Prepared secure message 0x2002bea0 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 30952r with MessageCounter:163334065. I: 52534 [IN]Sending encrypted msg 0x2002bea0 with MessageCounter:163334065 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000CD36 msec D: 52547 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 52555 [DMG]Command handler moving to [CommandSen] D: 52559 [DMG]Command handler moving to [AwaitingDe] E: 52564 [DL]Long dispatch time: 142 ms, for event type 16388 D: 52684 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 52692 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 52819 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 52827 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 52909 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 52917 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 53000 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 53007 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 53015 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 53089 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 53097 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 92) D: 53224 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 53232 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 53240 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:104985068 on exchange 30953r D: 53250 [EM]Handling via exchange: 30953r, Delegate: 0x2000cd94 D: 53257 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0004 I: 53264 [ZCL]OpCreds: Received a CSRRequest command D: 53269 [ZCL]OpCreds: Finding fabric with fabricIndex 0x0 I: 53468 [ZCL]OpCreds: AllocatePendingOperationalKey succeeded I: 53504 [ZCL]OpCreds: CSRRequest successful. D: 53508 [DMG]Command handler moving to [ Preparing] D: 53513 [DMG]Command handler moving to [AddingComm] D: 53518 [DMG]Command handler moving to [AddedComma] D: 53523 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 53531 [IN]Prepared secure message 0x2002bea0 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 30953r with MessageCounter:163334066. I: 53546 [IN]Sending encrypted msg 0x2002bea0 with MessageCounter:163334066 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000D129 msec D: 53558 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 53566 [DMG]Command handler moving to [CommandSen] D: 53571 [DMG]Command handler moving to [AwaitingDe] E: 53575 [DL]Long dispatch time: 343 ms, for event type 16388 D: 53629 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 53637 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 53719 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 53727 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 53809 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 55609 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 55617 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:104985069 on exchange 30954r D: 55627 [EM]Handling via exchange: 30954r, Delegate: 0x2000cd94 D: 55633 [IM]Received Read request D: 55637 [DMG]IM RH moving to [GeneratingReports] D: 55641 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 55650 [DMG] Cluster 3e, Attribute 1 is dirty D: 55655 [DMG]Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_0001 (expanded=0) D: 55664 [DMG] Sending report (payload has 36 bytes)... I: 55670 [IN]Prepared secure message 0x2002bfd8 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 30954r with MessageCounter:163334067. I: 55684 [IN]Sending encrypted msg 0x2002bfd8 with MessageCounter:163334067 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000D984 msec D: 55697 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 55705 [DMG] OnReportConfirm: NumReports = 0 D: 55710 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 55717 [DMG]IM RH moving to [AwaitingDestruction] D: 55722 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 55789 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 55797 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 55880 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 55970 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 55979 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:104985070 on exchange 30955r D: 55989 [EM]Handling via exchange: 30955r, Delegate: 0x2000cd94 D: 55995 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B I: 56003 [ZCL]OpCreds: Received an AddTrustedRootCertificate command I: 56067 [ZCL]OpCreds: AddTrustedRootCertificate successful. D: 56072 [DMG]Command handler moving to [ Preparing] D: 56077 [DMG]Command handler moving to [AddingComm] D: 56082 [DMG]Command handler moving to [AddedComma] D: 56087 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 56094 [IN]Prepared secure message 0x2002bea0 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 30955r with MessageCounter:163334068. I: 56108 [IN]Sending encrypted msg 0x2002bea0 with MessageCounter:163334068 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000DB2C msec D: 56121 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 68) D: 56129 [DMG]Command handler moving to [CommandSen] D: 56133 [DMG]Command handler moving to [AwaitingDe] E: 56138 [DL]Long dispatch time: 168 ms, for event type 16388 D: 56194 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 56202 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 56285 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 56375 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 56510 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 56517 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3) D: 56599 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 56607 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 56689 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 56700 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:104985071 on exchange 30956r D: 56710 [EM]Handling via exchange: 30956r, Delegate: 0x2000cd94 D: 56717 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0006 I: 56724 [ZCL]OpCreds: Received an AddNOC command I: 56733 [FP]Validating NOC chain I: 56851 [FP]NOC chain validation successful I: 56855 [FP]Added new fabric at index: 0x1 I: 56859 [FP]Assigned compressed fabric ID: 0x3199E9CFDD25901B, node ID: 0x00000000E950E4F5 I: 56867 [TS]Last Known Good Time: 2022-10-19T14:09:14 I: 56872 [TS]New proposed Last Known Good Time: 2022-10-19T06:13:01 I: 56878 [TS]Retaining current Last Known Good Time D: 56883 [DMG]Endpoint 0, Cluster 0x0000_003E update version to c613994a D: 56890 [DMG]Endpoint 0, Cluster 0x0000_003E update version to c613994b D: 56928 [EVL]LogEvent event number: 0x0000000000000002 priority: 1, endpoint id: 0x0 cluster id: 0x0000_001F event id: 0x0 Sys timestamp: 0x000000000000DE60 I: 56942 [ZCL]OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0xFFFFFFFD00010001 D: 56951 [DL]Using Thread extended MAC for hostname. I: 56956 [DIS]Advertise operational node 3199E9CFDD25901B-00000000E950E4F5 D: 56963 [DMG]Endpoint 0, Cluster 0x0000_003E update version to c613994c D: 56969 [DMG]Endpoint 0, Cluster 0x0000_003E update version to c613994d D: 56976 [DMG]Command handler moving to [ Preparing] D: 56981 [DMG]Command handler moving to [AddingComm] D: 56985 [DMG]Command handler moving to [AddedComma] I: 56990 [ZCL]OpCreds: successfully created fabric index 0x1 via AddNOC D: 56997 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 57004 [IN]Prepared secure message 0x2002bea0 to 0xFFFFFFFB00000000 (1) of type 0x9 and protocolId (0, 1) on exchange 30956r with MessageCounter:163334069. I: 57018 [IN]Sending encrypted msg 0x2002bea0 with MessageCounter:163334069 to 0xFFFFFFFB00000000 (1) at monotonic time: 000000000000DEBA msec D: 57031 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 57039 [DMG]Command handler moving to [CommandSen] D: 57043 [DMG]Command handler moving to [AwaitingDe] E: 57048 [DL]Long dispatch time: 359 ms, for event type 16388 D: 57139 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 57147 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 57229 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 57238 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:104985072 on exchange 30957r D: 57248 [EM]Handling via exchange: 30957r, Delegate: 0x2000cd94 D: 57254 [DMG]Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0003 D: 57275 [DMG]Command handler moving to [ Preparing] D: 57280 [DMG]Command handler moving to [AddingComm] D: 57285 [DMG]Command handler moving to [AddedComma] D: 57290 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to bdff0cde D: 57296 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 57303 [IN]Prepared secure message 0x2002bea0 to 0xFFFFFFFB00000000 (1) of type 0x9 and protocolId (0, 1) on exchange 30957r with MessageCounter:163334070. I: 57318 [IN]Sending encrypted msg 0x2002bea0 with MessageCounter:163334070 to 0xFFFFFFFB00000000 (1) at monotonic time: 000000000000DFE5 msec D: 57331 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 57338 [DMG]Command handler moving to [CommandSen] D: 57343 [DMG]Command handler moving to [AwaitingDe] E: 57348 [DL]Long dispatch time: 119 ms, for event type 16388 D: 57410 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 57417 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 57425 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:104985073 on exchange 30958r D: 57435 [EM]Handling via exchange: 30958r, Delegate: 0x2000cd94 D: 57441 [IM]Received Read request D: 57445 [DMG]IM RH moving to [GeneratingReports] D: 57449 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 57458 [DMG] Cluster 31, Attribute 3 is dirty D: 57463 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_0003 (expanded=0) D: 57472 [DMG] Sending report (payload has 36 bytes)... I: 57478 [IN]Prepared secure message 0x2002bfd8 to 0xFFFFFFFB00000000 (1) of type 0x5 and protocolId (0, 1) on exchange 30958r with MessageCounter:163334071. I: 57493 [IN]Sending encrypted msg 0x2002bfd8 with MessageCounter:163334071 to 0xFFFFFFFB00000000 (1) at monotonic time: 000000000000E094 msec D: 57506 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 57513 [DMG] OnReportConfirm: NumReports = 0 D: 57518 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 57525 [DMG]IM RH moving to [AwaitingDestruction] D: 57530 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 57589 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 57597 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 57605 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:104985074 on exchange 30959r D: 57615 [EM]Handling via exchange: 30959r, Delegate: 0x2000cd94 D: 57621 [DMG]Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0006 D: 57645 [DMG]Decreasing reference count for CommandHandler, remaining 1 D: 57651 [DL]OpenThread State Changed (Flags: 0x1017c100) D: 57656 [DL] Network Name: NEST-PAN-BFD8 D: 57663 [DL] PAN Id: 0xBFD8 D: 57666 [DL] Extended PAN Id: 0x4311AB3B79DBEA79 D: 57671 [DL] Channel: 22 D: 57673 [DL] Mesh Prefix: fd4f:2727:5e06::/64 D: 57681 [DL]OpenThread State Changed (Flags: 0x1100101d) D: 57686 [DL] Device Role: DETACHED D: 57689 [DL] Thread Unicast Addresses: D: 57693 [DL] fd4f:2727:5e06:0:d3c:22d:9517:fc25/64 valid D: 57699 [DL] fe80::fc0b:a145:8979:9a48/64 valid preferred I: 58597 [DL]SRP Client was started, detected server: fd4f:2727:5e06:0000:473a:1d06:8def:f7c5 D: 58606 [DL]OpenThread State Changed (Flags: 0x200002a4) D: 58777 [DL] Device Role: CHILD D: 58782 [DL] Partition Id: 0xA95283D E: 58824 [DL]Long dispatch time: 218 ms, for event type 32777 D: 58831 [DL]OpenThread State Changed (Flags: 0x00000001) D: 58838 [DL] Thread Unicast Addresses: D: 58842 [DL] fdb1:dd08:5b78:1:8324:856c:a6e:e109/64 valid preferred D: 58849 [DL] fd4f:2727:5e06::ff:fe00:ac01/64 valid rloc D: 58856 [DL] fd4f:2727:5e06:0:d3c:22d:9517:fc25/64 valid D: 58862 [DL] fe80::fc0b:a145:8979:9a48/64 valid preferred D: 58870 [DMG]Command handler moving to [ Preparing] D: 58876 [DMG]Command handler moving to [AddingComm] D: 58881 [DMG]Command handler moving to [AddedComma] D: 58886 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to bdff0cdf D: 58893 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 58901 [IN]Prepared secure message 0x2002c090 to 0xFFFFFFFB00000000 (1) of type 0x9 and protocolId (0, 1) on exchange 30959r with MessageCounter:163334072. I: 58916 [IN]Sending encrypted msg 0x2002c090 with MessageCounter:163334072 to 0xFFFFFFFB00000000 (1) at monotonic time: 000000000000E623 msec D: 58928 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 70) D: 58937 [DMG]Command handler moving to [CommandSen] D: 58942 [DMG]Command handler moving to [AwaitingDe] D: 58948 [DL]Using Thread extended MAC for hostname. I: 58953 [DIS]Advertise operational node 3199E9CFDD25901B-00000000E950E4F5 I: 58960 [SVR]Operational advertising enabled D: 58984 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 59182 [DL]SRP update succeeded I: 59185 [DIS]Setting operational delegate post init I: 59195 [SWU]Stopping the watchdog timer I: 59199 [SWU]Starting the periodic query timer, timeout: 86400 seconds I: 59205 [DIS]Updating services using commissioning mode 0 D: 59211 [DL]Using Thread extended MAC for hostname. I: 59215 [DIS]Advertise operational node 3199E9CFDD25901B-00000000E950E4F5 I: 59222 [DL]advertising srp service: 3199E9CFDD25901B-00000000E950E4F5._matter._tcp D: 59230 [DL]Using Thread extended MAC for hostname. I: 59236 [DIS]Advertise commission parameter vendorID=65521 productID=32772 discriminator=4003/15 cm=0 I: 59282 [DL]advertising srp service: 19A22F437C25E7D5._matterc._udp D: 59289 [DMG]Endpoint 0, Cluster 0x0000_002A update version to 82e3b1d D: 59296 [DMG]Endpoint 0, Cluster 0x0000_002A update version to 82e3b1e D: 59951 [DL]SRP update succeeded I: 59974 [DL]BLE GAP connection terminated (reason 0x13) I: 59980 [DL]Current number of connections: 0/1 E: 73938 [BLE]ack recv timeout, closing ep 0x2000f3c8 D: 73942 [IN]Clearing BLE pending packets. I: 73946 [BLE]Releasing end point's BLE connection back to application. I: 73953 [DL]Closing BLE GATT connection (ConnId 00) I: 77290 [EM]Received message of type 0x30 with protocolId (0, 0) and MessageCounter:140944388 on exchange 30960r D: 77300 [EM]Handling via exchange: 30960r, Delegate: 0x200041d0 I: 77306 [IN]CASE Server received Sigma1 message. Starting handshake. EC 0x20004ee0 I: 77314 [IN]CASE Server disabling CASE session setups D: 77319 [EM]Sending Standalone Ack for MessageCounter:140944388 on exchange 30960r I: 77326 [IN]Prepared unauthenticated message 0x2002bd60 to 0x0000000000000000 (0) of type 0x10 and protocolId (0, 0) on exchange 30960r with MessageCounter:245520776. I: 77341 [IN]Sending unauthenticated msg 0x2002bd60 with MessageCounter:245520776 to 0x0000000000000000 at monotonic time: 0000000000012E1D msec D: 77355 [EM]Flushed pending ack for MessageCounter:140944388 on exchange 30960r I: 77363 [SC]Received Sigma1 msg D: 77366 [SC]Found MRP parameters in the message D: 77371 [SC]Peer assigned session key ID 37449 I: 77379 [SC]CASE matched destination ID: fabricIndex 1, NodeID 0x00000000E950E4F5 D: 77608 [SC]Including MRP parameters I: 77612 [IN]Prepared unauthenticated message 0x20005194 to 0x0000000000000000 (0) of type 0x31 and protocolId (0, 0) on exchange 30960r with MessageCounter:245520777. I: 77627 [IN]Sending unauthenticated msg 0x20005194 with MessageCounter:245520777 to 0x0000000000000000 at monotonic time: 0000000000012F3B msec I: 77642 [DL]OpenThread SED interval set to 200ms I: 77646 [SC]Sent Sigma2 msg D: 78199 [EM]Retransmitting MessageCounter:245520777 on exchange 30960r Send Cnt 1 I: 78207 [IN]Sending unauthenticated msg 0x20005194 with MessageCounter:245520777 to 0x0000000000000000 at monotonic time: 000000000001317F msec D: 78221 [CSM]UpdatePeerAddress: No existing OperationalSessionSetup instance found D: 78229 [CTL]OperationalSessionSetup[0:1E351A928F88777C]: State change 1 --> 2 E: 78237 [CTL]PerformAddressUpdate could not perform lookup I: 78667 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:140944389 on exchange 30960r D: 78677 [EM]Found matching exchange: 30960r, Delegate: 0x200041ec D: 78684 [EM]Rxd Ack; Removing MessageCounter:245520777 from Retrans Table on exchange 30960r D: 78693 [EM]Removed CHIP MessageCounter:245520777 from RetransTable on exchange 30960r I: 78912 [EM]Received message of type 0x32 with protocolId (0, 0) and MessageCounter:140944390 on exchange 30960r D: 78922 [EM]Found matching exchange: 30960r, Delegate: 0x200041ec D: 78929 [EM]CHIP MessageCounter:245520777 not in RetransTable on exchange 30960r D: 78937 [EM]Sending Standalone Ack for MessageCounter:140944390 on exchange 30960r I: 78949 [IN]Prepared unauthenticated message 0x2002bd48 to 0x0000000000000000 (0) of type 0x10 and protocolId (0, 0) on exchange 30960r with MessageCounter:245520778. I: 78964 [IN]Sending unauthenticated msg 0x2002bd48 with MessageCounter:245520778 to 0x0000000000000000 at monotonic time: 0000000000013474 msec D: 78978 [EM]Flushed pending ack for MessageCounter:140944390 on exchange 30960r I: 78985 [SC]Received Sigma3 msg E: 78995 [SC]The device does not support GetClock_RealTimeMS() API: 3. Falling back to Last Known Good UTC Time D: 79202 [SC]Sending status report. Protocol code 0, exchange 30960 I: 79208 [IN]Prepared unauthenticated message 0x20005194 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 30960r with MessageCounter:245520779. I: 79223 [IN]Sending unauthenticated msg 0x20005194 with MessageCounter:245520779 to 0x0000000000000000 at monotonic time: 0000000000013577 msec I: 79239 [SC]SecureSession[0x20003560]: Moving from state 'kEstablishing' --> 'kActive' D: 79247 [IN]SecureSession[0x20003560]: Activated - Type:2 LSID:28613 D: 79254 [IN]New secure session activated for device <0000000018EB5475, 1>, LSID:28613 PSID:37449! I: 79262 [IN]CASE Session established to peer: <0000000018EB5475, 1> I: 79268 [IN]CASE Server enabling CASE session setups D: 79274 [IN]SecureSession[0x200036d0]: Allocated Type:2 LSID:28615 D: 79280 [SC]Allocated SecureSession (0x200036d0) - waiting for Sigma1 msg I: 79287 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:140944391 on exchange 30960r D: 79297 [EM]Found matching exchange: 30960r, Delegate: (nil) D: 79302 [EM]CHIP MessageCounter:245520777 not in RetransTable on exchange 30960r I: 79329 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:140944392 on exchange 30960r D: 79339 [EM]Found matching exchange: 30960r, Delegate: (nil) D: 79346 [EM]Rxd Ack; Removing MessageCounter:245520779 from Retrans Table on exchange 30960r D: 79354 [EM]Removed CHIP MessageCounter:245520779 from RetransTable on exchange 30960r I: 79362 [DL]OpenThread SED interval set to 1000ms I: 79383 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:237547857 on exchange 30961r D: 79393 [EM]Handling via exchange: 30961r, Delegate: 0x2000cd94 D: 79399 [IM]Received Read request D: 79403 [DMG]IM RH moving to [GeneratingReports] I: 79407 [DL]OpenThread SED interval set to 200ms D: 79412 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 79420 [DMG] Cluster 3c, Attribute 0 is dirty D: 79425 [DMG]Reading attribute: Cluster=0x0000_003C Endpoint=0 AttributeId=0x0000_0000 (expanded=0) D: 79434 [DMG] Sending report (payload has 36 bytes)... I: 79441 [IN]Prepared secure message 0x20005194 to 0x0000000018EB5475 (1) of type 0x5 and protocolId (0, 1) on exchange 30961r with MessageCounter:26282465. I: 79455 [IN]Sending encrypted msg 0x20005194 with MessageCounter:26282465 to 0x0000000018EB5475 (1) at monotonic time: 000000000001365E msec D: 79468 [DMG] OnReportConfirm: NumReports = 0 D: 79473 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 79481 [DMG]IM RH moving to [AwaitingDestruction] D: 79486 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 79949 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:237547858 on exchange 30961r D: 79961 [EM]Found matching exchange: 30961r, Delegate: (nil) D: 79966 [EM]Rxd Ack; Removing MessageCounter:26282465 from Retrans Table on exchange 30961r D: 79975 [EM]Removed CHIP MessageCounter:26282465 from RetransTable on exchange 30961r I: 79982 [DL]OpenThread SED interval set to 1000ms I: 79988 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:237547859 on exchange 30962r D: 79998 [EM]Handling via exchange: 30962r, Delegate: 0x2000cd94 D: 80004 [IM]Received Read request D: 80007 [DMG]IM RH moving to [GeneratingReports] I: 80012 [DL]OpenThread SED interval set to 200ms D: 80017 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 80025 [DMG] Cluster 1d, Attribute 3 is dirty D: 80030 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0003 (expanded=0) D: 80039 [DMG] Sending report (payload has 64 bytes)... I: 80045 [IN]Prepared secure message 0x20005194 to 0x0000000018EB5475 (1) of type 0x5 and protocolId (0, 1) on exchange 30962r with MessageCounter:26282466. I: 80059 [IN]Sending encrypted msg 0x20005194 with MessageCounter:26282466 to 0x0000000018EB5475 (1) at monotonic time: 00000000000138BB msec D: 80073 [DMG] OnReportConfirm: NumReports = 0 D: 80078 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 80086 [DMG]IM RH moving to [AwaitingDestruction] D: 80091 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 80301 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:237547860 on exchange 30962r D: 80311 [EM]Found matching exchange: 30962r, Delegate: (nil) D: 80319 [EM]Rxd Ack; Removing MessageCounter:26282466 from Retrans Table on exchange 30962r D: 80327 [EM]Removed CHIP MessageCounter:26282466 from RetransTable on exchange 30962r I: 80334 [DL]OpenThread SED interval set to 1000ms I: 80340 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:237547861 on exchange 30963r D: 80350 [EM]Handling via exchange: 30963r, Delegate: 0x2000cd94 D: 80356 [IM]Received Read request D: 80359 [DMG]IM RH moving to [GeneratingReports] I: 80364 [DL]OpenThread SED interval set to 200ms D: 80369 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 80377 [DMG] Cluster 1d, Attribute 0 is dirty D: 80382 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0000 (expanded=0) D: 80391 [DMG] Sending report (payload has 70 bytes)... I: 80398 [IN]Prepared secure message 0x20005194 to 0x0000000018EB5475 (1) of type 0x5 and protocolId (0, 1) on exchange 30963r with MessageCounter:26282467. I: 80412 [IN]Sending encrypted msg 0x20005194 with MessageCounter:26282467 to 0x0000000018EB5475 (1) at monotonic time: 0000000000013A1B msec D: 80426 [DMG] OnReportConfirm: NumReports = 0 D: 80431 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 80439 [DMG]IM RH moving to [AwaitingDestruction] D: 80443 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 80676 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:237547862 on exchange 30963r D: 80687 [EM]Found matching exchange: 30963r, Delegate: (nil) D: 80693 [EM]Rxd Ack; Removing MessageCounter:26282467 from Retrans Table on exchange 30963r D: 80701 [EM]Removed CHIP MessageCounter:26282467 from RetransTable on exchange 30963r I: 80709 [DL]OpenThread SED interval set to 1000ms I: 80770 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:237547863 on exchange 30964r D: 80780 [EM]Handling via exchange: 30964r, Delegate: 0x2000cd94 D: 80785 [IM]Received Read request D: 80789 [DMG]IM RH moving to [GeneratingReports] I: 80794 [DL]OpenThread SED interval set to 200ms D: 80798 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 80807 [DMG] Cluster 1d, Attribute 1 is dirty D: 80812 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0001 (expanded=0) D: 80822 [DMG] Sending report (payload has 512 bytes)... I: 80830 [IN]Prepared secure message 0x20005194 to 0x0000000018EB5475 (1) of type 0x5 and protocolId (0, 1) on exchange 30964r with MessageCounter:26282468. I: 80844 [IN]Sending encrypted msg 0x20005194 with MessageCounter:26282468 to 0x0000000018EB5475 (1) at monotonic time: 0000000000013BCC msec D: 80858 [DMG] OnReportConfirm: NumReports = 0 D: 80863 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 80871 [DMG]IM RH moving to [AwaitingDestruction] D: 80876 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 81159 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:237547864 on exchange 30964r D: 81170 [EM]Found matching exchange: 30964r, Delegate: (nil) D: 81176 [EM]Rxd Ack; Removing MessageCounter:26282468 from Retrans Table on exchange 30964r D: 81186 [EM]Removed CHIP MessageCounter:26282468 from RetransTable on exchange 30964r I: 81193 [DL]OpenThread SED interval set to 1000ms I: 81199 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:237547865 on exchange 30965r D: 81209 [EM]Handling via exchange: 30965r, Delegate: 0x2000cd94 D: 81215 [IM]Received Read request D: 81218 [DMG]IM RH moving to [GeneratingReports] I: 81223 [DL]OpenThread SED interval set to 200ms D: 81228 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 81236 [DMG] Cluster 1d, Attribute 2 is dirty D: 81241 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0002 (expanded=0) D: 81250 [DMG] Sending report (payload has 64 bytes)... I: 81256 [IN]Prepared secure message 0x20005194 to 0x0000000018EB5475 (1) of type 0x5 and protocolId (0, 1) on exchange 30965r with MessageCounter:26282469. I: 81271 [IN]Sending encrypted msg 0x20005194 with MessageCounter:26282469 to 0x0000000018EB5475 (1) at monotonic time: 0000000000013D76 msec D: 81285 [DMG] OnReportConfirm: NumReports = 0 D: 81289 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 81297 [DMG]IM RH moving to [AwaitingDestruction] D: 81302 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 81582 [IN]Received a duplicate message with MessageCounter:237547865 on exchange 30965r I: 81590 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:237547865 on exchange 30965r D: 81600 [EM]Found matching exchange: 30965r, Delegate: (nil) D: 81605 [EM]Forcing tx of solitary ack for duplicate MessageCounter:237547865 on exchange 30965r D: 81614 [EM]Sending Standalone Ack for MessageCounter:237547865 on exchange 30965r I: 81622 [IN]Prepared secure message 0x2002bd58 to 0x0000000018EB5475 (1) of type 0x10 and protocolId (0, 0) on exchange 30965r with MessageCounter:26282470. I: 81636 [IN]Sending encrypted msg 0x2002bd58 with MessageCounter:26282470 to 0x0000000018EB5475 (1) at monotonic time: 0000000000013EE4 msec I: 81670 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:237547866 on exchange 30965r D: 81680 [EM]Found matching exchange: 30965r, Delegate: (nil) D: 81686 [EM]Rxd Ack; Removing MessageCounter:26282469 from Retrans Table on exchange 30965r D: 81696 [EM]Removed CHIP MessageCounter:26282469 from RetransTable on exchange 30965r I: 81704 [DL]OpenThread SED interval set to 1000ms I: 81710 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:237547867 on exchange 30966r D: 81720 [EM]Handling via exchange: 30966r, Delegate: 0x2000cd94 D: 81725 [IM]Received Read request D: 81729 [DMG]IM RH moving to [GeneratingReports] I: 81734 [DL]OpenThread SED interval set to 200ms D: 81738 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 81747 [DMG] Cluster 1d, Attribute 3 is dirty D: 81752 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=1 AttributeId=0x0000_0003 (expanded=0) D: 81761 [DMG] Sending report (payload has 36 bytes)... I: 81767 [IN]Prepared secure message 0x20005194 to 0x0000000018EB5475 (1) of type 0x5 and protocolId (0, 1) on exchange 30966r with MessageCounter:26282471. I: 81781 [IN]Sending encrypted msg 0x20005194 with MessageCounter:26282471 to 0x0000000018EB5475 (1) at monotonic time: 0000000000013F75 msec D: 81795 [DMG] OnReportConfirm: NumReports = 0 D: 81800 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 81808 [DMG]IM RH moving to [AwaitingDestruction] D: 81813 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 82405 [EM]Retransmitting MessageCounter:26282471 on exchange 30966r Send Cnt 1 I: 82413 [IN]Sending encrypted msg 0x20005194 with MessageCounter:26282471 to 0x0000000018EB5475 (1) at monotonic time: 00000000000141ED msec D: 82427 [CSM]UpdatePeerAddress: No existing OperationalSessionSetup instance found D: 82434 [CTL]OperationalSessionSetup[1:0000000018EB5475]: State change 1 --> 2 I: 82442 [DIS]Resolving 3199E9CFDD25901B:0000000018EB5475 ... I: 82553 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:237547868 on exchange 30966r D: 82564 [EM]Found matching exchange: 30966r, Delegate: (nil) D: 82570 [EM]Rxd Ack; Removing MessageCounter:26282471 from Retrans Table on exchange 30966r D: 82578 [EM]Removed CHIP MessageCounter:26282471 from RetransTable on exchange 30966r I: 82587 [DL]OpenThread SED interval set to 1000ms I: 82621 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:237547869 on exchange 30967r D: 82631 [EM]Handling via exchange: 30967r, Delegate: 0x2000cd94 D: 82637 [IM]Received Read request D: 82642 [DMG]IM RH moving to [GeneratingReports] I: 82647 [DL]OpenThread SED interval set to 200ms I: 82652 [DIS]Checking node lookup status after 211 ms D: 82658 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 82666 [DMG] Cluster 1d, Attribute 0 is dirty D: 82672 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=1 AttributeId=0x0000_0000 (expanded=0) D: 82681 [DMG] Sending report (payload has 71 bytes)... I: 82688 [IN]Prepared secure message 0x20005194 to 0x0000000018EB5475 (1) of type 0x5 and protocolId (0, 1) on exchange 30967r with MessageCounter:26282472. I: 82703 [IN]Sending encrypted msg 0x20005194 with MessageCounter:26282472 to 0x0000000018EB5475 (1) at monotonic time: 000000000001430E msec D: 82716 [DMG] OnReportConfirm: NumReports = 0 D: 82721 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 82729 [DMG]IM RH moving to [AwaitingDestruction] D: 82734 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 82753 [IN]Received a duplicate message with MessageCounter:237547869 on exchange 30967r I: 82762 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:237547869 on exchange 30967r D: 82773 [EM]Found matching exchange: 30967r, Delegate: (nil) D: 82779 [EM]Forcing tx of solitary ack for duplicate MessageCounter:237547869 on exchange 30967r D: 82787 [EM]Sending Standalone Ack for MessageCounter:237547869 on exchange 30967r I: 82797 [IN]Prepared secure message 0x2002bd58 to 0x0000000018EB5475 (1) of type 0x10 and protocolId (0, 0) on exchange 30967r with MessageCounter:26282473. I: 82812 [IN]Sending encrypted msg 0x2002bd58 with MessageCounter:26282473 to 0x0000000018EB5475 (1) at monotonic time: 000000000001437B msec D: 83274 [EM]Retransmitting MessageCounter:26282472 on exchange 30967r Send Cnt 1 I: 83282 [IN]Sending encrypted msg 0x20005194 with MessageCounter:26282472 to 0x0000000018EB5475 (1) at monotonic time: 0000000000014552 msec I: 83461 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:237547870 on exchange 30966r I: 83483 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:237547871 on exchange 30967r D: 83493 [EM]Found matching exchange: 30967r, Delegate: (nil) D: 83500 [EM]Rxd Ack; Removing MessageCounter:26282472 from Retrans Table on exchange 30967r D: 83508 [EM]Removed CHIP MessageCounter:26282472 from RetransTable on exchange 30967r I: 83517 [DL]OpenThread SED interval set to 1000ms I: 83545 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:237547872 on exchange 30968r D: 83555 [EM]Handling via exchange: 30968r, Delegate: 0x2000cd94 D: 83561 [IM]Received Read request D: 83565 [DMG]IM RH moving to [GeneratingReports] I: 83569 [DL]OpenThread SED interval set to 200ms D: 83574 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 83582 [DMG] Cluster 1d, Attribute 1 is dirty D: 83587 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=1 AttributeId=0x0000_0001 (expanded=0) D: 83597 [DMG] Sending report (payload has 148 bytes)... I: 83603 [IN]Prepared secure message 0x20005194 to 0x0000000018EB5475 (1) of type 0x5 and protocolId (0, 1) on exchange 30968r with MessageCounter:26282474. I: 83617 [IN]Sending encrypted msg 0x20005194 with MessageCounter:26282474 to 0x0000000018EB5475 (1) at monotonic time: 00000000000146A1 msec D: 83631 [DMG] OnReportConfirm: NumReports = 0 D: 83636 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 83644 [DMG]IM RH moving to [AwaitingDestruction] D: 83649 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 83718 [IN]Received a duplicate message with MessageCounter:237547872 on exchange 30968r I: 83727 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:237547872 on exchange 30968r D: 83737 [EM]Found matching exchange: 30968r, Delegate: (nil) D: 83743 [EM]Forcing tx of solitary ack for duplicate MessageCounter:237547872 on exchange 30968r D: 83752 [EM]Sending Standalone Ack for MessageCounter:237547872 on exchange 30968r I: 83762 [IN]Prepared secure message 0x2002bd58 to 0x0000000018EB5475 (1) of type 0x10 and protocolId (0, 0) on exchange 30968r with MessageCounter:26282475. I: 83776 [IN]Sending encrypted msg 0x2002bd58 with MessageCounter:26282475 to 0x0000000018EB5475 (1) at monotonic time: 0000000000014740 msec I: 83791 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:237547873 on exchange 30967r I: 83917 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:237547874 on exchange 30968r D: 83928 [EM]Found matching exchange: 30968r, Delegate: (nil) D: 83933 [EM]Rxd Ack; Removing MessageCounter:26282474 from Retrans Table on exchange 30968r D: 83943 [EM]Removed CHIP MessageCounter:26282474 from RetransTable on exchange 30968r I: 83950 [DL]OpenThread SED interval set to 1000ms I: 83981 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:237547875 on exchange 30969r D: 83991 [EM]Handling via exchange: 30969r, Delegate: 0x2000cd94 D: 83997 [IM]Received Read request D: 84001 [DMG]IM RH moving to [GeneratingReports] I: 84005 [DL]OpenThread SED interval set to 200ms D: 84010 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 84019 [DMG] Cluster 1d, Attribute 2 is dirty D: 84024 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=1 AttributeId=0x0000_0002 (expanded=0) D: 84033 [DMG] Sending report (payload has 149 bytes)... I: 84040 [IN]Prepared secure message 0x20005194 to 0x0000000018EB5475 (1) of type 0x5 and protocolId (0, 1) on exchange 30969r with MessageCounter:26282476. I: 84054 [IN]Sending encrypted msg 0x20005194 with MessageCounter:26282476 to 0x0000000018EB5475 (1) at monotonic time: 0000000000014855 msec D: 84068 [DMG] OnReportConfirm: NumReports = 0 D: 84072 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 84080 [DMG]IM RH moving to [AwaitingDestruction] D: 84085 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 84638 [EM]Retransmitting MessageCounter:26282476 on exchange 30969r Send Cnt 1 I: 84645 [IN]Sending encrypted msg 0x20005194 with MessageCounter:26282476 to 0x0000000018EB5475 (1) at monotonic time: 0000000000014AA5 msec D: 84790 [IN]Received a duplicate message with MessageCounter:237547875 on exchange 30969r I: 84798 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:237547875 on exchange 30969r D: 84809 [EM]Found matching exchange: 30969r, Delegate: (nil) D: 84815 [EM]Forcing tx of solitary ack for duplicate MessageCounter:237547875 on exchange 30969r D: 84824 [EM]Sending Standalone Ack for MessageCounter:237547875 on exchange 30969r I: 84832 [IN]Prepared secure message 0x2002bd58 to 0x0000000018EB5475 (1) of type 0x10 and protocolId (0, 0) on exchange 30969r with MessageCounter:26282477. I: 84848 [IN]Sending encrypted msg 0x2002bd58 with MessageCounter:26282477 to 0x0000000018EB5475 (1) at monotonic time: 0000000000014B70 msec I: 84862 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:237547876 on exchange 30969r D: 84873 [EM]Found matching exchange: 30969r, Delegate: (nil) D: 84879 [EM]Rxd Ack; Removing MessageCounter:26282476 from Retrans Table on exchange 30969r D: 84887 [EM]Removed CHIP MessageCounter:26282476 from RetransTable on exchange 30969r I: 84896 [DL]OpenThread SED interval set to 1000ms I: 85824 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:237547877 on exchange 30969r I: 97441 [DIS]Checking node lookup status after 15000 ms E: 97447 [DIS]OperationalSessionSetup[1:0000000018EB5475]: operational discovery failed: 32 uart:~$ I: 170677 [FS]Fail-safe timer expired E: 170680 [SVR]Failsafe timer expired D: 170684 [IN]SecureSession[0x20003618]: MarkForEviction Type:1 LSID:28614 I: 170690 [SC]SecureSession[0x20003618]: Moving from state 'kActive' --> 'kPendingEviction' D: 170699 [IN]SecureSession[0x20003618]: Released - Type:1 LSID:28614 E: 170705 [SVR]Commissioning failed (attempt 1): 32 D: 170713 [IN]SecureSession[0x20003618]: Allocated Type:1 LSID:28616 D: 170719 [SC]Assigned local session key ID 28616 D: 170723 [SC]Waiting for PBKDF param request D: 170727 [DL]CHIPoBLE advertising set to on I: 170731 [DIS]Updating services using commissioning mode 1 D: 170737 [DL]Using Thread extended MAC for hostname. I: 170742 [DIS]Advertise operational node 3199E9CFDD25901B-00000000E950E4F5 D: 170749 [DL]Using Thread extended MAC for hostname. I: 170755 [DIS]Advertise commission parameter vendorID=65521 productID=32772 discriminator=4003/15 cm=1 I: 170764 [DL]advertising srp service: 19A22F437C25E7D5._matterc._udp E: 170771 [ZCL]OpCreds: Got FailSafeTimerExpired E: 170775 [ZCL]OpCreds: Proceeding to FailSafeCleanup on fail-safe expiry! D: 170818 [IN]Expiring all sessions for fabric 0x1!! D: 170823 [IN]SecureSession[0x20003560]: MarkForEviction Type:2 LSID:28613 I: 170831 [SC]SecureSession[0x20003560]: Moving from state 'kActive' --> 'kPendingEviction' D: 170839 [IN]SecureSession[0x20003560]: Released - Type:2 LSID:28613 E: 170846 [FP]Reverting pending fabric data for fabric 0x1 D: 170852 [EVL]LogEvent event number: 0x0000000000000003 priority: 1, endpoint id: 0x0 cluster id: 0x0000_0028 event id: 0x2 Sys timestamp: 0x0000000000029B63 D: 170866 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet E: 170874 [FP]Warning: metadata not found during delete of fabric 0x1 I: 170911 [FP]Fabric (0x1) deleted. I: 170914 [ZCL]UserLabel: Last Fabric index 0x1 was removed I: 170920 [ZCL]OpCreds: Fabric index 0x1 was removed D: 170925 [DMG]Endpoint 0, Cluster 0x0000_003E update version to c613994e D: 170932 [DMG]Endpoint 0, Cluster 0x0000_003E update version to c613994f I: 170969 [TS]Pending Last Known Good Time: 2022-10-19T14:09:14 I: 170975 [TS]Previous Last Known Good Time: 2022-10-19T14:09:14 I: 170981 [TS]Reverted Last Known Good Time to previous value D: 170987 [EVL]LogEvent event number: 0x0000000000000004 priority: 1, endpoint id: 0x0 cluster id: 0x0000_0028 event id: 0x2 Sys timestamp: 0x0000000000029BEA D: 171001 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet E: 171008 [FP]Warning: metadata not found during delete of fabric 0x1 E: 171018 [ZCL]OpCreds: failed to delete fabric at index 1: d8 D: 171024 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to bdff0ce0 D: 171031 [ZCL]Failsafe timeout, tell platform driver to revert network credentials. I: 171039 [NP]Reverting Thread operational dataset D: 171045 [DL]SRP update succeeded E: 171059 [DL]Long dispatch time: 379 ms, for event type 32782 I: 171065 [FS]Fail-safe cleanly disarmed I: 171071 [DL]CHIPoBLE advertising started D: 171075 [DL]OpenThread State Changed (Flags: 0x11002046) D: 171080 [DL] Device Role: DISABLED D: 171084 [DL] Thread Unicast Addresses: D: 171088 [DL] fdb1:dd08:5b78:1:8324:856c:a6e:e109/64 valid preferred D: 171096 [DL]OpenThread State Changed (Flags: 0x10000000) I: 171104 [DL]NFC Tag emulation started I: 201075 [DL]CHIPoBLE advertising mode changed to slow