I: Init CHIP stack
I: 221 [DL]BLE address: FB:6A:F9:87:9F:CA
I: 229 [DL]OpenThread SED interval is 1000ms
I: 235 [DL]OpenThread started: OK
I: 238 [DL]Setting OpenThread device type to SLEEPY END DEVICE
I: 244 [SVR]Subscription persistence not supported
I: 248 [SVR]Server initializing...
I: 251 [TS]Last Known Good Time: [unknown]
I: 255 [TS]Setting Last Known Good Time to firmware build time 2024-01-04T16:30:27
I: 267 [DMG]AccessControl: initializing
I: 270 [DMG]Examples::AccessControlDelegate::Init
I: 275 [DMG]AccessControl: setting
I: 278 [DMG]DefaultAclStorage: initializing
I: 282 [DMG]DefaultAclStorage: 0 entries loaded
D: 286 [IN]UDP::Init bind&listen port=5540
E: 290 [IN]SO_REUSEPORT failed: 109
D: 294 [IN]UDP::Init bound to port=5540
D: 297 [IN]BLEBase::Init - setting/overriding transport
D: 302 [IN]TransportMgr initialized
D: 313 [DL]Using Thread extended MAC for hostname.
I: 323 [ZCL]Using ZAP configuration...
I: 327 [DMG]AccessControlCluster: initializing
D: 331 [DL]Boot reason: 1
I: 334 [ZCL]Initiating Admin Commissioning cluster.
I: 339 [DIS]Updating services using commissioning mode 0
E: 344 [DIS]Failed to remove advertised services: 3
D: 348 [DL]Using Thread extended MAC for hostname.
I: 353 [DIS]Advertise commission parameter vendorID=65521 productID=32772 discriminator=3840/15 cm=0
E: 362 [DIS]Failed to advertise extended commissionable node: 3
D: 368 [DIS]Scheduling extended discovery timeout in 900s
E: 373 [DIS]Failed to finalize service update: 3
I: 377 [DIS]Delaying proxy of operational discovery: missing delegate
I: 384 [IN]CASE Server enabling CASE session setups
D: 389 [IN]SecureSession[0x200033b8]: Allocated Type:2 LSID:25936
I: 394 [SVR]Joining Multicast groups
I: 398 [SVR]Server Listening...
I: 401 [DL]Device Configuration:
I: 404 [DL]  Serial Number: 11223344556677889900
I: 408 [DL]  Vendor Id: 65521 (0xFFF1)
I: 412 [DL]  Product Id: 32772 (0x8004)
I: 415 [DL]  Product Name: not-specified
I: 419 [DL]  Hardware Version: 0
I: 422 [DL]  Setup Pin Code (0 for UNKNOWN/ERROR): 20202021
I: 428 [DL]  Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00)
I: 434 [DL]  Manufacturing Date: (not set)
I: 438 [DL]  Device Type: 65535 (0xFFFF)
I: 442 [SVR]SetupQRCode: [MT:4CT9142C00KA0648G00]
I: 447 [SVR]Copy/paste the below URL in a browser to see the QR Code:
I: 453 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A4CT9142C00KA0648G00
I: 462 [SVR]Manual pairing code: [34970112332]
I: 467 [DL]CHIP task running
I: 470 [DIS]Updating services using commissioning mode 0
E: 475 [DIS]Failed to remove advertised services: 3
D: 480 [DL]Using Thread extended MAC for hostname.
I: 485 [DIS]Advertise commission parameter vendorID=65521 productID=32772 discriminator=3840/15 cm=0
E: 493 [DIS]Failed to advertise extended commissionable node: 3
E: 499 [DIS]Failed to finalize service update: 3
I: Initialize binding Handler
I: 506 [SVR]Cannot load binding table: a0
I: Binding Table size: [0]:
I: 4951 [DL]OpenThread SED interval is 200ms
D: 4956 [IN]SecureSession[0x20003470]: Allocated Type:1 LSID:25937
D: 4962 [DL]CHIPoBLE advertising set to on
I: 4966 [DIS]Updating services using commissioning mode 1
E: 4971 [DIS]Failed to remove advertised services: 3
D: 4976 [DL]Using Thread extended MAC for hostname.
I: 4981 [DIS]Advertise commission parameter vendorID=65521 productID=32772 discriminator=3840/15 cm=1
E: 4990 [DIS]Failed to advertise commissionable node: 3
E: 4995 [DIS]Failed to finalize service update: 3
I: 5001 [DL]CHIPoBLE advertising started
I: 5005 [DL]NFC Tag emulation started
I: 35005 [DL]CHIPoBLE advertising mode changed to slow
I: 35011 [DL]CHIPoBLE advertising started
I: 45581 [DL]BLE connection established (ConnId: 0x00)
I: 45586 [DL]Current number of connections: 1/1
I: 45590 [DL]CHIPoBLE advertising stopped
I: 45594 [DL]NFC Tag emulation stopped
D: 46284 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 46291 [BLE]local and remote recv window sizes = 5
I: 46296 [BLE]selected BTP version 4
I: 46300 [BLE]using BTP fragment sizes rx 128 / tx 128.
D: 46307 [DL]ConnId: 0x00, New CCCD value: 0x0002
D: 46311 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 6)
D: 46319 [IN]BLE EndPoint 0x2000fc30 Connection Complete
I: 46324 [DL]CHIPoBLE connection established (ConnId: 0x00, GATT MTU: 131)
D: 46404 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 46494 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 46502 [EM]>>> [E:32766r S:0 M:170198130] (U) Msg RX from 0:966F48DB880EF1EA [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest)
I: 46515 [EM]<<< [E:32766r S:0 M:7730617] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:21 (SecureChannel:PBKDFParamResponse)
I: 46527 [IN](U) Sending msg 7730617 to IP address 'BLE'
D: 46532 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 46584 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 46592 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 14)
D: 46674 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 46682 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 46690 [EM]>>> [E:32766r S:0 M:170198131] (U) Msg RX from 0:966F48DB880EF1EA [0000] --- Type 0000:22 (SecureChannel:PASE_Pake1)
I: 48446 [EM]<<< [E:32766r S:0 M:7730618] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:23 (SecureChannel:PASE_Pake2)
I: 48458 [IN](U) Sending msg 7730618 to IP address 'BLE'
D: 48463 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
E: 48471 [DL]Long dispatch time: 1789 ms, for event type 16388
D: 48549 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 48557 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 6)
D: 48640 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 48647 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 48655 [EM]>>> [E:32766r S:0 M:170198132] (U) Msg RX from 0:966F48DB880EF1EA [0000] --- Type 0000:24 (SecureChannel:PASE_Pake3)
I: 48667 [EM]<<< [E:32766r S:0 M:7730619] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
I: 48678 [IN](U) Sending msg 7730619 to IP address 'BLE'
D: 48684 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 35)
I: 48692 [SC]SecureSession[0x20003470]: Moving from state 'kEstablishing' --> 'kActive'
D: 48700 [IN]SecureSession[0x20003470]: Activated - Type:1 LSID:25937
D: 48706 [IN]New secure session activated for device <FFFFFFFB00000000, 0>, LSID:25937 PSID:28442!
I: 48715 [SVR]Commissioning completed session establishment step
I: 48721 [DIS]Updating services using commissioning mode 0
E: 48726 [DIS]Failed to remove advertised services: 3
D: 48732 [DL]Using Thread extended MAC for hostname.
I: 48737 [DIS]Advertise commission parameter vendorID=65521 productID=32772 discriminator=3840/15 cm=0
E: 48746 [DIS]Failed to advertise extended commissionable node: 3
D: 48752 [DIS]Scheduling extended discovery timeout in 900s
E: 48757 [DIS]Failed to finalize service update: 3
D: 48761 [DL]CHIPoBLE advertising set to off
I: 48766 [SVR]Device completed Rendezvous process
E: 48770 [DL]Long dispatch time: 123 ms, for event type 16388
D: 48777 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 48784 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 48792 [EM]>>> [E:32767r S:25937 M:251125488] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
D: 48803 [IM]Received Read request
I: 48809 [EM]<<< [E:32767r S:25937 M:266401165] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
I: 48819 [IN](S) Sending msg 266401165 on secure session with LSID: 25937
D: 48826 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 97)
D: 48910 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 48917 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 48925 [EM]>>> [E:32768r S:25937 M:251125489] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
D: 48936 [IM]Received Read request
I: 48941 [EM]<<< [E:32768r S:25937 M:266401166] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
I: 48952 [IN](S) Sending msg 266401166 on secure session with LSID: 25937
D: 48959 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72)
D: 49045 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 49052 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 49060 [EM]>>> [E:32769r S:25937 M:251125490] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
D: 49071 [IM]Received Read request
I: 49076 [EM]<<< [E:32769r S:25937 M:266401167] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
I: 49087 [IN](S) Sending msg 266401167 on secure session with LSID: 25937
D: 49094 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72)
D: 49180 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 49187 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 49195 [EM]>>> [E:32770r S:25937 M:251125491] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
D: 49206 [IM]Received Read request
I: 49211 [EM]<<< [E:32770r S:25937 M:266401168] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
I: 49222 [IN](S) Sending msg 266401168 on secure session with LSID: 25937
D: 49229 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72)
D: 49315 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 49322 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 49330 [EM]>>> [E:32771r S:25937 M:251125492] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
D: 49341 [IM]Received Read request
I: 49346 [EM]<<< [E:32771r S:25937 M:266401169] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
I: 49357 [IN](S) Sending msg 266401169 on secure session with LSID: 25937
D: 49364 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 49450 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 49457 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 49465 [EM]>>> [E:32772r S:25937 M:251125493] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
D: 49476 [IM]Received Read request
I: 49481 [EM]<<< [E:32772r S:25937 M:266401170] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
I: 49492 [IN](S) Sending msg 266401170 on secure session with LSID: 25937
D: 49499 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 49585 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 49592 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 49600 [EM]>>> [E:32773r S:25937 M:251125494] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
D: 49611 [IM]Received Read request
I: 49617 [EM]<<< [E:32773r S:25937 M:266401171] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
I: 49627 [IN](S) Sending msg 266401171 on secure session with LSID: 25937
D: 49634 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 97)
D: 49720 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 49727 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 49735 [EM]>>> [E:32774r S:25937 M:251125495] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
D: 49746 [IM]Received Read request
I: 49751 [EM]<<< [E:32774r S:25937 M:266401172] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
I: 49762 [IN](S) Sending msg 266401172 on secure session with LSID: 25937
D: 49769 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72)
D: 49855 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 49862 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 49870 [EM]>>> [E:32775r S:25937 M:251125496] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
D: 49881 [IM]Received Read request
I: 49886 [EM]<<< [E:32775r S:25937 M:266401173] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
I: 49897 [IN](S) Sending msg 266401173 on secure session with LSID: 25937
D: 49904 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 49989 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 52509 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 55017 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 55074 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 57594 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 59889 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 59897 [EM]>>> [E:32776r S:25937 M:251125497] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:0a (IM:TimedRequest)
I: 59909 [EM]<<< [E:32776r S:25937 M:266401174] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:01 (IM:StatusResponse)
I: 59920 [IN](S) Sending msg 266401174 on secure session with LSID: 25937
D: 59926 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 43)
D: 60024 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 60032 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 60040 [EM]>>> [E:32776r S:25937 M:251125498] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 60052 [FS]GeneralCommissioning: Received ArmFailSafe (120s)
I: 60059 [EM]<<< [E:32776r S:25937 M:266401175] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 60071 [IN](S) Sending msg 266401175 on secure session with LSID: 25937
D: 60078 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 60159 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 60167 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 60175 [EM]>>> [E:32777r S:25937 M:251125499] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
D: 60186 [IM]Received Read request
I: 60191 [EM]<<< [E:32777r S:25937 M:266401176] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
I: 60202 [IN](S) Sending msg 266401176 on secure session with LSID: 25937
D: 60208 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 60294 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 60302 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 60310 [EM]>>> [E:32778r S:25937 M:251125500] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:0a (IM:TimedRequest)
I: 60322 [EM]<<< [E:32778r S:25937 M:266401177] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:01 (IM:StatusResponse)
I: 60333 [IN](S) Sending msg 266401177 on secure session with LSID: 25937
D: 60340 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 43)
D: 60429 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 60437 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 60445 [EM]>>> [E:32778r S:25937 M:251125501] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 60476 [EM]<<< [E:32778r S:25937 M:266401178] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 60488 [IN](S) Sending msg 266401178 on secure session with LSID: 25937
D: 60495 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 60609 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 60617 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 60625 [EM]>>> [E:32779r S:25937 M:251125502] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 60637 [ZCL]OpCreds: Certificate Chain request received for DAC
I: 60647 [EM]<<< [E:32779r S:25937 M:266401179] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 60658 [IN](S) Sending msg 266401179 on secure session with LSID: 25937
D: 60665 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 60744 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 60752 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 60834 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 60841 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 60924 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 60931 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 61014 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 61022 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 61029 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 58)
D: 61104 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 61112 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 61120 [EM]>>> [E:32780r S:25937 M:251125503] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 61132 [ZCL]OpCreds: Certificate Chain request received for PAI
I: 61141 [EM]<<< [E:32780r S:25937 M:266401180] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 61153 [IN](S) Sending msg 266401180 on secure session with LSID: 25937
D: 61160 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 61239 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 61246 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 61329 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 61336 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 61419 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 61426 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 61509 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 61517 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 61524 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 28)
D: 61599 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 61607 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 61615 [EM]>>> [E:32781r S:25937 M:251125504] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 61627 [ZCL]OpCreds: Received an AttestationRequest command
I: 61667 [ZCL]OpCreds: AttestationRequest successful.
I: 61675 [EM]<<< [E:32781r S:25937 M:266401181] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 61687 [IN](S) Sending msg 266401181 on secure session with LSID: 25937
D: 61694 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 61779 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 61786 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 61869 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 61876 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 61959 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 61966 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 62049 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 62094 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 62101 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 62184 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 62191 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 90)
D: 62274 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 62282 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 62290 [EM]>>> [E:32782r S:25937 M:251125505] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 62302 [ZCL]OpCreds: Received a CSRRequest command
I: 62485 [ZCL]OpCreds: AllocatePendingOperationalKey succeeded
I: 62524 [ZCL]OpCreds: CSRRequest successful.
I: 62530 [EM]<<< [E:32782r S:25937 M:266401182] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 62542 [IN](S) Sending msg 266401182 on secure session with LSID: 25937
D: 62549 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
E: 62556 [DL]Long dispatch time: 274 ms, for event type 16388
D: 62634 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 62641 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 62724 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 62731 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 62814 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 63759 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 63849 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 63939 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 63948 [EM]>>> [E:32783r S:25937 M:251125506] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 63960 [ZCL]OpCreds: Received an AddTrustedRootCertificate command
I: 64029 [ZCL]OpCreds: AddTrustedRootCertificate successful.
I: 64036 [EM]<<< [E:32783r S:25937 M:266401183] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 64048 [IN](S) Sending msg 266401183 on secure session with LSID: 25937
D: 64054 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 68)
E: 64062 [DL]Long dispatch time: 123 ms, for event type 16388
D: 64119 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 64127 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 64209 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 64299 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 64434 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 64441 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
I: 64451 [EM]>>> [E:32784r S:25937 M:251125507] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 64463 [ZCL]OpCreds: Received an AddNOC command
I: 64470 [FP]Validating NOC chain
I: 64537 [FP]NOC chain validation successful
I: 64541 [FP]Added new fabric at index: 0x1
I: 64545 [FP]Assigned compressed fabric ID: 0x310A9064FE4923E9, node ID: 0x3992EA419D6B939E
I: 64553 [TS]Last Known Good Time: 2024-01-04T16:30:27
I: 64558 [TS]New proposed Last Known Good Time: 2024-01-01T00:00:00
I: 64564 [TS]Retaining current Last Known Good Time
I: 64592 [ZCL]OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0xFFFFFFFD00010001
D: 64601 [DL]Using Thread extended MAC for hostname.
I: 64606 [DIS]Advertise operational node 310A9064FE4923E9-3992EA419D6B939E
I: 64613 [ZCL]OpCreds: successfully created fabric index 0x1 via AddNOC
I: 64620 [EM]<<< [E:32784r S:25937 M:266401184] (S) Msg TX to 1:FFFFFFFB00000000 [23E9] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 64632 [IN](S) Sending msg 266401184 on secure session with LSID: 25937
E: 64638 [DL]Long dispatch time: 204 ms, for event type 16388
D: 64644 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 64652 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 70)
D: 64748 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 64757 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 64884 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 64893 [EM]>>> [E:32785r S:25937 M:251125508] (S) Msg RX from 1:FFFFFFFB00000000 [23E9] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 64911 [EM]<<< [E:32785r S:25937 M:266401185] (S) Msg TX to 1:FFFFFFFB00000000 [23E9] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 64923 [IN](S) Sending msg 266401185 on secure session with LSID: 25937
D: 64930 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 65019 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 65027 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 65035 [EM]>>> [E:32786r S:25937 M:251125509] (S) Msg RX from 1:FFFFFFFB00000000 [23E9] --- Type 0001:02 (IM:ReadRequest)
D: 65046 [IM]Received Read request
I: 65051 [EM]<<< [E:32786r S:25937 M:266401186] (S) Msg TX to 1:FFFFFFFB00000000 [23E9] --- Type 0001:05 (IM:ReportData)
I: 65062 [IN](S) Sending msg 266401186 on secure session with LSID: 25937
D: 65068 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 65154 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 65162 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 65170 [EM]>>> [E:32787r S:25937 M:251125510] (S) Msg RX from 1:FFFFFFFB00000000 [23E9] --- Type 0001:08 (IM:InvokeCommandRequest)
D: 65193 [DL]OpenThread State Changed (Flags: 0x1017c100)
D: 65198 [DL]   Network Name: OpenThreadDemo
D: 65202 [DL]   PAN Id: 0x1234
D: 65205 [DL]   Extended PAN Id: 0x1111111122222222
D: 65210 [DL]   Channel: 15
D: 65212 [DL]   Mesh Prefix: fd30:7a52:371e:f565::/64
D: 65218 [DL]OpenThread State Changed (Flags: 0x1100101d)
D: 65223 [DL]   Device Role: DETACHED
D: 65227 [DL]   Thread Unicast Addresses:
D: 65230 [DL]        fd30:7a52:371e:f565:ec2b:b609:669d:4420/64 valid
D: 65237 [DL]        fe80::4856:c567:6040:899c/64 valid preferred
I: 66598 [DL]SRP Client was started, detected server: fd30:7a52:371e:f565:58a2:925e:b943:7c56
D: 66608 [DL]OpenThread State Changed (Flags: 0x200002a4)
D: 66613 [DL]   Device Role: CHILD
D: 66616 [DL]   Partition Id: 0x77BB2A4B
D: 66621 [DL]OpenThread State Changed (Flags: 0x00000001)
D: 66626 [DL]   Thread Unicast Addresses:
D: 66630 [DL]        fd79:7f72:32f0:1:2148:587f:2d26:c6d3/64 valid preferred
D: 66636 [DL]        fd30:7a52:371e:f565:0:ff:fe00:a404/64 valid rloc
D: 66643 [DL]        fd30:7a52:371e:f565:ec2b:b609:669d:4420/64 valid
D: 66649 [DL]        fe80::4856:c567:6040:899c/64 valid preferred
I: 66657 [EM]<<< [E:32787r S:25937 M:266401187] (S) Msg TX to 1:FFFFFFFB00000000 [23E9] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 66668 [IN](S) Sending msg 266401187 on secure session with LSID: 25937
D: 66675 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 70)
D: 66683 [DL]Using Thread extended MAC for hostname.
I: 66688 [DIS]Advertise operational node 310A9064FE4923E9-3992EA419D6B939E
I: 66694 [SVR]Operational advertising enabled
D: 66729 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 67352 [DL]SRP update succeeded
I: 67356 [DIS]Setting operational delegate post init
I: 67364 [SWU]Stopping the watchdog timer
I: 67367 [SWU]Starting the periodic query timer, timeout: 86400 seconds
E: 67374 [SVR]Server initialization complete
I: 67378 [DIS]Updating services using commissioning mode 0
D: 67383 [DL]Using Thread extended MAC for hostname.
I: 67388 [DIS]Advertise operational node 310A9064FE4923E9-3992EA419D6B939E
I: 67395 [DL]advertising srp service: 310A9064FE4923E9-3992EA419D6B939E._matter._tcp
D: 67402 [DL]Using Thread extended MAC for hostname.
I: 67408 [DIS]Advertise commission parameter vendorID=65521 productID=32772 discriminator=3840/15 cm=0
I: 67417 [DL]advertising srp service: C2BA875DA65835CF._matterc._udp
I: 67764 [DL]BLE GAP connection terminated (reason 0x13)
I: 67769 [DL]Current number of connections: 0/1
D: 68706 [DL]SRP update succeeded
I: 69121 [EM]>>> [E:32788r S:0 M:170198133] (U) Msg RX from 0:166194B2E5EC28ED [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
I: 69133 [IN]CASE Server received Sigma1 message . Starting handshake. EC 0x20004d78
I: 69140 [IN]CASE Server disabling CASE session setups
I: 69146 [EM]<<< [E:32788r S:0 M:7730620 (Ack:170198133)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 69158 [IN](U) Sending msg 7730620 to IP address 'UDP:[fd11:1111:1122:2222:58e:9527:da88:956e]:48281'
I: 69169 [SC]Received Sigma1 msg
I: 69176 [SC]CASE matched destination ID: fabricIndex 1, NodeID 0x3992EA419D6B939E
I: 69391 [EM]<<< [E:32788r S:0 M:7730621 (Ack:170198133)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2)
I: 69404 [IN](U) Sending msg 7730621 to IP address 'UDP:[fd11:1111:1122:2222:58e:9527:da88:956e]:48281'
I: 69415 [SC]Sent Sigma2 msg
I: 70104 [EM]>>> [E:32788r S:0 M:170198134 (Ack:7730621)] (U) Msg RX from 0:166194B2E5EC28ED [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
I: 70117 [EM]<<< [E:32788r S:0 M:7730622 (Ack:170198134)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 70130 [IN](U) Sending msg 7730622 to IP address 'UDP:[fd11:1111:1122:2222:58e:9527:da88:956e]:48281'
I: 70140 [SC]Received Sigma3 msg
E: 70148 [SC]The device does not support GetClock_RealTimeMS() API: 3.  Falling back to Last Known Good UTC Time
E: 70282 [DL]Long dispatch time: 124 ms, for event type 2
I: 70310 [EM]<<< [E:32788r S:0 M:7730623 (Ack:170198134)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
I: 70323 [IN](U) Sending msg 7730623 to IP address 'UDP:[fd11:1111:1122:2222:58e:9527:da88:956e]:48281'
I: 70335 [SC]SecureSession[0x200033b8]: Moving from state 'kEstablishing' --> 'kActive'
D: 70343 [IN]SecureSession[0x200033b8]: Activated - Type:2 LSID:25936
D: 70349 [IN]New secure session activated for device <D07881E73455012C, 1>, LSID:25936 PSID:28443!
I: 70358 [IN]CASE Session established to peer: <D07881E73455012C, 1>
I: 70364 [IN]CASE Server enabling CASE session setups
D: 70369 [IN]SecureSession[0x20003528]: Allocated Type:2 LSID:25938
I: 70506 [EM]>>> [E:32788r S:0 M:170198135 (Ack:7730623)] (U) Msg RX from 0:166194B2E5EC28ED [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 70531 [EM]>>> [E:32789r S:25936 M:256249412] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0001:02 (IM:ReadRequest)
D: 70542 [IM]Received Read request
I: 70547 [EM]<<< [E:32789r S:25936 M:839296 (Ack:256249412)] (S) Msg TX to 1:D07881E73455012C [23E9] --- Type 0001:05 (IM:ReportData)
I: 70559 [IN](S) Sending msg 839296 on secure session with LSID: 25936
I: 70918 [EM]>>> [E:32789r S:25936 M:256249413 (Ack:839296)] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 70942 [EM]>>> [E:32790r S:25936 M:256249414] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0001:02 (IM:ReadRequest)
D: 70953 [IM]Received Read request
I: 70959 [EM]<<< [E:32790r S:25936 M:839297 (Ack:256249414)] (S) Msg TX to 1:D07881E73455012C [23E9] --- Type 0001:05 (IM:ReportData)
I: 70970 [IN](S) Sending msg 839297 on secure session with LSID: 25936
I: 71328 [EM]>>> [E:32790r S:25936 M:256249415 (Ack:839297)] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 71354 [EM]>>> [E:32791r S:25936 M:256249416] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 71366 [FS]GeneralCommissioning: Received CommissioningComplete
I: 71381 [FP]Metadata for Fabric 0x1 persisted to storage.
I: 71409 [TS]Committing Last Known Good Time to storage: 2024-01-04T16:30:27
I: 71421 [ZCL]OpCreds: Fabric index 0x1 was committed to storage. Compressed Fabric Id 0x310A9064FE4923E9, FabricId D145FFFDE1A6BB37, NodeId 3992EA419D6B939E, VendorId 0x6006
I: 71438 [FS]GeneralCommissioning: Successfully commited pending fabric data
I: 71445 [FS]Fail-safe cleanly disarmed
I: 71450 [EM]<<< [E:32791r S:25936 M:839298 (Ack:256249416)] (S) Msg TX to 1:D07881E73455012C [23E9] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 71462 [IN](S) Sending msg 839298 on secure session with LSID: 25936
I: 71470 [SWU]Device commissioned, schedule a default provider query
I: 71477 [SVR]Commissioning completed successfully
I: 71482 [DIS]Updating services using commissioning mode 0
D: 71487 [DL]Using Thread extended MAC for hostname.
I: 71492 [DIS]Advertise operational node 310A9064FE4923E9-3992EA419D6B939E
D: 71499 [DL]Using Thread extended MAC for hostname.
I: 71504 [DIS]Advertise commission parameter vendorID=65521 productID=32772 discriminator=3840/15 cm=0
D: 71514 [IN]Expiring all PASE sessions
D: 71518 [IN]SecureSession[0x20003470]: MarkForEviction Type:1 LSID:25937
I: 71524 [SC]SecureSession[0x20003470]: Moving from state 'kActive' --> 'kPendingEviction'
D: 71533 [IN]SecureSession[0x20003470]: Released - Type:1 LSID:25937
D: 71540 [IN]Clearing BLE pending packets.
I: 71544 [BLE]Releasing end point's BLE connection back to application.
I: 71550 [DL]Closing BLE GATT connection (ConnId 00)
I: 71743 [EM]>>> [E:32791r S:25936 M:256249417 (Ack:839298)] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 71758 [DL]OpenThread SED interval is 1000ms
I: 71763 [EM]>>> [E:32792r S:25936 M:256249418] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0001:02 (IM:ReadRequest)
D: 71774 [IM]Received Read request
I: 71778 [DL]OpenThread SED interval is 200ms
I: 71784 [EM]<<< [E:32792r S:25936 M:839299 (Ack:256249418)] (S) Msg TX to 1:D07881E73455012C [23E9] --- Type 0001:05 (IM:ReportData)
I: 71795 [IN](S) Sending msg 839299 on secure session with LSID: 25936
I: 71953 [EM]>>> [E:32792r S:25936 M:256249419 (Ack:839299)] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 71969 [DL]OpenThread SED interval is 1000ms
I: 71974 [EM]>>> [E:32793r S:25936 M:256249420] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0001:02 (IM:ReadRequest)
D: 71985 [IM]Received Read request
I: 71989 [DL]OpenThread SED interval is 200ms
I: 71994 [EM]<<< [E:32793r S:25936 M:839300 (Ack:256249420)] (S) Msg TX to 1:D07881E73455012C [23E9] --- Type 0001:05 (IM:ReportData)
I: 72006 [IN](S) Sending msg 839300 on secure session with LSID: 25936
I: 72269 [EM]>>> [E:32793r S:25936 M:256249421 (Ack:839300)] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 72282 [DL]OpenThread SED interval is 1000ms
I: 72399 [EM]>>> [E:32794r S:25936 M:256249422] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0001:02 (IM:ReadRequest)
D: 72410 [IM]Received Read request
I: 72414 [DL]OpenThread SED interval is 200ms
I: 72419 [EM]<<< [E:32794r S:25936 M:839301 (Ack:256249422)] (S) Msg TX to 1:D07881E73455012C [23E9] --- Type 0001:05 (IM:ReportData)
I: 72431 [IN](S) Sending msg 839301 on secure session with LSID: 25936
I: 72802 [EM]>>> [E:32794r S:25936 M:256249423 (Ack:839301)] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 72818 [DL]OpenThread SED interval is 1000ms
I: 72823 [EM]>>> [E:32795r S:25936 M:256249424] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0001:0a (IM:TimedRequest)
I: 72835 [EM]<<< [E:32795r S:25936 M:839302 (Ack:256249424)] (S) Msg TX to 1:D07881E73455012C [23E9] --- Type 0001:01 (IM:StatusResponse)
I: 72847 [IN](S) Sending msg 839302 on secure session with LSID: 25936
I: 72855 [DL]OpenThread SED interval is 200ms
I: 73236 [EM]>>> [E:32795r S:25936 M:256249425 (Ack:839302)] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 73249 [ZCL]Received command to open commissioning window
D: 73255 [IN]SecureSession[0x20003470]: Allocated Type:1 LSID:25939
I: 73261 [DIS]Updating services using commissioning mode 2
D: 73266 [DL]Using Thread extended MAC for hostname.
I: 73271 [DIS]Advertise operational node 310A9064FE4923E9-3992EA419D6B939E
D: 73278 [DL]Using Thread extended MAC for hostname.
I: 73284 [DIS]Advertise commission parameter vendorID=65521 productID=32772 discriminator=3468/13 cm=2
I: 73293 [DL]advertising srp service: 2A825572D051D4B4._matterc._udp
I: 73300 [DL]removing srp service: C2BA875DA65835CF._matterc._udp
I: 73305 [ZCL]Commissioning window is now open
I: 73311 [EM]<<< [E:32795r S:25936 M:839303 (Ack:256249425)] (S) Msg TX to 1:D07881E73455012C [23E9] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 73324 [IN](S) Sending msg 839303 on secure session with LSID: 25936
I: 73610 [EM]>>> [E:32795r S:25936 M:256249426 (Ack:839303)] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 73634 [EM]>>> [E:32796r S:25936 M:256249427] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0001:02 (IM:ReadRequest)
D: 73645 [IM]Received Read request
I: 73650 [EM]<<< [E:32796r S:25936 M:839304 (Ack:256249427)] (S) Msg TX to 1:D07881E73455012C [23E9] --- Type 0001:05 (IM:ReportData)
I: 73662 [IN](S) Sending msg 839304 on secure session with LSID: 25936
I: 73997 [EM]>>> [E:32796r S:25936 M:256249428 (Ack:839304)] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 74021 [EM]>>> [E:32797r S:25936 M:256249429] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0001:0a (IM:TimedRequest)
I: 74033 [EM]<<< [E:32797r S:25936 M:839305 (Ack:256249429)] (S) Msg TX to 1:D07881E73455012C [23E9] --- Type 0001:01 (IM:StatusResponse)
I: 74045 [IN](S) Sending msg 839305 on secure session with LSID: 25936
I: 74195 [EM]>>> [E:32797r S:25936 M:256249430 (Ack:839305)] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 74209 [ZCL]Received command to close commissioning window
I: 74214 [SVR]Closing pairing window
D: 74218 [IN]SecureSession[0x20003470]: Released - Type:1 LSID:25939
I: 74224 [DIS]Updating services using commissioning mode 0
D: 74229 [DL]Using Thread extended MAC for hostname.
I: 74234 [DIS]Advertise operational node 310A9064FE4923E9-3992EA419D6B939E
D: 74241 [DL]Using Thread extended MAC for hostname.
I: 74246 [DIS]Advertise commission parameter vendorID=65521 productID=32772 discriminator=3840/15 cm=0
I: 74256 [DL]advertising srp service: 2A825572D051D4B4._matterc._udp
D: 74262 [DIS]Scheduling extended discovery timeout in 900s
I: 74268 [DL]removing srp service: C2BA875DA65835CF._matterc._udp
I: 74273 [ZCL]Commissioning window is now closed
I: 74279 [EM]<<< [E:32797r S:25936 M:839306 (Ack:256249430)] (S) Msg TX to 1:D07881E73455012C [23E9] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 74292 [IN](S) Sending msg 839306 on secure session with LSID: 25936
I: 74893 [EM]>>> [E:32797r S:25936 M:256249431 (Ack:839306)] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 74907 [DL]OpenThread SED interval is 1000ms
I: 74923 [EM]>>> [E:32798r S:25936 M:256249432] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0001:02 (IM:ReadRequest)
D: 74935 [IM]Received Read request
I: 74940 [DL]OpenThread SED interval is 200ms
I: 74945 [EM]<<< [E:32798r S:25936 M:839307 (Ack:256249432)] (S) Msg TX to 1:D07881E73455012C [23E9] --- Type 0001:05 (IM:ReportData)
I: 74957 [IN](S) Sending msg 839307 on secure session with LSID: 25936
I: 75296 [EM]>>> [E:32799r S:25936 M:256249433] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0001:02 (IM:ReadRequest)
D: 75309 [IM]Received Read request
I: 75314 [EM]<<< [E:32799r S:25936 M:839308 (Ack:256249433)] (S) Msg TX to 1:D07881E73455012C [23E9] --- Type 0001:05 (IM:ReportData)
I: 75326 [IN](S) Sending msg 839308 on secure session with LSID: 25936
I: 75335 [EM]>>> [E:32798r S:25936 M:256249434 (Ack:839307)] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 75494 [EM]>>> [E:32799r S:25936 M:256249435 (Ack:839308)] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 75509 [DL]OpenThread SED interval is 1000ms
I: 75515 [EM]>>> [E:32800r S:25936 M:256249436] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0001:0a (IM:TimedRequest)
I: 75527 [EM]<<< [E:32800r S:25936 M:839309 (Ack:256249436)] (S) Msg TX to 1:D07881E73455012C [23E9] --- Type 0001:01 (IM:StatusResponse)
I: 75539 [IN](S) Sending msg 839309 on secure session with LSID: 25936
I: 75547 [DL]OpenThread SED interval is 200ms
I: 75718 [EM]>>> [E:32800r S:25936 M:256249437 (Ack:839309)] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 75732 [ZCL]Received command to open commissioning window
D: 75738 [IN]SecureSession[0x20003470]: Allocated Type:1 LSID:25940
I: 75744 [DIS]Updating services using commissioning mode 2
D: 75749 [DL]Using Thread extended MAC for hostname.
I: 75754 [DIS]Advertise operational node 310A9064FE4923E9-3992EA419D6B939E
D: 75761 [DL]Using Thread extended MAC for hostname.
I: 75766 [DIS]Advertise commission parameter vendorID=65521 productID=32772 discriminator=1466/05 cm=2
I: 75776 [DL]advertising srp service: DEBE6C323524D155._matterc._udp
I: 75782 [DL]removing srp service: C2BA875DA65835CF._matterc._udp
I: 75788 [DL]removing srp service: 2A825572D051D4B4._matterc._udp
I: 75794 [ZCL]Commissioning window is now open
I: 75799 [EM]<<< [E:32800r S:25936 M:839310 (Ack:256249437)] (S) Msg TX to 1:D07881E73455012C [23E9] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 75812 [IN](S) Sending msg 839310 on secure session with LSID: 25936
I: 76522 [EM]>>> [E:32800r S:25936 M:256249438 (Ack:839310)] (S) Msg RX from 1:D07881E73455012C [23E9] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 77083 [DL]SRP update succeeded
E: 101477 [SWU]No suitable OTA Provider candidate found
I: 101482 [SWU]No provider available