I: nRF5 802154 radio initialized I: 4 Sectors of 4096 bytes I: alloc wra: 0, f00 I: data wra: 0, d0 ooting Zephyr OS build v3.2.99-ncs1 *** I: Init CHIP stack 32muart:~$ : 222 [DL]BLE address: CD:DB:8D:84:48:6A mI: SoftDevice Controller build revision: I: 6d 90 41 2a 38 e8 ad 17 |m.A*8... I: 29 a5 03 38 39 27 d7 85 |)..89'.. I: 1f 85 d8 e1 |.... I: 246 [DL]OpenThread started: OK I: 249 [DL]Setting OpenThread device type to ROUTER I: 254 [SVR]Server initializing... D: 257 [FP]Initializing FabricTable from persistent storage I: 262 [TS]Last Known Good Time: 2023-01-25T11:24:03 I: 268 [DMG]AccessControl: initializing I: 271 [DMG]Examples::AccessControlDelegate::Init I: 276 [DMG]AccessControl: setting I: 279 [DMG]DefaultAclStorage: initializing I: 283 [DMG]DefaultAclStorage: 0 entries loaded D: 287 [IN]UDP::Init bind&listen port=5540 E: 291 [IN]SO_REUSEPORT failed: 109 D: 294 [IN]UDP::Init bound to port=5540 D: 298 [IN]BLEBase::Init - setting/overriding transport D: 302 [IN]TransportMgr initialized D: 309 [DL]Using Thread extended MAC for hostname. I: 315 [ZCL]Using ZAP configuration... D: 319 [DMG]Failed to read stored attribute (0, 0x0000_0028, 0x0000_0005: a0 D: 327 [DMG]Failed to read stored attribute (1, 0x0000_0006, 0x0000_4003: a0 D: 335 [DMG]Failed to read stored attribute (1, 0x0000_0008, 0x0000_4000: a0 I: 341 [DMG]AccessControlCluster: initializing D: 346 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 22934b50 D: 352 [DL]Boot reason: 1 D: 354 [ZCL]GeneralDiagnostics: OnDeviceReboot D: 359 [DMG]Endpoint 0, Cluster 0x0000_0033 update version to 58d01dac D: 365 [EVL]LogEvent event number: 0x0000000000020000 priority: 2, endpoint id: 0x0 cluster id: 0x0000_0033 event id: 0x3 Sys timestamp: 0x000000000000016D I: 379 [ZCL]Initiating Admin Commissioning cluster. D: 384 [DMG]Endpoint 1, Cluster 0x0000_0003 update version to 555a74a6 D: 390 [DMG]Endpoint 1, Cluster 0x0000_0004 update version to 7dcf6cd7 D: 396 [DMG]Endpoint 1, Cluster 0x0000_0004 update version to 7dcf6cd8 I: 403 [ZCL]On/Off set value: 1 0 I: 406 [ZCL]On/off already set to new value D: 410 [DMG]Endpoint 1, Cluster 0x0000_0008 update version to 23b72b98 I: 416 [ZCL]Cluster LevelControl: attribute CurrentLevel set to 254 D: 422 [ZCL]LED is off. Try to use move-to-level-with-on-off instead of move-to-level D: 431 [IN]SecureSession[0x20003650]: Allocated Type:1 LSID:22351 D: 437 [SC]Assigned local session key ID 22351 D: 441 [SC]Waiting for PBKDF param request D: 445 [DL]CHIPoBLE advertising set to on I: 449 [DIS]Updating services using commissioning mode 1 D: 454 [DL]Using Thread extended MAC for hostname. D: 459 [DL]Using Thread extended MAC for hostname. I: 463 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1 E: 473 [DIS]Failed to advertise commissionable node: 3 E: 477 [DIS]Failed to finalize service update: 1c I: 482 [DIS]Updating services using commissioning mode 1 D: 487 [DL]Using Thread extended MAC for hostname. D: 492 [DL]Using Thread extended MAC for hostname. I: 497 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1 E: 506 [DIS]Failed to advertise commissionable node: 3 E: 511 [DIS]Failed to finalize service update: 1c I: 515 [DIS]Delaying proxy of operational discovery: missing delegate I: 521 [IN]CASE Server enabling CASE session setups D: 526 [IN]SecureSession[0x20003708]: Allocated Type:2 LSID:22352 D: 532 [SC]Allocated SecureSession (0x20003708) - waiting for Sigma1 msg I: 538 [SVR]Joining Multicast groups D: 542 [ZCL]Emitting StartUp event D: 545 [EVL]LogEvent event number: 0x0000000000020001 priority: 2, endpoint id: 0x0 cluster id: 0x0000_0028 event id: 0x0 Sys timestamp: 0x0000000000000221 I: 559 [SVR]Server Listening... I: 562 [DL]Device Configuration: I: 565 [DL] Serial Number: 11223344556677889900 I: 569 [DL] Vendor Id: 65521 (0xFFF1) I: 573 [DL] Product Id: 32773 (0x8005) I: 576 [DL] Hardware Version: 0 I: 580 [DL] Setup Pin Code (0 for UNKNOWN/ERROR): 20202021 I: 585 [DL] Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00) I: 592 [DL] Manufacturing Date: (not set) I: 596 [DL] Device Type: 65535 (0xFFFF) I: 600 [SVR]SetupQRCode: [MT:6FCJ142C00KA0648G00] I: 604 [SVR]Copy/paste the below URL in a browser to see the QR Code: I: 611 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A6FCJ142C00KA0648G00 I: 620 [SVR]Manual pairing code: [34970112332] I: 625 [DL]CHIP task running I: 629 [DL]CHIPoBLE advertising started D: 633 [DMG]Endpoint 1, Cluster 0x0000_0006 update version to a42345de I: 640 [ZCL]Cluster OnOff: attribute OnOff set to 0 D: 644 [DMG]Endpoint 1, Cluster 0x0000_0008 update version to 23b72b99 I: 651 [ZCL]Cluster LevelControl: attribute CurrentLevel set to 254 D: 657 [ZCL]LED is off. Try to use move-to-level-with-on-off instead of move-to-level I: 665 [DL]NFC Tag emulation started I: 13477 [DL]BLE connection established (ConnId: 0x00) I: 13482 [DL]Current number of connections: 1/2 I: 13486 [DL]CHIPoBLE advertising stopped I: 13490 [DL]NFC Tag emulation stopped W: Ignoring data for unknown channel ID 0x003a D: 14426 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 14433 [BLE]local and remote recv window sizes = 5 I: 14437 [BLE]selected BTP version 4 I: 14441 [BLE]using BTP fragment sizes rx 244 / tx 244. D: 14546 [DL]ConnId: 0x00, New CCCD value: 0x0002 D: 14550 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 6) D: 14558 [IN]BLE EndPoint 0x20012270 Connection Complete I: 14563 [DL]CHIPoBLE connection established (ConnId: 0x00, GATT MTU: 247) D: 14605 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 14614 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 14621 [EM]>>> [E:16623r M:70809559] (U) Msg RX from 0:5189CC053F0F13BA [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest) D: 14633 [EM]Handling via exchange: 16623r, Delegate: 0x20005834 D: 14639 [SC]Received PBKDF param request D: 14643 [SC]Peer assigned session ID 64167 D: 14646 [SC]Found MRP parameters in the message D: 14651 [SC]Including MRP parameters in PBKDF param response I: 14657 [EM]<<< [E:16623r M:154641172] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:21 (SecureChannel:PBKDFParamResponse) I: 14669 [IN](U) Sending msg 154641172 to IP address 'BLE' D: 14674 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 140) D: 14682 [SC]Sent PBKDF param response D: 14725 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 14786 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 14793 [EM]>>> [E:16623r M:70809560] (U) Msg RX from 0:5189CC053F0F13BA [0000] --- Type 0000:22 (SecureChannel:PASE_Pake1) D: 14804 [EM]Found matching exchange: 16623r, Delegate: 0x20005834 D: 14810 [SC]Received spake2p msg1 I: 16746 [EM]<<< [E:16623r M:154641173] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:23 (SecureChannel:PASE_Pake2) I: 16757 [IN](U) Sending msg 154641173 to IP address 'BLE' D: 16762 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 132) D: 16770 [SC]Sent spake2p msg2 E: 16773 [DL]Long dispatch time: 1987 ms, for event type 16388 D: 16855 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 16886 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 16893 [EM]>>> [E:16623r M:70809561] (U) Msg RX from 0:5189CC053F0F13BA [0000] --- Type 0000:24 (SecureChannel:PASE_Pake3) D: 16904 [EM]Found matching exchange: 16623r, Delegate: 0x20005834 D: 16910 [SC]Received spake2p msg3 D: 16914 [SC]Sending status report. Protocol code 0, exchange 16623 I: 16920 [EM]<<< [E:16623r M:154641174] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport) I: 16931 [IN](U) Sending msg 154641174 to IP address 'BLE' D: 16937 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 35) I: 16945 [SC]SecureSession[0x20003650]: Moving from state 'kEstablishing' --> 'kActive' D: 16953 [IN]SecureSession[0x20003650]: Activated - Type:1 LSID:22351 D: 16960 [IN]New secure session activated for device , LSID:22351 PSID:64167! I: 16968 [SVR]Commissioning completed session establishment step I: 16974 [DIS]Updating services using commissioning mode 0 D: 16980 [DL]Using Thread extended MAC for hostname. D: 16985 [DL]Using Thread extended MAC for hostname. I: 16990 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=0 E: 17000 [DIS]Failed to advertise extended commissionable node: 3 D: 17006 [DIS]Scheduling extended discovery timeout in 900s E: 17011 [DIS]Failed to finalize service update: 1c D: 17016 [DL]CHIPoBLE advertising set to off I: 17020 [SVR]Device completed Rendezvous process E: 17024 [DL]Long dispatch time: 138 ms, for event type 16388 D: 17030 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 17038 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 17046 [EM]>>> [E:16624r M:110087012] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 17056 [EM]Handling via exchange: 16624r, Delegate: 0x2000fc3c D: 17062 [IM]Received Read request D: 17066 [DMG]IM RH moving to [GeneratingReports] D: 17070 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 17079 [DMG] Cluster 1d, Attribute 3 is dirty D: 17084 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0003 (expanded=0) D: 17093 [DMG] Sending report (payload has 64 bytes)... I: 17099 [EM]<<< [E:16624r M:118289807] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 17109 [IN](S) Sending msg 118289807 on secure session with LSID: 22351 D: 17116 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 99) D: 17123 [DMG] OnReportConfirm: NumReports = 0 D: 17128 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 17135 [DMG]IM RH moving to [AwaitingDestruction] D: 17140 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 17156 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 17164 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 17172 [EM]>>> [E:16625r M:110087013] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 17182 [EM]Handling via exchange: 16625r, Delegate: 0x2000fc3c D: 17188 [IM]Received Read request D: 17192 [DMG]IM RH moving to [GeneratingReports] D: 17196 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 17205 [DMG] Cluster 1d, Attribute 1 is dirty D: 17210 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0001 (expanded=0) D: 17220 [DMG] Sending report (payload has 400 bytes)... I: 17228 [EM]<<< [E:16625r M:118289808] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 17238 [IN](S) Sending msg 118289808 on secure session with LSID: 22351 D: 17244 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 17252 [DMG] OnReportConfirm: NumReports = 0 D: 17256 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 17264 [DMG]IM RH moving to [AwaitingDestruction] D: 17268 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 17305 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 17313 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 193) D: 17366 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 17374 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 17382 [EM]>>> [E:16626r M:110087014] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 17392 [EM]Handling via exchange: 16626r, Delegate: 0x2000fc3c D: 17398 [IM]Received Read request D: 17402 [DMG]IM RH moving to [GeneratingReports] D: 17406 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 17415 [DMG] Cluster 31, Attribute fffc is dirty D: 17420 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFC (expanded=0) D: 17430 [DMG] Sending report (payload has 37 bytes)... I: 17436 [EM]<<< [E:16626r M:118289809] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 17446 [IN](S) Sending msg 118289809 on secure session with LSID: 22351 D: 17452 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72) D: 17460 [DMG] OnReportConfirm: NumReports = 0 D: 17464 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 17472 [DMG]IM RH moving to [AwaitingDestruction] D: 17476 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 17516 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 17524 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 17532 [EM]>>> [E:16627r M:110087015] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 17542 [EM]Handling via exchange: 16627r, Delegate: 0x2000fc3c D: 17548 [IM]Received Read request D: 17552 [DMG]IM RH moving to [GeneratingReports] D: 17556 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 17565 [DMG] Cluster 1d, Attribute 3 is dirty D: 17570 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0003 (expanded=0) D: 17579 [DMG] Sending report (payload has 64 bytes)... I: 17586 [EM]<<< [E:16627r M:118289810] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 17596 [IN](S) Sending msg 118289810 on secure session with LSID: 22351 D: 17602 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 99) D: 17610 [DMG] OnReportConfirm: NumReports = 0 D: 17614 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 17622 [DMG]IM RH moving to [AwaitingDestruction] D: 17626 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 17696 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 17704 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 17712 [EM]>>> [E:16628r M:110087016] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 17722 [EM]Handling via exchange: 16628r, Delegate: 0x2000fc3c D: 17728 [IM]Received Read request D: 17732 [DMG]IM RH moving to [GeneratingReports] D: 17736 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 17745 [DMG] Cluster 1d, Attribute 1 is dirty D: 17750 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0001 (expanded=0) D: 17760 [DMG] Sending report (payload has 400 bytes)... I: 17768 [EM]<<< [E:16628r M:118289811] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 17778 [IN](S) Sending msg 118289811 on secure session with LSID: 22351 D: 17784 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 17792 [DMG] OnReportConfirm: NumReports = 0 D: 17796 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 17804 [DMG]IM RH moving to [AwaitingDestruction] D: 17808 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 17846 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 17853 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 193) D: 17906 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 17914 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 17922 [EM]>>> [E:16629r M:110087017] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 17932 [EM]Handling via exchange: 16629r, Delegate: 0x2000fc3c D: 17938 [IM]Received Read request D: 17942 [DMG]IM RH moving to [GeneratingReports] D: 17946 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 17955 [DMG] Cluster 31, Attribute fffc is dirty D: 17960 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFC (expanded=0) D: 17970 [DMG] Sending report (payload has 37 bytes)... I: 17976 [EM]<<< [E:16629r M:118289812] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 17986 [IN](S) Sending msg 118289812 on secure session with LSID: 22351 D: 17992 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72) D: 18000 [DMG] OnReportConfirm: NumReports = 0 D: 18004 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 18012 [DMG]IM RH moving to [AwaitingDestruction] D: 18016 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 18055 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 18064 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 18072 [EM]>>> [E:16630r M:110087018] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 18082 [EM]Handling via exchange: 16630r, Delegate: 0x2000fc3c D: 18088 [IM]Received Read request D: 18094 [DMG]IM RH moving to [GeneratingReports] D: 18099 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 18107 [DMG] Cluster 31, Attribute 3 is dirty D: 18112 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_0003 (expanded=1) D: 18122 [DMG] Cluster 28, Attribute 4 is dirty D: 18127 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0004 (expanded=0) D: 18136 [DMG] Cluster 28, Attribute 2 is dirty D: 18141 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0002 (expanded=0) D: 18150 [DMG] Cluster 30, Attribute 3 is dirty D: 18155 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0003 (expanded=0) D: 18164 [DMG] Cluster 30, Attribute 2 is dirty D: 18169 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0002 (expanded=0) D: 18178 [DMG] Cluster 30, Attribute 1 is dirty D: 18183 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0001 (expanded=0) D: 18192 [DMG] Cluster 30, Attribute 0 is dirty D: 18197 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0000 (expanded=0) D: 18206 [DMG] Cluster 31, Attribute fffc is dirty D: 18212 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFC (expanded=1) D: 18221 [DMG] Sending report (payload has 228 bytes)... I: 18228 [EM]<<< [E:16630r M:118289813] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 18238 [IN](S) Sending msg 118289813 on secure session with LSID: 22351 D: 18244 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 18252 [DMG] OnReportConfirm: NumReports = 0 D: 18257 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 18264 [DMG]IM RH moving to [AwaitingDestruction] D: 18269 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 18296 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 18303 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 21) D: 18356 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 18364 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 18372 [EM]>>> [E:16631r M:110087019] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) D: 18383 [EM]Handling via exchange: 16631r, Delegate: 0x2000fc3c D: 18389 [DMG]Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000 I: 18397 [FS]GeneralCommissioning: Received ArmFailSafe (60s) D: 18402 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 22934b51 D: 18409 [DMG]Command handler moving to [ Preparing] D: 18414 [DMG]Command handler moving to [AddingComm] D: 18419 [DMG]Command handler moving to [AddedComma] D: 18424 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 18431 [EM]<<< [E:16631r M:118289814] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 18442 [IN](S) Sending msg 118289814 on secure session with LSID: 22351 D: 18449 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 18456 [DMG]Command handler moving to [CommandSen] D: 18461 [DMG]Command handler moving to [AwaitingDe] E: 18465 [DL]Long dispatch time: 101 ms, for event type 16388 D: 18505 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 18514 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 18522 [EM]>>> [E:16632r M:110087020] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) D: 18533 [EM]Handling via exchange: 16632r, Delegate: 0x2000fc3c D: 18539 [DMG]Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0002 D: 18556 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 22934b52 D: 18563 [DMG]Command handler moving to [ Preparing] D: 18568 [DMG]Command handler moving to [AddingComm] D: 18573 [DMG]Command handler moving to [AddedComma] D: 18578 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 18585 [EM]<<< [E:16632r M:118289815] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 18596 [IN](S) Sending msg 118289815 on secure session with LSID: 22351 D: 18602 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 18610 [DMG]Command handler moving to [CommandSen] D: 18615 [DMG]Command handler moving to [AwaitingDe] E: 18619 [DL]Long dispatch time: 105 ms, for event type 16388 D: 18656 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 18664 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 18672 [EM]>>> [E:16633r M:110087021] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) D: 18683 [EM]Handling via exchange: 16633r, Delegate: 0x2000fc3c D: 18689 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 I: 18697 [ZCL]OpCreds: Certificate Chain request received for PAI D: 18703 [DMG]Command handler moving to [ Preparing] D: 18707 [DMG]Command handler moving to [AddingComm] D: 18712 [DMG]Command handler moving to [AddedComma] D: 18717 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 18726 [EM]<<< [E:16633r M:118289816] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 18737 [IN](S) Sending msg 118289816 on secure session with LSID: 22351 D: 18744 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 18752 [DMG]Command handler moving to [CommandSen] D: 18757 [DMG]Command handler moving to [AwaitingDe] D: 18835 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 18843 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 18956 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 18963 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 48) D: 19076 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 19084 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 19092 [EM]>>> [E:16634r M:110087022] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) D: 19103 [EM]Handling via exchange: 16634r, Delegate: 0x2000fc3c D: 19109 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 I: 19117 [ZCL]OpCreds: Certificate Chain request received for DAC D: 19122 [DMG]Command handler moving to [ Preparing] D: 19127 [DMG]Command handler moving to [AddingComm] D: 19132 [DMG]Command handler moving to [AddedComma] D: 19137 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 19146 [EM]<<< [E:16634r M:118289817] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 19157 [IN](S) Sending msg 118289817 on secure session with LSID: 22351 D: 19164 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 19171 [DMG]Command handler moving to [CommandSen] D: 19176 [DMG]Command handler moving to [AwaitingDe] D: 19256 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 19263 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 19376 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 19383 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 77) D: 19495 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 19504 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 19512 [EM]>>> [E:16635r M:110087023] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) D: 19523 [EM]Handling via exchange: 16635r, Delegate: 0x2000fc3c D: 19529 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0000 I: 19537 [ZCL]OpCreds: Received an AttestationRequest command I: 19573 [ZCL]OpCreds: AttestationRequest successful. D: 19578 [DMG]Command handler moving to [ Preparing] D: 19582 [DMG]Command handler moving to [AddingComm] D: 19587 [DMG]Command handler moving to [AddedComma] D: 19592 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 19602 [EM]<<< [E:16635r M:118289818] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 19613 [IN](S) Sending msg 118289818 on secure session with LSID: 22351 D: 19620 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 19628 [DMG]Command handler moving to [CommandSen] D: 19632 [DMG]Command handler moving to [AwaitingDe] E: 19637 [DL]Long dispatch time: 133 ms, for event type 16388 D: 19736 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 19743 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 19856 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 19863 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 235) D: 19976 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 19984 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 19992 [EM]>>> [E:16636r M:110087024] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) D: 20003 [EM]Handling via exchange: 16636r, Delegate: 0x2000fc3c D: 20009 [DMG]Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000 I: 20017 [FS]GeneralCommissioning: Received ArmFailSafe (60s) D: 20022 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 22934b53 D: 20029 [DMG]Command handler moving to [ Preparing] D: 20033 [DMG]Command handler moving to [AddingComm] D: 20038 [DMG]Command handler moving to [AddedComma] D: 20043 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 20050 [EM]<<< [E:16636r M:118289819] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 20061 [IN](S) Sending msg 118289819 on secure session with LSID: 22351 D: 20068 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 20075 [DMG]Command handler moving to [CommandSen] D: 20080 [DMG]Command handler moving to [AwaitingDe] E: 20085 [DL]Long dispatch time: 101 ms, for event type 16388 D: 20156 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 21596 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 21604 [EM]>>> [E:16637r M:110087025] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) D: 21615 [EM]Handling via exchange: 16637r, Delegate: 0x2000fc3c D: 21621 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0004 I: 21629 [ZCL]OpCreds: Received a CSRRequest command D: 21634 [ZCL]OpCreds: Finding fabric with fabricIndex 0x0 I: 21828 [ZCL]OpCreds: AllocatePendingOperationalKey succeeded I: 21864 [ZCL]OpCreds: CSRRequest successful. D: 21868 [DMG]Command handler moving to [ Preparing] D: 21873 [DMG]Command handler moving to [AddingComm] D: 21878 [DMG]Command handler moving to [AddedComma] D: 21883 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 21891 [EM]<<< [E:16637r M:118289820] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 21902 [IN](S) Sending msg 118289820 on secure session with LSID: 22351 D: 21909 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 21916 [DMG]Command handler moving to [CommandSen] D: 21921 [DMG]Command handler moving to [AwaitingDe] E: 21926 [DL]Long dispatch time: 330 ms, for event type 16388 D: 22016 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 22023 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 138) D: 22135 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 22144 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 22256 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 22265 [EM]>>> [E:16638r M:110087026] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) D: 22276 [EM]Handling via exchange: 16638r, Delegate: 0x2000fc3c D: 22282 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B I: 22290 [ZCL]OpCreds: Received an AddTrustedRootCertificate command I: 22353 [ZCL]OpCreds: AddTrustedRootCertificate successful. D: 22358 [DMG]Command handler moving to [ Preparing] D: 22363 [DMG]Command handler moving to [AddingComm] D: 22367 [DMG]Command handler moving to [AddedComma] D: 22372 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 22380 [EM]<<< [E:16638r M:118289821] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 22391 [IN](S) Sending msg 118289821 on secure session with LSID: 22351 D: 22397 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 68) D: 22405 [DMG]Command handler moving to [CommandSen] D: 22410 [DMG]Command handler moving to [AwaitingDe] E: 22414 [DL]Long dispatch time: 158 ms, for event type 16388 D: 22495 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 22504 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 22616 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 22625 [EM]>>> [E:16639r M:110087027] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) D: 22636 [EM]Handling via exchange: 16639r, Delegate: 0x2000fc3c D: 22643 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0006 I: 22650 [ZCL]OpCreds: Received an AddNOC command I: 22657 [FP]Validating NOC chain I: 22718 [FP]NOC chain validation successful I: 22722 [FP]Added new fabric at index: 0x1 I: 22726 [FP]Assigned compressed fabric ID: 0x9A40BE2EC5AFB8A2, node ID: 0x000000009CCEEEE9 I: 22734 [TS]Last Known Good Time: 2023-01-25T11:24:03 I: 22739 [TS]New proposed Last Known Good Time: 2023-02-01T07:56:39 I: 22745 [TS]Updating pending Last Known Good Time to 2023-02-01T07:56:39 D: 22752 [DMG]Endpoint 0, Cluster 0x0000_003E update version to d1ec6d1e D: 22758 [DMG]Endpoint 0, Cluster 0x0000_003E update version to d1ec6d1f D: 22797 [EVL]LogEvent event number: 0x0000000000020002 priority: 1, endpoint id: 0x0 cluster id: 0x0000_001F event id: 0x0 Sys timestamp: 0x000000000000590C I: 22811 [ZCL]OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0x3A5C47E77ABF1A5D D: 22819 [DL]Using Thread extended MAC for hostname. I: 22824 [DIS]Advertise operational node 9A40BE2EC5AFB8A2-000000009CCEEEE9 D: 22831 [DMG]Endpoint 0, Cluster 0x0000_003E update version to d1ec6d20 D: 22837 [DMG]Endpoint 0, Cluster 0x0000_003E update version to d1ec6d21 D: 22844 [DMG]Command handler moving to [ Preparing] D: 22848 [DMG]Command handler moving to [AddingComm] D: 22853 [DMG]Command handler moving to [AddedComma] I: 22858 [ZCL]OpCreds: successfully created fabric index 0x1 via AddNOC D: 22864 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 22872 [EM]<<< [E:16639r M:118289822] (S) Msg TX to 1:FFFFFFFB00000000 [B8A2] --- Type 0001:09 (IM:InvokeCommandResponse) I: 22883 [IN](S) Sending msg 118289822 on secure session with LSID: 22351 D: 22889 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 22897 [DMG]Command handler moving to [CommandSen] D: 22901 [DMG]Command handler moving to [AwaitingDe] E: 22906 [DL]Long dispatch time: 290 ms, for event type 16388 D: 22975 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 22984 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 22992 [EM]>>> [E:16640r M:110087028] (S) Msg RX from 1:FFFFFFFB00000000 [B8A2] --- Type 0001:08 (IM:InvokeCommandRequest) D: 23003 [EM]Handling via exchange: 16640r, Delegate: 0x2000fc3c D: 23009 [DMG]Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0003 D: 23023 [DMG]Command handler moving to [ Preparing] D: 23028 [DMG]Command handler moving to [AddingComm] D: 23032 [DMG]Command handler moving to [AddedComma] D: 23037 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 22934b54 D: 23044 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 23051 [EM]<<< [E:16640r M:118289823] (S) Msg TX to 1:FFFFFFFB00000000 [B8A2] --- Type 0001:09 (IM:InvokeCommandResponse) I: 23062 [IN](S) Sending msg 118289823 on secure session with LSID: 22351 D: 23068 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 23076 [DMG]Command handler moving to [CommandSen] D: 23081 [DMG]Command handler moving to [AwaitingDe] E: 23085 [DL]Long dispatch time: 101 ms, for event type 16388 D: 23156 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 23164 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 23172 [EM]>>> [E:16641r M:110087029] (S) Msg RX from 1:FFFFFFFB00000000 [B8A2] --- Type 0001:08 (IM:InvokeCommandRequest) D: 23183 [EM]Handling via exchange: 16641r, Delegate: 0x2000fc3c D: 23189 [DMG]Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0006 D: 23207 [DMG]Decreasing reference count for CommandHandler, remaining 1 D: 23214 [DL]OpenThread State Changed (Flags: 0x100fc100) D: 23219 [DL] Network Name: MyHome1551423246 D: 23224 [DL] PAN Id: 0xF155 D: 23227 [DL] Extended PAN Id: 0x9AF908EE8CB04C73 D: 23231 [DL] Channel: 25 D: 23234 [DL] Mesh Prefix: fdde:ad00:beef::/64 D: 23239 [DL]OpenThread State Changed (Flags: 0x1100101d) D: 23244 [DL] Device Role: DETACHED D: 23247 [DL] Thread Unicast Addresses: D: 23251 [DL] fdde:ad00:beef:0:3b68:d297:6b7d:adc0/64 valid D: 23257 [DL] fe80::a8a2:f9de:8800:152f/64 valid preferred D: 23962 [DL]OpenThread State Changed (Flags: 0x00000100) I: 24586 [DL]SRP Client was started, detected server: fd53:69aa:0a11:0000:56f3:fadf:52fd:9ccc D: 24595 [DL]OpenThread State Changed (Flags: 0x301032b7) D: 24600 [DL] Device Role: CHILD D: 24603 [DL] Partition Id: 0x5BF0EA5 D: 24607 [DL] Thread Unicast Addresses: D: 24611 [DL] fd53:69aa:a11:0:7124:e099:b72a:33d/64 valid preferred D: 24618 [DL] fd9a:f908:ee8c::ff:fe00:dc01/64 valid rloc D: 24623 [DL] fd9a:f908:ee8c:0:3b68:d297:6b7d:adc0/64 valid D: 24629 [DL] fe80::a8a2:f9de:8800:152f/64 valid preferred D: 24636 [DL]OpenThread State Changed (Flags: 0x00000001) D: 24641 [DL] Thread Unicast Addresses: D: 24645 [DL] fd53:69aa:a11:0:7124:e099:b72a:33d/64 valid preferred D: 24652 [DL] fd9a:f908:ee8c::ff:fe00:dc01/64 valid rloc D: 24658 [DL] fd9a:f908:ee8c:0:3b68:d297:6b7d:adc0/64 valid D: 24664 [DL] fe80::a8a2:f9de:8800:152f/64 valid preferred D: 24671 [DMG]Command handler moving to [ Preparing] D: 24675 [DMG]Command handler moving to [AddingComm] D: 24680 [DMG]Command handler moving to [AddedComma] D: 24685 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 22934b55 D: 24691 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 24699 [EM]<<< [E:16641r M:118289824] (S) Msg TX to 1:FFFFFFFB00000000 [B8A2] --- Type 0001:09 (IM:InvokeCommandResponse) I: 24710 [IN](S) Sending msg 118289824 on secure session with LSID: 22351 D: 24716 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 70) D: 24724 [DMG]Command handler moving to [CommandSen] D: 24729 [DMG]Command handler moving to [AwaitingDe] D: 24734 [DL]Using Thread extended MAC for hostname. I: 24738 [DIS]Advertise operational node 9A40BE2EC5AFB8A2-000000009CCEEEE9 I: 24745 [SVR]Operational advertising enabled D: 24836 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 25394 [DL]SRP update succeeded I: 25397 [DIS]Setting operational delegate post init I: 25405 [SWU]Stopping the watchdog timer I: 25409 [SWU]Starting the periodic query timer, timeout: 86400 seconds I: 25415 [DIS]Updating services using commissioning mode 0 D: 25420 [DL]Using Thread extended MAC for hostname. I: 25425 [DIS]Advertise operational node 9A40BE2EC5AFB8A2-000000009CCEEEE9 I: 25432 [DL]advertising srp service: 9A40BE2EC5AFB8A2-000000009CCEEEE9._matter._tcp D: 25440 [DL]Using Thread extended MAC for hostname. I: 25446 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=0 I: 25455 [DL]advertising srp service: 63C5FEEE153A65DD._matterc._udp D: 25462 [DMG]Endpoint 0, Cluster 0x0000_002A update version to d9b02b0c D: 25468 [DMG]Endpoint 0, Cluster 0x0000_002A update version to d9b02b0d D: 26565 [DL]SRP update succeeded D: 27296 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 27305 [EM]>>> [E:16642r M:70809562] (U) Msg RX from 0:6CE24ED4F0574BEA [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1) D: 27316 [EM]Handling via exchange: 16642r, Delegate: 0x200042c0 I: 27322 [IN]CASE Server received Sigma1 message. Starting handshake. EC 0x20004fd0 I: 27329 [IN]CASE Server disabling CASE session setups I: 27334 [EM]<<< [E:16642r M:154641175 (Ack:70809562)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) I: 27347 [IN](U) Sending msg 154641175 to IP address 'UDP:[fdf9:8ee:8cb0:4c73:d3:ac0a:2074:af3f]:55456' D: 27357 [EM]Flushed pending ack for MessageCounter:70809562 on exchange 16642r I: 27365 [SC]Received Sigma1 msg D: 27368 [SC]Found MRP parameters in the message D: 27373 [SC]Peer assigned session key ID 64168 I: 27380 [SC]CASE matched destination ID: fabricIndex 1, NodeID 0x000000009CCEEEE9 D: 27606 [SC]Including MRP parameters I: 27610 [EM]<<< [E:16642r M:154641176 (Ack:70809562)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2) I: 27622 [IN](U) Sending msg 154641176 to IP address 'UDP:[fdf9:8ee:8cb0:4c73:d3:ac0a:2074:af3f]:55456' I: 27633 [SC]Sent Sigma2 msg D: 28038 [EM]Retransmitting MessageCounter:154641176 on exchange 16642r Send Cnt 1 I: 28045 [IN](U) Sending msg 154641176 to IP address 'UDP:[fdf9:8ee:8cb0:4c73:d3:ac0a:2074:af3f]:55456' D: 28389 [EM]Retransmitting MessageCounter:154641176 on exchange 16642r Send Cnt 2 I: 28397 [IN](U) Sending msg 154641176 to IP address 'UDP:[fdf9:8ee:8cb0:4c73:d3:ac0a:2074:af3f]:55456' I: 28903 [EM]>>> [E:16642r M:70809563 (Ack:154641176)] (U) Msg RX from 0:6CE24ED4F0574BEA [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3) D: 28915 [EM]Found matching exchange: 16642r, Delegate: 0x200042dc D: 28921 [EM]Rxd Ack; Removing MessageCounter:154641176 from Retrans Table on exchange 16642r I: 28930 [EM]<<< [E:16642r M:154641177 (Ack:70809563)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) I: 28943 [IN](U) Sending msg 154641177 to IP address 'UDP:[fdf9:8ee:8cb0:4c73:d3:ac0a:2074:af3f]:55456' D: 28953 [EM]Flushed pending ack for MessageCounter:70809563 on exchange 16642r I: 28960 [SC]Received Sigma3 msg E: 28966 [SC]The device does not support GetClock_RealTimeMS() API: 3. Falling back to Last Known Good UTC Time D: 29263 [SC]Sending status report. Protocol code 0, exchange 16642 I: 29270 [EM]<<< [E:16642r M:154641178 (Ack:70809563)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport) I: 29282 [IN](U) Sending msg 154641178 to IP address 'UDP:[fdf9:8ee:8cb0:4c73:d3:ac0a:2074:af3f]:55456' I: 29294 [SC]SecureSession[0x20003708]: Moving from state 'kEstablishing' --> 'kActive' D: 29302 [IN]SecureSession[0x20003708]: Activated - Type:2 LSID:22352 D: 29308 [IN]New secure session activated for device <3A5C47E77ABF1A5D, 1>, LSID:22352 PSID:64168! I: 29317 [IN]CASE Session established to peer: <3A5C47E77ABF1A5D, 1> I: 29323 [IN]CASE Server enabling CASE session setups D: 29328 [IN]SecureSession[0x200037c0]: Allocated Type:2 LSID:22353 D: 29335 [SC]Allocated SecureSession (0x200037c0) - waiting for Sigma1 msg I: 29403 [EM]>>> [E:16643r M:216231075] (S) Msg RX from 1:3A5C47E77ABF1A5D [B8A2] --- Type 0001:08 (IM:InvokeCommandRequest) D: 29416 [EM]Handling via exchange: 16643r, Delegate: 0x2000fc3c D: 29422 [DMG]Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0004 I: 29430 [FS]GeneralCommissioning: Received CommissioningComplete I: 29550 [FP]Metadata for Fabric 0x1 persisted to storage. I: 29743 [TS]Committing Last Known Good Time to storage: 2023-02-01T07:56:39 I: 29807 [ZCL]OpCreds: Fabric index 0x1 was committed to storage. Compressed Fabric Id 0x9A40BE2EC5AFB8A2, FabricId 0000000000000001, NodeId 000000009CCEEEE9, VendorId 0x1349 I: 29849 [FS]GeneralCommissioning: Successfully commited pending fabric data I: 29855 [FS]Fail-safe cleanly disarmed D: 29859 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 22934b56 D: 29866 [DMG]Command handler moving to [ Preparing] D: 29870 [DMG]Command handler moving to [AddingComm] D: 29875 [DMG]Command handler moving to [AddedComma] D: 29880 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 29887 [EM]<<< [E:16643r M:84337419 (Ack:216231075)] (S) Msg TX to 1:3A5C47E77ABF1A5D [B8A2] --- Type 0001:09 (IM:InvokeCommandResponse) I: 29900 [IN](S) Sending msg 84337419 on secure session with LSID: 22352 D: 29907 [DMG]Command handler moving to [CommandSen] D: 29912 [DMG]Command handler moving to [AwaitingDe] I: 29917 [SWU]Device commissioned, schedule a default provider query I: 29923 [SVR]Commissioning completed successfully I: 29928 [DIS]Updating services using commissioning mode 0 D: 29933 [DL]Using Thread extended MAC for hostname. I: 29938 [DIS]Advertise operational node 9A40BE2EC5AFB8A2-000000009CCEEEE9 D: 29945 [DL]Using Thread extended MAC for hostname. I: 29951 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=0 D: 29961 [IN]Expiring all PASE sessions D: 29964 [IN]SecureSession[0x20003650]: MarkForEviction Type:1 LSID:22351 I: 29971 [SC]SecureSession[0x20003650]: Moving from state 'kActive' --> 'kPendingEviction' D: 29979 [IN]SecureSession[0x20003650]: Released - Type:1 LSID:22351 D: 29985 [IN]Clearing BLE pending packets. I: 29989 [BLE]Releasing end point's BLE connection back to application. I: 29995 [DL]Closing BLE GATT connection (ConnId 00) D: 30001 [ZCL]Commissioning complete, notify platform driver to persist network credentials. E: 30035 [DL]Long dispatch time: 118 ms, for event type 32781 D: 30041 [EM]Retransmitting MessageCounter:154641178 on exchange 16642r Send Cnt 1 I: 30049 [IN](U) Sending msg 154641178 to IP address 'UDP:[fdf9:8ee:8cb0:4c73:d3:ac0a:2074:af3f]:55456' E: not connected! I: 30062 [EM]>>> [E:16642r M:70809564 (Ack:154641178)] (U) Msg RX from 0:6CE24ED4F0574BEA [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 30074 [EM]Found matching exchange: 16642r, Delegate: (nil) D: 30080 [EM]Rxd Ack; Removing MessageCounter:154641178 from Retrans Table on exchange 16642r D: 30089 [DL]ConnId: 0x00, New CCCD value: 0x0000 E: 30093 [BLE]no endpoint for unsub recvd I: 30098 [EM]>>> [E:16643r M:216231076 (Ack:84337419)] (S) Msg RX from 1:3A5C47E77ABF1A5D [B8A2] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 30110 [EM]Found matching exchange: 16643r, Delegate: (nil) D: 30116 [EM]Rxd Ack; Removing MessageCounter:84337419 from Retrans Table on exchange 16643r I: 30198 [EM]>>> [E:16644r M:216231077] (S) Msg RX from 1:3A5C47E77ABF1A5D [B8A2] --- Type 0001:02 (IM:ReadRequest) D: 30208 [EM]Handling via exchange: 16644r, Delegate: 0x2000fc3c D: 30214 [IM]Received Read request D: 30218 [DMG]IM RH moving to [GeneratingReports] D: 30222 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 30231 [DMG] Cluster 3e, Attribute 1 is dirty D: 30236 [DMG]Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_0001 (expanded=0) D: 30247 [DMG] Sending report (payload has 151 bytes)... I: 30253 [EM]<<< [E:16644r M:84337420 (Ack:216231077)] (S) Msg TX to 1:3A5C47E77ABF1A5D [B8A2] --- Type 0001:05 (IM:ReportData) I: 30265 [IN](S) Sending msg 84337420 on secure session with LSID: 22352 D: 30272 [DMG] OnReportConfirm: NumReports = 0 D: 30277 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 30285 [DMG]IM RH moving to [AwaitingDestruction] D: 30290 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 30297 [EM]>>> [E:16642r M:70809565 (Ack:154641178)] (U) Msg RX from 0:6CE24ED4F0574BEA [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) I: 30391 [EM]>>> [E:16644r M:216231078 (Ack:84337420)] (S) Msg RX from 1:3A5C47E77ABF1A5D [B8A2] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 30403 [EM]Found matching exchange: 16644r, Delegate: (nil) D: 30410 [EM]Rxd Ack; Removing MessageCounter:84337420 from Retrans Table on exchange 16644r I: 30421 [EM]>>> [E:16645r M:216231079] (S) Msg RX from 1:3A5C47E77ABF1A5D [B8A2] --- Type 0001:02 (IM:ReadRequest) D: 30431 [EM]Handling via exchange: 16645r, Delegate: 0x2000fc3c D: 30437 [IM]Received Read request D: 30440 [DMG]IM RH moving to [GeneratingReports] I: 30445 [DL]BLE GAP connection terminated (reason 0x22) I: 30450 [DL]Current number of connections: 0/2 D: 30454 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 30463 [DMG] Cluster 1d, Attribute 3 is dirty D: 30468 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0003 (expanded=0) D: 30477 [DMG] Sending report (payload has 64 bytes)... I: 30483 [EM]<<< [E:16645r M:84337421 (Ack:216231079)] (S) Msg TX to 1:3A5C47E77ABF1A5D [B8A2] --- Type 0001:05 (IM:ReportData) I: 30495 [IN](S) Sending msg 84337421 on secure session with LSID: 22352 D: 30502 [DMG] OnReportConfirm: NumReports = 0 D: 30507 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 30515 [DMG]IM RH moving to [AwaitingDestruction] D: 30520 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 30626 [EM]>>> [E:16645r M:216231080 (Ack:84337421)] (S) Msg RX from 1:3A5C47E77ABF1A5D [B8A2] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 30640 [EM]Found matching exchange: 16645r, Delegate: (nil) D: 30646 [EM]Rxd Ack; Removing MessageCounter:84337421 from Retrans Table on exchange 16645r I: 30655 [EM]>>> [E:16646r M:216231081] (S) Msg RX from 1:3A5C47E77ABF1A5D [B8A2] --- Type 0001:02 (IM:ReadRequest) D: 30665 [EM]Handling via exchange: 16646r, Delegate: 0x2000fc3c D: 30671 [IM]Received Read request D: 30674 [DMG]IM RH moving to [GeneratingReports] D: 30679 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 30688 [DMG] Cluster 1d, Attribute 0 is dirty D: 30693 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=1 AttributeId=0x0000_0000 (expanded=0) D: 30702 [DMG] Sending report (payload has 71 bytes)... I: 30708 [EM]<<< [E:16646r M:84337422 (Ack:216231081)] (S) Msg TX to 1:3A5C47E77ABF1A5D [B8A2] --- Type 0001:05 (IM:ReportData) I: 30719 [IN](S) Sending msg 84337422 on secure session with LSID: 22352 D: 30727 [DMG] OnReportConfirm: NumReports = 0 D: 30732 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 30740 [DMG]IM RH moving to [AwaitingDestruction] D: 30744 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 30850 [EM]>>> [E:16646r M:216231082 (Ack:84337422)] (S) Msg RX from 1:3A5C47E77ABF1A5D [B8A2] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 30864 [EM]Found matching exchange: 16646r, Delegate: (nil) D: 30870 [EM]Rxd Ack; Removing MessageCounter:84337422 from Retrans Table on exchange 16646r I: 30879 [EM]>>> [E:16647r M:216231083] (S) Msg RX from 1:3A5C47E77ABF1A5D [B8A2] --- Type 0001:02 (IM:ReadRequest) D: 30889 [EM]Handling via exchange: 16647r, Delegate: 0x2000fc3c D: 30895 [IM]Received Read request D: 30899 [DMG]IM RH moving to [GeneratingReports] D: 30904 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 30912 [DMG] Cluster 1d, Attribute 3 is dirty D: 30917 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=1 AttributeId=0x0000_0003 (expanded=0) D: 30926 [DMG] Sending report (payload has 36 bytes)... I: 30932 [EM]<<< [E:16647r M:84337423 (Ack:216231083)] (S) Msg TX to 1:3A5C47E77ABF1A5D [B8A2] --- Type 0001:05 (IM:ReportData) I: 30944 [IN](S) Sending msg 84337423 on secure session with LSID: 22352 D: 30951 [DMG] OnReportConfirm: NumReports = 0 D: 30956 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 30964 [DMG]IM RH moving to [AwaitingDestruction] D: 30968 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 31146 [EM]>>> [E:16647r M:216231084 (Ack:84337423)] (S) Msg RX from 1:3A5C47E77ABF1A5D [B8A2] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 31160 [EM]Found matching exchange: 16647r, Delegate: (nil) D: 31166 [EM]Rxd Ack; Removing MessageCounter:84337423 from Retrans Table on exchange 16647r I: 31175 [EM]>>> [E:16648r M:216231085] (S) Msg RX from 1:3A5C47E77ABF1A5D [B8A2] --- Type 0001:02 (IM:ReadRequest) D: 31185 [EM]Handling via exchange: 16648r, Delegate: 0x2000fc3c D: 31191 [IM]Received Read request D: 31195 [DMG]IM RH moving to [GeneratingReports] D: 31199 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 31208 [DMG] Cluster 1d, Attribute 1 is dirty D: 31213 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=1 AttributeId=0x0000_0001 (expanded=0) D: 31222 [DMG] Sending report (payload has 176 bytes)... I: 31229 [EM]<<< [E:16648r M:84337424 (Ack:216231085)] (S) Msg TX to 1:3A5C47E77ABF1A5D [B8A2] --- Type 0001:05 (IM:ReportData) I: 31240 [IN](S) Sending msg 84337424 on secure session with LSID: 22352 D: 31248 [DMG] OnReportConfirm: NumReports = 0 D: 31253 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 31261 [DMG]IM RH moving to [AwaitingDestruction] D: 31266 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 31650 [EM]Retransmitting MessageCounter:84337424 on exchange 16648r Send Cnt 1 I: 31658 [IN](S) Sending msg 84337424 on secure session with LSID: 22352 I: 31729 [EM]>>> [E:16648r M:216231086 (Ack:84337424)] (S) Msg RX from 1:3A5C47E77ABF1A5D [B8A2] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 31743 [EM]Found matching exchange: 16648r, Delegate: (nil) D: 31748 [EM]Rxd Ack; Removing MessageCounter:84337424 from Retrans Table on exchange 16648r I: 31758 [EM]>>> [E:16649r M:216231087] (S) Msg RX from 1:3A5C47E77ABF1A5D [B8A2] --- Type 0001:02 (IM:ReadRequest) D: 31770 [EM]Handling via exchange: 16649r, Delegate: 0x2000fc3c D: 31775 [IM]Received Read request D: 31779 [DMG]IM RH moving to [GeneratingReports] D: 31784 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 31792 [DMG] Cluster 8, Attribute fffc is dirty D: 31797 [DMG]Reading attribute: Cluster=0x0000_0008 Endpoint=1 AttributeId=0x0000_FFFC (expanded=0) D: 31806 [DMG] Sending report (payload has 37 bytes)... I: 31813 [EM]<<< [E:16649r M:84337425 (Ack:216231087)] (S) Msg TX to 1:3A5C47E77ABF1A5D [B8A2] --- Type 0001:05 (IM:ReportData) I: 31824 [IN](S) Sending msg 84337425 on secure session with LSID: 22352 D: 31832 [DMG] OnReportConfirm: NumReports = 0 D: 31836 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 31844 [DMG]IM RH moving to [AwaitingDestruction] D: 31849 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 31855 [EM]>>> [E:16648r M:216231088 (Ack:84337424)] (S) Msg RX from 1:3A5C47E77ABF1A5D [B8A2] --- Type 0000:10 (SecureChannel:StandaloneAck) I: 31963 [EM]>>> [E:16649r M:216231089 (Ack:84337425)] (S) Msg RX from 1:3A5C47E77ABF1A5D [B8A2] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 31977 [EM]Found matching exchange: 16649r, Delegate: (nil) D: 31983 [EM]Rxd Ack; Removing MessageCounter:84337425 from Retrans Table on exchange 16649r I: 31992 [EM]>>> [E:16650r M:216231090] (S) Msg RX from 1:3A5C47E77ABF1A5D [B8A2] --- Type 0001:02 (IM:ReadRequest) D: 32002 [EM]Handling via exchange: 16650r, Delegate: 0x2000fc3c D: 32008 [IM]Received Read request D: 32012 [DMG]IM RH moving to [GeneratingReports] D: 32017 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 32025 [DMG] Cluster 6, Attribute fffc is dirty D: 32030 [DMG]Reading attribute: Cluster=0x0000_0006 Endpoint=1 AttributeId=0x0000_FFFC (expanded=0) D: 32039 [DMG] Sending report (payload has 37 bytes)... I: 32046 [EM]<<< [E:16650r M:84337426 (Ack:216231090)] (S) Msg TX to 1:3A5C47E77ABF1A5D [B8A2] --- Type 0001:05 (IM:ReportData) I: 32057 [IN](S) Sending msg 84337426 on secure session with LSID: 22352 D: 32064 [DMG] OnReportConfirm: NumReports = 0 D: 32069 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 32077 [DMG]IM RH moving to [AwaitingDestruction] D: 32082 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 32141 [EM]>>> [E:16650r M:216231091 (Ack:84337426)] (S) Msg RX from 1:3A5C47E77ABF1A5D [B8A2] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 32156 [EM]Found matching exchange: 16650r, Delegate: (nil) D: 32161 [EM]Rxd Ack; Removing MessageCounter:84337426 from Retrans Table on exchange 16650r I: 32170 [EM]>>> [E:16651r M:216231092] (S) Msg RX from 1:3A5C47E77ABF1A5D [B8A2] --- Type 0001:02 (IM:ReadRequest) D: 32180 [EM]Handling via exchange: 16651r, Delegate: 0x2000fc3c D: 32186 [IM]Received Read request D: 32190 [DMG]IM RH moving to [GeneratingReports] D: 32195 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 32203 [DMG] Cluster 3e, Attribute 1 is dirty D: 32208 [DMG]Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_0001 (expanded=0) D: 32218 [DMG] Sending report (payload has 151 bytes)... I: 32224 [EM]<<< [E:16651r M:84337427 (Ack:216231092)] (S) Msg TX to 1:3A5C47E77ABF1A5D [B8A2] --- Type 0001:05 (IM:ReportData) I: 32236 [IN](S) Sending msg 84337427 on secure session with LSID: 22352 D: 32243 [DMG] OnReportConfirm: NumReports = 0 D: 32248 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 32256 [DMG]IM RH moving to [AwaitingDestruction] D: 32261 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 32342 [EM]>>> [E:16651r M:216231093 (Ack:84337427)] (S) Msg RX from 1:3A5C47E77ABF1A5D [B8A2] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 32355 [EM]Found matching exchange: 16651r, Delegate: (nil) D: 32361 [EM]Rxd Ack; Removing MessageCounter:84337427 from Retrans Table on exchange 16651r I: 32417 [EM]>>> [E:16652r M:216231094] (S) Msg RX from 1:3A5C47E77ABF1A5D [B8A2] --- Type 0001:0a (IM:TimedRequest) D: 32428 [EM]Handling via exchange: 16652r, Delegate: 0x2000fc3c D: 32434 [DMG]Got Timed Request with timeout 10000: handler 0x20010038 exchange 16652r I: 32442 [EM]<<< [E:16652r M:84337428 (Ack:216231094)] (S) Msg TX to 1:3A5C47E77ABF1A5D [B8A2] --- Type 0001:01 (IM:StatusResponse) I: 32454 [IN](S) Sending msg 84337428 on secure session with LSID: 22352 D: 32462 [DMG]Timed Request time limit 0x000000000000A5DD: handler 0x20010038 exchange 16652r I: 32555 [EM]>>> [E:16652r M:216231095 (Ack:84337428)] (S) Msg RX from 1:3A5C47E77ABF1A5D [B8A2] --- Type 0001:08 (IM:InvokeCommandRequest) D: 32567 [EM]Found matching exchange: 16652r, Delegate: 0x20010038 D: 32573 [EM]Rxd Ack; Removing MessageCounter:84337428 from Retrans Table on exchange 16652r D: 32582 [DMG]Timed following action arrived at 0x0000000000007F46: handler 0x20010038 exchange 16652r D: 32591 [DMG]Handing timed invoke to IM engine: handler 0x20010038 exchange 16652r D: 32599 [DMG]Received command for Endpoint=0 Cluster=0x0000_003C Command=0x0000_0000 I: 32606 [ZCL]Received command to open commissioning window D: 32612 [IN]SecureSession[0x20003650]: Allocated Type:1 LSID:22354 D: 32618 [SC]Assigned local session key ID 22354 D: 32623 [SC]Waiting for PBKDF param request I: 32627 [DIS]Updating services using commissioning mode 2 D: 32632 [DL]Using Thread extended MAC for hostname. I: 32637 [DIS]Advertise operational node 9A40BE2EC5AFB8A2-000000009CCEEEE9 D: 32644 [DL]Using Thread extended MAC for hostname. I: 32649 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=0568/02 cm=2 I: 32659 [DL]advertising srp service: CCDF12D7805CAAAE._matterc._udp I: 32665 [DL]removing srp service: 63C5FEEE153A65DD._matterc._udp I: 32671 [ZCL]Commissioning window is now open D: 32675 [DMG]Command handler moving to [ Preparing] D: 32680 [DMG]Command handler moving to [AddingComm] D: 32685 [DMG]Command handler moving to [AddedComma] D: 32689 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 32697 [EM]<<< [E:16652r M:84337429 (Ack:216231095)] (S) Msg TX to 1:3A5C47E77ABF1A5D [B8A2] --- Type 0001:09 (IM:InvokeCommandResponse) I: 32709 [IN](S) Sending msg 84337429 on secure session with LSID: 22352 D: 32717 [DMG]Command handler moving to [CommandSen] D: 32721 [DMG]Command handler moving to [AwaitingDe] D: 33093 [EM]Retransmitting MessageCounter:84337429 on exchange 16652r Send Cnt 1 I: 33100 [IN](S) Sending msg 84337429 on secure session with LSID: 22352 I: 33110 [EM]>>> [E:16652r M:216231096 (Ack:84337429)] (S) Msg RX from 1:3A5C47E77ABF1A5D [B8A2] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 33123 [EM]Found matching exchange: 16652r, Delegate: (nil) D: 33129 [EM]Rxd Ack; Removing MessageCounter:84337429 from Retrans Table on exchange 16652r D: 33602 [DL]SRP update succeeded D: 42236 [DL]OpenThread State Changed (Flags: 0x00000064) D: 42241 [DL] Device Role: ROUTER E: 59923 [SWU]No suitable OTA Provider candidate found I: 59928 [SWU]No provider available I: 332613 [SVR]Closing pairing window D: 332616 [IN]SecureSession[0x20003650]: Released - Type:1 LSID:22354 I: 332622 [DIS]Updating services using commissioning mode 0 D: 332628 [DL]Using Thread extended MAC for hostname. I: 332633 [DIS]Advertise operational node 9A40BE2EC5AFB8A2-000000009CCEEEE9 D: 332640 [DL]Using Thread extended MAC for hostname. I: 332645 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=0 I: 332655 [DL]advertising srp service: CCDF12D7805CAAAE._matterc._udp D: 332661 [DIS]Scheduling extended discovery timeout in 900s D: 333524 [DL]SRP update succeeded