îgçïI: Factory Reset Triggered. Release button within 3000ms to cancel.
I: Factory Reset triggered
D: 143464 [ZCL]Emitting ShutDown event
D: 143468 [EVL]LogEvent event number: 0x0000000000020002 priority: 2, endpoint id:  0x0 cluster id: 0x0000_0028 event id: 0x1 Sys timestamp: 0x000000000002306C
D: 143482 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet
I: 143488 [DL]Performing factory reset
I: 143512 [DL]Erasing Thread persistent info...
I: nRF5 802154 radio initialized
I: 4 Sectors of 4096 bytes
I: alloc wra: 1, e78
I: data wra: 1, 5c
*** Booting Zephyr OS build v3.0.99-ncs1  ***
I: Init CHIP stack
I: Swap type: none
D: 131 [DL]Boot reason: 6


uart:~$ I: 235 [DL]BLE address: E6:4D:57:2E:84:51
I: SoftDevice Controller build revision:
I: 33 78 2a 18 20 f5 61 61 |3x*. .aa
I: a6 8b 77 60 62 83 39 2a |..w`b.9*
I: 7c f1 14 e4             ||...
I: 260 [DL]OpenThread started: OK
I: 263 [DL]Setting OpenThread device type to ROUTER
I: 268 [SVR]Server initializing...
D: 272 [DIS]Init fabric pairing table with server storage
I: 278 [DMG]AccessControl: initializing
I: 281 [DMG]Examples::AccessControlDelegate::Init
I: 286 [DMG]AccessControl: setting
I: 289 [DMG]DefaultAclStorage: initializing
I: 293 [DMG]DefaultAclStorage: 0 entries loaded
I: 297 [ZCL]Using ZAP configuration...
I: 302 [DMG]AccessControlCluster: initializing
I: 306 [ZCL]Initiating Admin Commissioning cluster.
D: 311 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 6fa44934
I: 317 [ZCL]OpCreds: Initiating OpCreds cluster by writing fabrics list from fabric table.
D: 325 [DIS]Add fabric pairing table delegate
D: 330 [DMG]Endpoint 0, Cluster 0x0000_0004 update version to 5a7cd7dc
E: 336 [ZCL]DeviceInfoProvider is not registered
E: 340 [ZCL]Trying to write invalid Calendar Type
E: 345 [ZCL]Failed to write calendar type with error: 0x87
D: 350 [DMG]Endpoint 1, Cluster 0x0000_0004 update version to b6fdcd5e
D: 357 [DMG]Endpoint 1, Cluster 0x0000_0006 update version to 48327bab
I: 363 [ZCL]Cluster OnOff: attribute OnOff set to 0
D: 368 [DMG]Endpoint 1, Cluster 0x0000_0008 update version to 5724edba
I: 374 [ZCL]Cluster LevelControl: attribute CurrentLevel set to 254
D: 380 [IN]UDP::Init bind&listen port=5540
E: 384 [IN]SO_REUSEPORT failed: 109
D: 388 [IN]UDP::Init bound to port=5540
D: 391 [IN]BLEBase::Init - setting/overriding transport
D: 396 [IN]TransportMgr initialized
D: 406 [DIS]Add fabric pairing table delegate
D: 410 [DL]Using Thread extended MAC for hostname.
D: 421 [SC]Assigned local session key ID 242
D: 425 [SC]Waiting for PBKDF param request
D: 429 [DL]CHIPoBLE advertising set to on
I: 433 [DIS]Updating services using commissioning mode 1
D: 438 [DL]Using Thread extended MAC for hostname.
D: 443 [DL]Using Thread extended MAC for hostname.
I: 448 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15
E: 457 [DIS]Failed to advertise commissionable node: Error CHIP:0x00000003
D: 464 [DIS]Scheduling discovery timeout in 900s
E: 468 [DIS]Failed to finalize service update: Error CHIP:0x0000001C
I: 474 [DIS]Updating services using commissioning mode 1
D: 479 [DL]Using Thread extended MAC for hostname.
D: 484 [DL]Using Thread extended MAC for hostname.
I: 489 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15
E: 498 [DIS]Failed to advertise commissionable node: Error CHIP:0x00000003
D: 505 [DIS]Scheduling discovery timeout in 900s
E: 509 [DIS]Failed to finalize service update: Error CHIP:0x0000001C
I: 515 [DIS]Delaying proxy of operational discovery: missing delegate
I: 522 [IN]CASE Server enabling CASE session setups
I: 526 [SVR]Joining Multicast groups
D: 529 [ZCL]Emitting StartUp event
D: 533 [EVL]LogEvent event number: 0x0000000000000000 priority: 2, endpoint id:  0x0 cluster id: 0x0000_0028 event id: 0x0 Sys timestamp: 0x0000000000000215
D: 547 [ZCL]GeneralDiagnosticsDelegate: OnDeviceRebooted
D: 552 [DMG]Endpoint 0, Cluster 0x0000_0033 update version to 362afc59
D: 559 [EVL]LogEvent event number: 0x0000000000000001 priority: 2, endpoint id:  0x0 cluster id: 0x0000_0033 event id: 0x3 Sys timestamp: 0x000000000000022E
I: 573 [SVR]Server Listening...
I: 575 [DL]Device Configuration:
I: 579 [DL]  Serial Number: TEST_SN
I: 582 [DL]  Vendor Id: 65521 (0xFFF1)
I: 586 [DL]  Product Id: 32773 (0x8005)
I: 590 [DL]  Hardware Version: 0
I: 593 [DL]  Setup Pin Code (0 for UNKNOWN/ERROR): 20202021
I: 599 [DL]  Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00)
I: 606 [DL]  Manufacturing Date: (not set)
I: 610 [DL]  Device Type: 65535 (0xFFFF)
I: 614 [SVR]SetupQRCode: [MT:6FCJ142C00KA0648G00]
I: 619 [SVR]Copy/paste the below URL in a browser to see the QR Code:
I: 625 [SVR]https://dhrishi.github.io/connectedhomeip/qrcode.html?data=MT%3A6FCJ142C00KA0648G00
I: 634 [SVR]Manual pairing code: [34970112332]
I: 639 [DL]CHIP task running
I: 645 [DL]CHIPoBLE advertising started
I: 649 [DL]NFC Tag emulation started

uart:~$ I: 30648 [DL]CHIPoBLE advertising mode changed to slow
I: 31903 [DL]BLE connection established (ConnId: 0x00)
I: 31908 [DL]Current number of connections: 1/1
I: 31912 [DL]CHIPoBLE advertising stopped
I: 31916 [DL]NFC Tag emulation stopped
D: 32735 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 32741 [BLE]local and remote recv window sizes = 5
I: 32746 [BLE]selected BTP version 4
I: 32749 [BLE]using BTP fragment sizes rx 244 / tx 244.
D: 32833 [DL]ConnId: 0x00, New CCCD value: 0x0001
D: 32838 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 6)
D: 32844 [IN]BLE EndPoint 0x20009ac8 Connection Complete
I: 32849 [DL]CHIPoBLE connection established (ConnId: 0x00, GATT MTU: 247)
D: 33028 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 33034 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 33040 [EM]Received message of type 0x20 with protocolId (0, 0) and MessageCounter:2535842104 on exchange 32338r
D: 33050 [EM]Handling via exchange: 32338r, Delegate: 0x20005940
D: 33056 [SC]Received PBKDF param request
D: 33059 [SC]Peer assigned session ID 28636
D: 33063 [SC]Found MRP parameters in the message
D: 33068 [SC]Including MRP parameters in PBKDF param response
I: 33074 [IN]Prepared unauthenticated message 0x2002d878 to 0x0000000000000000 (0)  of type 0x21 and protocolId (0, 0) on exchange 32338r with MessageCounter:4116404075.
I: 33089 [IN]Sending unauthenticated msg 0x2002d878 with MessageCounter:4116404075 to 0x0000000000000000 at monotonic time: 0000000000008141 msec
D: 33102 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 139)
D: 33109 [SC]Sent PBKDF param response
D: 33174 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 33272 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 33278 [EM]Received message of type 0x22 with protocolId (0, 0) and MessageCounter:2535842105 on exchange 32338r
D: 33288 [EM]Found matching exchange: 32338r, Delegate: 0x20005940
D: 33294 [SC]Received spake2p msg1
I: 35193 [IN]Prepared unauthenticated message 0x2002d808 to 0x0000000000000000 (0)  of type 0x23 and protocolId (0, 0) on exchange 32338r with MessageCounter:4116404076.
I: 35208 [IN]Sending unauthenticated msg 0x2002d808 with MessageCounter:4116404076 to 0x0000000000000000 at monotonic time: 0000000000008988 msec
D: 35221 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 132)
D: 35228 [SC]Sent spake2p msg2
E: 35230 [DL]Long dispatch time: 1958 ms, for event type 16388
D: 35319 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 35368 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 35374 [EM]Received message of type 0x24 with protocolId (0, 0) and MessageCounter:2535842106 on exchange 32338r
D: 35384 [EM]Found matching exchange: 32338r, Delegate: 0x20005940
D: 35390 [SC]Received spake2p msg3
D: 35394 [SC]Sending status report. Protocol code 0, exchange 32338
I: 35400 [IN]Prepared unauthenticated message 0x2002d898 to 0x0000000000000000 (0)  of type 0x40 and protocolId (0, 0) on exchange 32338r with MessageCounter:4116404077.
I: 35415 [IN]Sending unauthenticated msg 0x2002d898 with MessageCounter:4116404077 to 0x0000000000000000 at monotonic time: 0000000000008A57 msec
D: 35428 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 35)
D: 35435 [IN]New secure session created for device <FFFFFFFB00000000, 0>, LSID:242 PSID:28636!
I: 35444 [SVR]Commissioning completed session establishment step
I: 35450 [DIS]Updating services using commissioning mode 0
D: 35455 [DL]Using Thread extended MAC for hostname.
D: 35460 [DL]Using Thread extended MAC for hostname.
I: 35466 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15
E: 35475 [DIS]Failed to advertise extended commissionable node: Error CHIP:0x00000003
D: 35482 [DIS]Scheduling extended discovery timeout in 900s
E: 35488 [DIS]Failed to finalize service update: Error CHIP:0x0000001C
D: 35494 [DL]CHIPoBLE advertising set to off
I: 35515 [SVR]Device completed Rendezvous process
E: 35519 [DL]Long dispatch time: 151 ms, for event type 16388
D: 35525 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 35530 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 35537 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:7061790 on exchange 32339r
D: 35547 [EM]Handling via exchange: 32339r, Delegate: 0x200078bc
D: 35553 [IM]Received Read request
D: 35558 [DMG]IM RH moving to [GeneratingReports]
D: 35563 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0
D: 35571 [DMG]<RE:Run> Cluster 31, Attribute 3 is dirty
D: 35576 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_0003 (expanded=1)
D: 35585 [DMG]<RE:Run> Cluster 28, Attribute 4 is dirty
D: 35590 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0004 (expanded=0)
D: 35599 [DMG]<RE:Run> Cluster 28, Attribute 2 is dirty
D: 35604 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0002 (expanded=0)
D: 35614 [DMG]<RE:Run> Cluster 30, Attribute 3 is dirty
D: 35619 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0003 (expanded=0)
D: 35628 [DMG]<RE:Run> Cluster 30, Attribute 2 is dirty
D: 35633 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0002 (expanded=0)
D: 35642 [DMG]<RE:Run> Cluster 30, Attribute 1 is dirty
D: 35647 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0001 (expanded=0)
D: 35656 [DMG]<RE:Run> Cluster 30, Attribute 0 is dirty
D: 35661 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0000 (expanded=0)
D: 35670 [DMG]<RE:Run> Cluster 31, Attribute fffc is dirty
D: 35675 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFC (expanded=1)
D: 35684 [DMG]<RE> Sending report (payload has 224 bytes)...
I: 35691 [IN]Prepared secure message 0x2002da40 to 0xFFFFFFFB00000000 (0)  of type 0x5 and protocolId (0, 1) on exchange 32339r with MessageCounter:3086491.
I: 35705 [IN]Sending encrypted msg 0x2002da40 with MessageCounter:3086491 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000008B79 msec
D: 35718 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 244)
D: 35724 [DMG]<RE> OnReportConfirm: NumReports = 0
D: 35729 [DMG]<RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages
D: 35736 [DMG]IM RH moving to [AwaitingDestruction]
D: 35741 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet
D: 35806 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 35812 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 17)
D: 35904 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 35910 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 35916 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:7061791 on exchange 32340r
D: 35926 [EM]Handling via exchange: 32340r, Delegate: 0x200078bc
D: 35932 [DMG]Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000
D: 35941 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 6fa44935
D: 35947 [DMG]ICR moving to [ Preparing]
D: 35951 [DMG]ICR moving to [AddingComm]
D: 35955 [DMG]ICR moving to [AddedComma]
D: 35959 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 35966 [IN]Prepared secure message 0x2002d908 to 0xFFFFFFFB00000000 (0)  of type 0x9 and protocolId (0, 1) on exchange 32340r with MessageCounter:3086492.
I: 35980 [IN]Sending encrypted msg 0x2002d908 with MessageCounter:3086492 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000008C8B msec
D: 35992 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 71)
D: 35998 [DMG]ICR moving to [CommandSen]
D: 36002 [DMG]ICR moving to [AwaitingDe]
D: 36051 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 36056 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 36063 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:7061792 on exchange 32341r
D: 36072 [EM]Handling via exchange: 32341r, Delegate: 0x200078bc
D: 36079 [DMG]Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0002
D: 36102 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 6fa44936
D: 36108 [DMG]ICR moving to [ Preparing]
D: 36112 [DMG]ICR moving to [AddingComm]
D: 36116 [DMG]ICR moving to [AddedComma]
D: 36119 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 36127 [IN]Prepared secure message 0x2002d908 to 0xFFFFFFFB00000000 (0)  of type 0x9 and protocolId (0, 1) on exchange 32341r with MessageCounter:3086493.
I: 36141 [IN]Sending encrypted msg 0x2002d908 with MessageCounter:3086493 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000008D2C msec
D: 36154 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 71)
D: 36160 [DMG]ICR moving to [CommandSen]
D: 36164 [DMG]ICR moving to [AwaitingDe]
E: 36167 [DL]Long dispatch time: 111 ms, for event type 16388
D: 36246 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 36251 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 36258 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:7061793 on exchange 32342r
D: 36267 [EM]Handling via exchange: 32342r, Delegate: 0x200078bc
D: 36274 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002
I: 36281 [ZCL]OpCreds: Certificate Chain request received for PAI
D: 36287 [DMG]ICR moving to [ Preparing]
D: 36291 [DMG]ICR moving to [AddingComm]
D: 36295 [DMG]ICR moving to [AddedComma]
D: 36299 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 36308 [IN]Prepared secure message 0x2002d908 to 0xFFFFFFFB00000000 (0)  of type 0x9 and protocolId (0, 1) on exchange 32342r with MessageCounter:3086494.
I: 36322 [IN]Sending encrypted msg 0x2002d908 with MessageCounter:3086494 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000008DE2 msec
D: 36334 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 244)
D: 36341 [DMG]ICR moving to [CommandSen]
D: 36345 [DMG]ICR moving to [AwaitingDe]
D: 36391 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 36397 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 244)
D: 36489 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 36494 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 48)
D: 36587 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 36592 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 36599 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:7061794 on exchange 32343r
D: 36609 [EM]Handling via exchange: 32343r, Delegate: 0x200078bc
D: 36615 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002
I: 36622 [ZCL]OpCreds: Certificate Chain request received for DAC
D: 36628 [DMG]ICR moving to [ Preparing]
D: 36632 [DMG]ICR moving to [AddingComm]
D: 36636 [DMG]ICR moving to [AddedComma]
D: 36640 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 36649 [IN]Prepared secure message 0x2002d908 to 0xFFFFFFFB00000000 (0)  of type 0x9 and protocolId (0, 1) on exchange 32343r with MessageCounter:3086495.
I: 36663 [IN]Sending encrypted msg 0x2002d908 with MessageCounter:3086495 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000008F37 msec
D: 36676 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 244)
D: 36682 [DMG]ICR moving to [CommandSen]
D: 36686 [DMG]ICR moving to [AwaitingDe]
D: 36732 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 36738 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 244)
D: 36830 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 36835 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 77)
D: 36928 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 36934 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 36940 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:7061795 on exchange 32344r
D: 36950 [EM]Handling via exchange: 32344r, Delegate: 0x200078bc
D: 36957 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0000
I: 36964 [ZCL]OpCreds: received an AttestationRequest
D: 37000 [DMG]ICR moving to [ Preparing]
D: 37004 [DMG]ICR moving to [AddingComm]
D: 37008 [DMG]ICR moving to [AddedComma]
D: 37012 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 37022 [IN]Prepared secure message 0x2002d908 to 0xFFFFFFFB00000000 (0)  of type 0x9 and protocolId (0, 1) on exchange 32344r with MessageCounter:3086496.
I: 37036 [IN]Sending encrypted msg 0x2002d908 with MessageCounter:3086496 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000000090AC msec
D: 37049 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 244)
D: 37055 [DMG]ICR moving to [CommandSen]
D: 37059 [DMG]ICR moving to [AwaitingDe]
E: 37063 [DL]Long dispatch time: 129 ms, for event type 16388
D: 37122 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 37128 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 244)
D: 37220 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 37226 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 237)
D: 37329 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 37419 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 37426 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:7061796 on exchange 32345r
D: 37436 [EM]Handling via exchange: 32345r, Delegate: 0x200078bc
D: 37442 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0004
I: 37450 [ZCL]OpCreds: commissioner has requested a CSR
I: 37801 [ZCL]OpCreds: NewCertificateSigningRequest returned 0
D: 37838 [DMG]ICR moving to [ Preparing]
D: 37842 [DMG]ICR moving to [AddingComm]
D: 37845 [DMG]ICR moving to [AddedComma]
D: 37849 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 37858 [IN]Prepared secure message 0x2002d908 to 0xFFFFFFFB00000000 (0)  of type 0x9 and protocolId (0, 1) on exchange 32345r with MessageCounter:3086497.
I: 37872 [IN]Sending encrypted msg 0x2002d908 with MessageCounter:3086497 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000000093F0 msec
D: 37884 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 244)
D: 37891 [DMG]ICR moving to [CommandSen]
D: 37895 [DMG]ICR moving to [AwaitingDe]
E: 37898 [DL]Long dispatch time: 479 ms, for event type 16388
D: 37959 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 37964 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 138)
D: 38049 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 38095 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
D: 38184 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 38192 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:7061797 on exchange 32346r
D: 38202 [EM]Handling via exchange: 32346r, Delegate: 0x200078bc
D: 38208 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B
I: 38215 [ZCL]OpCreds: commissioner has added a trusted root Cert
D: 38221 [DMG]ICR moving to [ Preparing]
D: 38225 [DMG]ICR moving to [AddingComm]
D: 38229 [DMG]ICR moving to [AddedComma]
D: 38232 [DMG]Endpoint 0, Cluster 0x0000_003E update version to 40c40f12
D: 38239 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 38246 [IN]Prepared secure message 0x2002d908 to 0xFFFFFFFB00000000 (0)  of type 0x9 and protocolId (0, 1) on exchange 32346r with MessageCounter:3086498.
I: 38260 [IN]Sending encrypted msg 0x2002d908 with MessageCounter:3086498 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000009574 msec
D: 38273 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 68)
D: 38280 [DMG]ICR moving to [CommandSen]
D: 38283 [DMG]ICR moving to [AwaitingDe]
E: 38287 [DL]Long dispatch time: 103 ms, for event type 16388
D: 38365 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 38370 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
D: 38454 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 38462 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:7061798 on exchange 32347r
D: 38472 [EM]Handling via exchange: 32347r, Delegate: 0x200078bc
D: 38478 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0006
I: 38486 [ZCL]OpCreds: Received AddNOC command
I: 38491 [DIS]Verifying the received credentials
I: 38555 [DIS]Added new fabric at index: 0x1, Initialized: 1
I: 38560 [DIS]Assigned compressed fabric ID: 0xC45284823480B187, node ID: 0x000000000000000B
I: 38599 [DIS]Fabric (1) persisted to storage. Calling OnFabricPersistedToStorage
I: 38606 [ZCL]OpCreds: Fabric  index 0x1 was persisted to storage. FabricId 0000000000000001, NodeId 000000000000000B, VendorId 0x34B0
I: 38618 [ZCL]OpCreds: Call to fabricListChanged
D: 38622 [DMG]Endpoint 0, Cluster 0x0000_003E update version to 40c40f13
D: 38629 [DMG]Endpoint 0, Cluster 0x0000_003E update version to 40c40f14
D: 38663 [EVL]LogEvent event number: 0x0000000000000002 priority: 1, endpoint id:  0x0 cluster id: 0x0000_001F event id: 0x0 Sys timestamp: 0x0000000000009706
I: 38677 [ZCL]OpCreds: ACL entry created for Fabric 1 CASE Admin NodeId 0x000000000001B669
D: 38685 [DL]Using Thread extended MAC for hostname.
I: 38690 [DIS]Advertise operational node C45284823480B187-000000000000000B
D: 38696 [DMG]ICR moving to [ Preparing]
D: 38700 [DMG]ICR moving to [AddingComm]
D: 38704 [DMG]ICR moving to [AddedComma]
I: 38707 [ZCL]OpCreds: successfully created fabric index 1 via AddNOC
D: 38714 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 38721 [IN]Prepared secure message 0x2002d908 to 0xFFFFFFFB00000000 (1)  of type 0x9 and protocolId (0, 1) on exchange 32347r with MessageCounter:3086499.
I: 38735 [IN]Sending encrypted msg 0x2002d908 with MessageCounter:3086499 to 0xFFFFFFFB00000000 (1) at monotonic time: 000000000000974F msec
D: 38748 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 71)
D: 38754 [DMG]ICR moving to [CommandSen]
D: 38758 [DMG]ICR moving to [AwaitingDe]
E: 38761 [DL]Long dispatch time: 307 ms, for event type 16388
D: 38814 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 38820 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 38827 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:7061799 on exchange 32348r
D: 38836 [EM]Handling via exchange: 32348r, Delegate: 0x200078bc
D: 38843 [DMG]Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0003
D: 38863 [DMG]ICR moving to [ Preparing]
D: 38867 [DMG]ICR moving to [AddingComm]
D: 38870 [DMG]ICR moving to [AddedComma]
D: 38874 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 38882 [IN]Prepared secure message 0x2002d908 to 0xFFFFFFFB00000000 (1)  of type 0x9 and protocolId (0, 1) on exchange 32348r with MessageCounter:3086500.
I: 38896 [IN]Sending encrypted msg 0x2002d908 with MessageCounter:3086500 to 0xFFFFFFFB00000000 (1) at monotonic time: 00000000000097EF msec
D: 38908 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 71)
D: 38915 [DMG]ICR moving to [CommandSen]
D: 38919 [DMG]ICR moving to [AwaitingDe]
E: 38922 [DL]Long dispatch time: 102 ms, for event type 16388
D: 38994 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 39000 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 39006 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:7061800 on exchange 32349r
D: 39016 [EM]Handling via exchange: 32349r, Delegate: 0x200078bc
D: 39022 [DMG]Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0006
D: 39050 [DMG]Decreasing reference count for CommandHandler, remaining 1
D: 39056 [DL]OpenThread State Changed (Flags: 0x1006c100)
D: 39061 [DL]   Network Name: OpenThread
D: 39065 [DL]   PAN Id: 0x1234
D: 39068 [DL]   Extended PAN Id: 0x1111111122222222
D: 39072 [DL]   Channel: 15
D: 39075 [DL]   Mesh Prefix: fdde:ad00:beef::/64
D: 39080 [DL]OpenThread State Changed (Flags: 0x1100101d)
D: 39086 [DL]   Device Role: DETACHED
D: 39089 [DL]   Thread Unicast Addresses:
D: 39093 [DL]        fdde:ad00:beef:0:eba3:f3f6:9d88:565d/64 valid
D: 39099 [DL]        fe80::c881:8334:8ad4:9cc/64 valid preferred
D: 41506 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 3)
D: 41559 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 44034 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
D: 46541 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 3)
D: 46599 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 49074 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
D: 51580 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 3)
D: 51639 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 54114 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
D: 56620 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 3)
D: 56678 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 59199 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
D: 61704 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 3)
D: 61763 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 64239 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
D: 66744 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 3)
D: 66803 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 69278 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
D: 71784 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 3)
D: 71843 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 74363 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
D: 76869 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 3)
D: 76931 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 79403 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
D: 81909 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 3)
D: 81968 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 84443 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
D: 86949 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 3)
D: 87008 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 89528 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
D: 92035 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 3)
D: 92093 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 94568 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
E: 95941 [SVR]Failsafe timer expired
E: 95944 [SVR]Commissioning failed (attempt 1): Error CHIP:0x00000032
D: 95950 [IN]Clearing BLE pending packets.
I: 95954 [BLE]Releasing end point's BLE connection back to application.
I: 95961 [DL]Closing BLE GATT connection (ConnId 00)
D: 95969 [SC]Assigned local session key ID 243
D: 95973 [SC]Waiting for PBKDF param request
D: 95977 [DL]CHIPoBLE advertising set to on
I: 95981 [DIS]Updating services using commissioning mode 1
D: 95986 [DL]Using Thread extended MAC for hostname.
D: 95991 [DL]Using Thread extended MAC for hostname.
I: 95996 [DIS]Advertise operational node C45284823480B187-000000000000000B
E: 96002 [DIS]Failed to advertise operational node: Error CHIP:0x00000003
D: 96009 [DL]Using Thread extended MAC for hostname.
I: 96015 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15
E: 96026 [DIS]Failed to advertise commissionable node: Error CHIP:0x00000003
E: 96033 [DIS]Failed to finalize service update: Error CHIP:0x0000001C
I: 96040 [ZCL]OpCreds: Call to FailSafeCleanup
D: 96044 [IN]Expiring all connections for fabric 1!!
I: 96167 [DIS]Fabric (0x1) deleted. Calling OnFabricDeletedFromStorage
I: 96262 [ZCL]OpCreds: Fabric index 0x1 was deleted from fabric storage.
I: 96269 [ZCL]OpCreds: Call to fabricListChanged
D: 96273 [DMG]Endpoint 0, Cluster 0x0000_003E update version to 40c40f15
D: 96280 [DMG]Endpoint 0, Cluster 0x0000_003E update version to 40c40f16
D: 96287 [EVL]LogEvent event number: 0x0000000000000003 priority: 1, endpoint id:  0x0 cluster id: 0x0000_0028 event id: 0x2 Sys timestamp: 0x000000000001781E
D: 96301 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet
I: 96334 [DIS]Updating services using commissioning mode 1
D: 96339 [DL]Using Thread extended MAC for hostname.
D: 96345 [DL]Using Thread extended MAC for hostname.
I: 96350 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15
E: 96359 [DIS]Failed to advertise commissionable node: Error CHIP:0x00000003
D: 96366 [DIS]Scheduling discovery timeout in 900s
E: 96370 [DIS]Failed to finalize service update: Error CHIP:0x0000001C
D: 96377 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 6fa44937
D: 96383 [ZCL]Failsafe timeout, tell platform driver to revert network credentials.
D: 96444 [DMG]Decreasing reference count for CommandHandler, remaining 0
E: 96451 [DMG]Failed to send command response: 3
D: 96455 [DMG]ICR moving to [AwaitingDe]
E: 96459 [DL]Long dispatch time: 518 ms, for event type 32785
D: 96468 [DL]OpenThread State Changed (Flags: 0x11002006)
D: 96473 [DL]   Device Role: DISABLED
D: 96476 [DL]   Thread Unicast Addresses:
D: 96481 [DL]OpenThread State Changed (Flags: 0x10000000)
I: 96488 [DL]BLE GAP connection terminated (reason 0x16)
I: 96493 [DL]Current number of connections: 0/1
I: 96499 [DL]CHIPoBLE advertising started
I: 96504 [DL]NFC Tag emulation started

