Hello,
We cant get a connection to our Matter Development Board like in the discription: https://devzone.nordicsemi.com/nordic/nordic-blog/b/blog/posts/connected-home-over-ip-sneak-peek-of-early-development-on-nrf52840
We flashed the LightBulb Example from the Nordic SDK and cant get any connection.
We already tried both Operating Systems (Android and IOS).
We are using Windows and Visual Studio Code for the SDK.
The actuall Mobile Device which we tried to connect to the nrf52840 is a Samsung Galaxy S10 Android Version 10.
I dropped the log File in the extension.
Best regards
Pascal Kaltwasser
î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
