Matter Commissioning

Hi, 

I'm testing the matter commissioning from your sample "light_bulb" on the nRF Connect SDK v2.1.0

I have this setup:

- One nrf52840dk flashed with the light_bulb using the configuration file prj.conf, whith "CONFIG_CHIP_LIB_SHELL=y" added;

- One Raspberry Pi 4 as Openthread Border Router built from openthread/ot-br-posix github project;

- One nrf52840dk flashed with the openthread/rcp sample, connected to the Border Router;

- Android smartphone with last released Android CHIPTool apk version, downloaded from https://github.com/nrfconnect/sdk-connectedhomeip/releases .

I started configuring the Thread network from the Border Router with these commmands:

- sudo service otbr-agent restart

- sudo ot-ctl dataset init new

- sudo ot-ctl dataset commit active

- sudo ot-ctl ifconfig up

- sudo thread start

And verified with sudo ot-ctl state that border router were the leader of that network.

Subsequently i've opened a linux terminal to comunicate via uart with the matter sample, pushed the boot/reset button on the development kit and verified the bluetooth advertising pushing button 4.

Finally i've opened Android CHIP Tool from the smartphone and clicked on the "PROVISION CHIP DEVICE WITH THREAD" tab, inserted the QR Code obtained from the light_bulb sample.

The app asked me to insert the thread network (channel, panid, extended panid and masterkey), should i do it manually? We expected this to be done automatically.

  • Hi,

    Since the Android phone/application is not itself part of the Thread network (it does not have Thread capabilities), it does not automatically have access to the network credentials of the running Thread network. The phone application communicates with the Matter accessory that is being commissioned through BLE, and it can talk with commissioned Matter devices through WiFi and the Thread border router over IPv6. You will have to enter the Thread network credentials of your Thread network manually if you are not using the default, pre-commissioned, credentials. The app will transfer the credentials to the accessory over BLE, for the accessory to attach to the Thread network.

    Best regards,
    Jørgen

  • I tried inserting the thread network datas, as you suggested, but the commissioning fails.

    The logs from light_bulb sample terminal are reported in the attached text file.

    I: 30663 [DL]CHIPoBLE advertising mode changed to slow
    I: 407958 [DL]BLE connection established (ConnId: 0x00)
    I: 407963 [DL]Current number of connections: 1/1
    I: 407968 [DL]CHIPoBLE advertising stopped
    I: 407971 [DL]NFC Tag emulation stopped
    D: 408948 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 408955 [BLE]local and remote recv window sizes = 5
    I: 408960 [BLE]selected BTP version 4
    I: 408963 [BLE]using BTP fragment sizes rx 244 / tx 244.
    D: 409068 [DL]ConnId: 0x00, New CCCD value: 0x0002
    D: 409072 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 6)
    D: 409080 [IN]BLE EndPoint 0x20011c00 Connection Complete
    I: 409085 [DL]CHIPoBLE connection established (ConnId: 0x00, GATT MTU: 247)
    D: 409248 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 409338 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 409346 [EM]Received message of type 0x20 with protocolId (0, 0) and MessageCounter:222164225 on exchange 49031r
    D: 409356 [EM]Handling via exchange: 49031r, Delegate: 0x20005754
    D: 409362 [SC]Received PBKDF param request
    D: 409366 [SC]Peer assigned session ID 28885
    D: 409369 [SC]Found MRP parameters in the message
    D: 409374 [SC]Including MRP parameters in PBKDF param response
    I: 409380 [IN]Prepared unauthenticated message 0x2002ef20 to 0x0000000000000000 (0)  of type 0x21 and protocolId (0, 0) on exchange 49031r with MessageCounte.
    I: 409396 [IN]Sending unauthenticated msg 0x2002ef20 with MessageCounter:240044632 to 0x0000000000000000 at monotonic time: 0000000000063F33 msec
    D: 409408 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 140)
    D: 409416 [SC]Sent PBKDF param response
    D: 409473 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 409518 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 409526 [EM]Received message of type 0x22 with protocolId (0, 0) and MessageCounter:222164226 on exchange 49031r
    D: 409536 [EM]Found matching exchange: 49031r, Delegate: 0x20005754
    D: 409542 [SC]Received spake2p msg1
    I: 411524 [IN]Prepared unauthenticated message 0x2002eeb0 to 0x0000000000000000 (0)  of type 0x23 and protocolId (0, 0) on exchange 49031r with MessageCounte.
    I: 411539 [IN]Sending unauthenticated msg 0x2002eeb0 with MessageCounter:240044633 to 0x0000000000000000 at monotonic time: 0000000000064793 msec
    D: 411552 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 132)
    D: 411560 [SC]Sent spake2p msg2
    E: 411563 [DL]Long dispatch time: 2045 ms, for event type 16388
    D: 411723 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 411768 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 411775 [EM]Received message of type 0x24 with protocolId (0, 0) and MessageCounter:222164227 on exchange 49031r
    D: 411785 [EM]Found matching exchange: 49031r, Delegate: 0x20005754
    D: 411791 [SC]Received spake2p msg3
    D: 411795 [SC]Sending status report. Protocol code 0, exchange 49031
    I: 411801 [IN]Prepared unauthenticated message 0x2002ef38 to 0x0000000000000000 (0)  of type 0x40 and protocolId (0, 0) on exchange 49031r with MessageCounte.
    I: 411817 [IN]Sending unauthenticated msg 0x2002ef38 with MessageCounter:240044634 to 0x0000000000000000 at monotonic time: 00000000000648A8 msec
    D: 411829 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 35)
    I: 411838 [SC]SecureSession[0x20003570]: Moving from state 'kEstablishing' --> 'kActive'
    D: 411846 [IN]SecureSession[0x20003570]: Activated - Type:1 LSID:63222
    D: 411852 [IN]New secure session activated for device <FFFFFFFB00000000, 0>, LSID:63222 PSID:28885!
    I: 411861 [SVR]Commissioning completed session establishment step
    I: 411867 [DIS]Updating services using commissioning mode 0
    D: 411872 [DL]Using Thread extended MAC for hostname.
    D: 411878 [DL]Using Thread extended MAC for hostname.
    I: 411883 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=0
    E: 411892 [DIS]Failed to advertise extended commissionable node: 3
    D: 411898 [DIS]Scheduling extended discovery timeout in 900s
    E: 411904 [DIS]Failed to finalize service update: 1c
    D: 411908 [DL]CHIPoBLE advertising set to off
    I: 411913 [SVR]Device completed Rendezvous process
    E: 411917 [DL]Long dispatch time: 149 ms, for event type 16388
    D: 411948 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 412083 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 412091 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:164278656 on exchange 49032r
    D: 412101 [EM]Handling via exchange: 49032r, Delegate: 0x2000f5cc
    D: 412107 [IM]Received Read request
    D: 412113 [DMG]IM RH moving to [GeneratingReports]
    D: 412118 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0
    D: 412126 [DMG]<RE:Run> Cluster 31, Attribute 3 is dirty
    D: 412132 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_0003 (expanded=1)
    D: 412141 [DMG]<RE:Run> Cluster 28, Attribute 4 is dirty
    D: 412146 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0004 (expanded=0)
    D: 412155 [DMG]<RE:Run> Cluster 28, Attribute 2 is dirty
    D: 412160 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0002 (expanded=0)
    D: 412169 [DMG]<RE:Run> Cluster 30, Attribute 3 is dirty
    D: 412175 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0003 (expanded=0)
    D: 412184 [DMG]<RE:Run> Cluster 30, Attribute 2 is dirty
    D: 412189 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0002 (expanded=0)
    D: 412198 [DMG]<RE:Run> Cluster 30, Attribute 1 is dirty
    D: 412203 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0001 (expanded=0)
    D: 412212 [DMG]<RE:Run> Cluster 30, Attribute 0 is dirty
    D: 412217 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0000 (expanded=0)
    D: 412226 [DMG]<RE:Run> Cluster 31, Attribute fffc is dirty
    D: 412232 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFC (expanded=1)
    D: 412241 [DMG]<RE> Sending report (payload has 228 bytes)...
    I: 412248 [IN]Prepared secure message 0x2002f0d0 to 0xFFFFFFFB00000000 (0)  of type 0x5 and protocolId (0, 1) on exchange 49032r with MessageCounter:15252699.
    I: 412262 [IN]Sending encrypted msg 0x2002f0d0 with MessageCounter:152526994 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000064A66 msec
    D: 412275 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
    D: 412282 [DMG]<RE> OnReportConfirm: NumReports = 0
    D: 412287 [DMG]<RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages
    D: 412294 [DMG]IM RH moving to [AwaitingDestruction]
    D: 412299 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet
    D: 412577 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 412585 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 21)
    D: 412713 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 412721 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 412729 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:164278657 on exchange 49033r
    D: 412739 [EM]Handling via exchange: 49033r, Delegate: 0x2000f5cc
    D: 412745 [DMG]Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000
    I: 412753 [FS]GeneralCommissioning: Received ArmFailSafe (60s)
    D: 412759 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 848f1f2b
    D: 412765 [DMG]Command handler moving to [ Preparing]
    D: 412770 [DMG]Command handler moving to [AddingComm]
    D: 412775 [DMG]Command handler moving to [AddedComma]
    D: 412780 [DMG]Decreasing reference count for CommandHandler, remaining 0
    I: 412787 [IN]Prepared secure message 0x2002ef98 to 0xFFFFFFFB00000000 (0)  of type 0x9 and protocolId (0, 1) on exchange 49033r with MessageCounter:15252699.
    I: 412801 [IN]Sending encrypted msg 0x2002ef98 with MessageCounter:152526995 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000064C81 msec
    D: 412814 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
    D: 412822 [DMG]Command handler moving to [CommandSen]
    D: 412826 [DMG]Command handler moving to [AwaitingDe]
    E: 412831 [DL]Long dispatch time: 110 ms, for event type 16388
    D: 412938 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 413028 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 413036 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:164278658 on exchange 49034r
    D: 413046 [EM]Handling via exchange: 49034r, Delegate: 0x2000f5cc
    D: 413052 [DMG]Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0002
    D: 413078 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 848f1f2c
    D: 413085 [DMG]Command handler moving to [ Preparing]
    D: 413089 [DMG]Command handler moving to [AddingComm]
    D: 413094 [DMG]Command handler moving to [AddedComma]
    D: 413099 [DMG]Decreasing reference count for CommandHandler, remaining 0
    I: 413106 [IN]Prepared secure message 0x2002ef98 to 0xFFFFFFFB00000000 (0)  of type 0x9 and protocolId (0, 1) on exchange 49034r with MessageCounter:15252699.
    I: 413121 [IN]Sending encrypted msg 0x2002ef98 with MessageCounter:152526996 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000064DC1 msec
    D: 413134 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
    D: 413141 [DMG]Command handler moving to [CommandSen]
    D: 413146 [DMG]Command handler moving to [AwaitingDe]
    E: 413151 [DL]Long dispatch time: 123 ms, for event type 16388
    D: 413208 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 413216 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 413224 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:164278659 on exchange 49035r
    D: 413234 [EM]Handling via exchange: 49035r, Delegate: 0x2000f5cc
    D: 413241 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002
    I: 413248 [ZCL]OpCreds: Certificate Chain request received for PAI
    D: 413254 [DMG]Command handler moving to [ Preparing]
    D: 413259 [DMG]Command handler moving to [AddingComm]
    D: 413264 [DMG]Command handler moving to [AddedComma]
    D: 413269 [DMG]Decreasing reference count for CommandHandler, remaining 0
    I: 413278 [IN]Prepared secure message 0x2002ef98 to 0xFFFFFFFB00000000 (0)  of type 0x9 and protocolId (0, 1) on exchange 49035r with MessageCounter:15252699.
    I: 413292 [IN]Sending encrypted msg 0x2002ef98 with MessageCounter:152526997 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000064E6C msec
    D: 413305 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
    D: 413313 [DMG]Command handler moving to [CommandSen]
    D: 413318 [DMG]Command handler moving to [AwaitingDe]
    E: 413322 [DL]Long dispatch time: 106 ms, for event type 16388
    D: 413388 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 413395 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
    D: 413523 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 413530 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 48)
    D: 413658 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 413666 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 413674 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:164278660 on exchange 49036r
    D: 413684 [EM]Handling via exchange: 49036r, Delegate: 0x2000f5cc
    D: 413690 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002
    I: 413698 [ZCL]OpCreds: Certificate Chain request received for DAC
    D: 413704 [DMG]Command handler moving to [ Preparing]
    D: 413709 [DMG]Command handler moving to [AddingComm]
    D: 413714 [DMG]Command handler moving to [AddedComma]
    D: 413719 [DMG]Decreasing reference count for CommandHandler, remaining 0
    I: 413728 [IN]Prepared secure message 0x2002ef98 to 0xFFFFFFFB00000000 (0)  of type 0x9 and protocolId (0, 1) on exchange 49036r with MessageCounter:15252699.
    I: 413742 [IN]Sending encrypted msg 0x2002ef98 with MessageCounter:152526998 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000006502E msec
    D: 413755 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
    D: 413763 [DMG]Command handler moving to [CommandSen]
    D: 413767 [DMG]Command handler moving to [AwaitingDe]
    E: 413772 [DL]Long dispatch time: 106 ms, for event type 16388
    D: 413838 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 413845 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
    D: 413928 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 413935 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 77)
    D: 414018 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 414026 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 414034 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:164278661 on exchange 49037r
    D: 414044 [EM]Handling via exchange: 49037r, Delegate: 0x2000f5cc
    D: 414051 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0000
    I: 414058 [ZCL]OpCreds: Received an AttestationRequest command
    I: 414094 [ZCL]OpCreds: AttestationRequest successful.
    D: 414099 [DMG]Command handler moving to [ Preparing]
    D: 414104 [DMG]Command handler moving to [AddingComm]
    D: 414109 [DMG]Command handler moving to [AddedComma]
    D: 414114 [DMG]Decreasing reference count for CommandHandler, remaining 0
    I: 414124 [IN]Prepared secure message 0x2002ef98 to 0xFFFFFFFB00000000 (0)  of type 0x9 and protocolId (0, 1) on exchange 49037r with MessageCounter:15252699.
    I: 414138 [IN]Sending encrypted msg 0x2002ef98 with MessageCounter:152526999 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000000651BA msec
    D: 414151 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
    D: 414159 [DMG]Command handler moving to [CommandSen]
    D: 414164 [DMG]Command handler moving to [AwaitingDe]
    E: 414168 [DL]Long dispatch time: 142 ms, for event type 16388
    D: 414243 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 414250 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
    D: 414333 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 414340 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 237)
    D: 414467 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 414513 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 414521 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:164278662 on exchange 49038r
    D: 414531 [EM]Handling via exchange: 49038r, Delegate: 0x2000f5cc
    D: 414538 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0004
    I: 414545 [ZCL]OpCreds: Received a CSRRequest command
    D: 414550 [ZCL]OpCreds: Finding fabric with fabricIndex 0x0
    I: 414752 [ZCL]OpCreds: AllocatePendingOperationalKey succeeded
    I: 414788 [ZCL]OpCreds: CSRRequest successful.
    D: 414792 [DMG]Command handler moving to [ Preparing]
    D: 414797 [DMG]Command handler moving to [AddingComm]
    D: 414801 [DMG]Command handler moving to [AddedComma]
    D: 414806 [DMG]Decreasing reference count for CommandHandler, remaining 0
    I: 414815 [IN]Prepared secure message 0x2002ef98 to 0xFFFFFFFB00000000 (0)  of type 0x9 and protocolId (0, 1) on exchange 49038r with MessageCounter:15252700.
    I: 414829 [IN]Sending encrypted msg 0x2002ef98 with MessageCounter:152527000 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000006546D msec
    D: 414842 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
    D: 414850 [DMG]Command handler moving to [CommandSen]
    D: 414854 [DMG]Command handler moving to [AwaitingDe]
    E: 414859 [DL]Long dispatch time: 346 ms, for event type 16388
    D: 414918 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 414925 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 138)
    D: 415008 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 415055 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    D: 415143 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 415152 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:164278663 on exchange 49039r
    D: 415162 [EM]Handling via exchange: 49039r, Delegate: 0x2000f5cc
    D: 415168 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B
    I: 415176 [ZCL]OpCreds: Received an AddTrustedRootCertificate command
    I: 415239 [ZCL]OpCreds: AddTrustedRootCertificate successful.
    D: 415244 [DMG]Command handler moving to [ Preparing]
    D: 415249 [DMG]Command handler moving to [AddingComm]
    D: 415254 [DMG]Command handler moving to [AddedComma]
    D: 415259 [DMG]Decreasing reference count for CommandHandler, remaining 0
    I: 415266 [IN]Prepared secure message 0x2002ef98 to 0xFFFFFFFB00000000 (0)  of type 0x9 and protocolId (0, 1) on exchange 49039r with MessageCounter:15252700.
    I: 415280 [IN]Sending encrypted msg 0x2002ef98 with MessageCounter:152527001 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000065630 msec
    D: 415293 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 68)
    D: 415300 [DMG]Command handler moving to [CommandSen]
    D: 415305 [DMG]Command handler moving to [AwaitingDe]
    E: 415310 [DL]Long dispatch time: 167 ms, for event type 16388
    D: 415413 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 415458 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    D: 415548 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 415557 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:164278664 on exchange 49040r
    D: 415567 [EM]Handling via exchange: 49040r, Delegate: 0x2000f5cc
    D: 415574 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0006
    I: 415582 [ZCL]OpCreds: Received an AddNOC command
    I: 415588 [FP]Validating NOC chain
    I: 415649 [FP]NOC chain validation successful
    I: 415653 [FP]Added new fabric at index: 0x1
    I: 415657 [FP]Assigned compressed fabric ID: 0x66E25C03E0B81285, node ID: 0x000000000000000B
    I: 415665 [TS]Last Known Good Time: 2022-10-05T09:18:27
    I: 415670 [TS]New proposed Last Known Good Time: 2021-06-10T00:00:00
    I: 415676 [TS]Retaining current Last Known Good Time
    D: 415681 [DMG]Endpoint 0, Cluster 0x0000_003E update version to e42e51dc
    D: 415688 [DMG]Endpoint 0, Cluster 0x0000_003E update version to e42e51dd
    D: 415728 [EVL]LogEvent event number: 0x0000000000050002 priority: 1, endpoint id:  0x0 cluster id: 0x0000_001F event id: 0x0 Sys timestamp: 0x000000000006570
    I: 415742 [ZCL]OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0x000000000001B669
    D: 415751 [DL]Using Thread extended MAC for hostname.
    I: 415756 [DIS]Advertise operational node 66E25C03E0B81285-000000000000000B
    D: 415762 [DMG]Endpoint 0, Cluster 0x0000_003E update version to e42e51de
    D: 415769 [DMG]Endpoint 0, Cluster 0x0000_003E update version to e42e51df
    D: 415776 [DMG]Command handler moving to [ Preparing]
    D: 415781 [DMG]Command handler moving to [AddingComm]
    D: 415785 [DMG]Command handler moving to [AddedComma]
    I: 415790 [ZCL]OpCreds: successfully created fabric index 0x1 via AddNOC
    D: 415797 [DMG]Decreasing reference count for CommandHandler, remaining 0
    I: 415804 [IN]Prepared secure message 0x2002ef98 to 0xFFFFFFFB00000000 (1)  of type 0x9 and protocolId (0, 1) on exchange 49040r with MessageCounter:15252700.
    I: 415818 [IN]Sending encrypted msg 0x2002ef98 with MessageCounter:152527002 to 0xFFFFFFFB00000000 (1) at monotonic time: 000000000006584A msec
    D: 415831 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
    D: 415839 [DMG]Command handler moving to [CommandSen]
    D: 415843 [DMG]Command handler moving to [AwaitingDe]
    E: 415848 [DL]Long dispatch time: 300 ms, for event type 16388
    D: 415953 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 415961 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 415969 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:164278665 on exchange 49041r
    D: 415979 [EM]Handling via exchange: 49041r, Delegate: 0x2000f5cc
    D: 415986 [DMG]Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0003
    D: 416002 [DMG]Command handler moving to [ Preparing]
    D: 416007 [DMG]Command handler moving to [AddingComm]
    D: 416011 [DMG]Command handler moving to [AddedComma]
    D: 416016 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 848f1f2d
    D: 416023 [DMG]Decreasing reference count for CommandHandler, remaining 0
    I: 416030 [IN]Prepared secure message 0x2002ef98 to 0xFFFFFFFB00000000 (1)  of type 0x9 and protocolId (0, 1) on exchange 49041r with MessageCounter:15252700.
    I: 416045 [IN]Sending encrypted msg 0x2002ef98 with MessageCounter:152527003 to 0xFFFFFFFB00000000 (1) at monotonic time: 000000000006592D msec
    D: 416057 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
    D: 416065 [DMG]Command handler moving to [CommandSen]
    D: 416070 [DMG]Command handler moving to [AwaitingDe]
    E: 416075 [DL]Long dispatch time: 114 ms, for event type 16388
    D: 416133 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 416141 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 416149 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:164278666 on exchange 49042r
    D: 416159 [EM]Handling via exchange: 49042r, Delegate: 0x2000f5cc
    D: 416165 [DMG]Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0006
    D: 416186 [DMG]Decreasing reference count for CommandHandler, remaining 1
    D: 416192 [DL]OpenThread State Changed (Flags: 0x1006c100)
    D: 416198 [DL]   Network Name: OpenThread
    D: 416201 [DL]   PAN Id: 0x5137
    D: 416204 [DL]   Extended PAN Id: 0x87ED341D9DEC80E4
    D: 416209 [DL]   Channel: 18
    D: 416212 [DL]   Mesh Prefix: fdde:ad00:beef::/64
    D: 416217 [DL]OpenThread State Changed (Flags: 0x1100101d)
    D: 416222 [DL]   Device Role: DETACHED
    D: 416226 [DL]   Thread Unicast Addresses:
    D: 416230 [DL]        fdde:ad00:beef:0:6604:7f8a:124f:ab0d/64 valid
    D: 416236 [DL]        fe80::d0c3:a0fc:c55b:8d3a/64 valid preferred
    D: 418649 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
    D: 418787 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 421308 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    D: 423816 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
    D: 424007 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 426527 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    D: 426540 [DL]OpenThread State Changed (Flags: 0x0000b017)
    D: 426545 [DL]   Device Role: DETACHED
    D: 426548 [DL]   Network Name: OpenThread
    D: 426552 [DL]   PAN Id: 0x1411
    D: 426555 [DL]   Extended PAN Id: 0x87ED341D9DEC80E4
    D: 426560 [DL]   Channel: 18
    D: 426562 [DL]   Mesh Prefix: fdde:ad00:beef::/64
    D: 426567 [DL]   Thread Unicast Addresses:
    D: 426571 [DL]        fdde:ad00:beef:0:6604:7f8a:124f:ab0d/64 valid
    D: 426577 [DL]        fe80::d0c3:a0fc:c55b:8d3a/64 valid preferred
    I: 428050 [DL]SRP Client was started, detected server: fd70:2607:fbec:b10c:7a6f:774a:512d:4358
    D: 428059 [DL]OpenThread State Changed (Flags: 0x301932b7)
    D: 428233 [DL]   Device Role: CHILD
    D: 428236 [DL]   Network Name: OpenThread-1411
    D: 428242 [DL]   PAN Id: 0x1411
    D: 428245 [DL]   Extended PAN Id: 0x87ED341D9DEC80E4
    D: 428250 [DL]   Channel: 18
    D: 428253 [DL]   Mesh Prefix: fd70:2607:fbec:b10c::/64
    D: 428259 [DL]   Partition Id: 0x1F1DB766
    D: 428263 [DL]   Thread Unicast Addresses:
    D: 428266 [DL]        fd6c:1211:8162:1:c44:b5b1:e907:5c60/64 valid preferred
    D: 428274 [DL]        fd70:2607:fbec:b10c:0:ff:fe00:c01/64 valid rloc
    D: 428280 [DL]        fd70:2607:fbec:b10c:6604:7f8a:124f:ab0d/64 valid
    D: 428287 [DL]        fe80::d0c3:a0fc:c55b:8d3a/64 valid preferred
    E: 428337 [DL]Long dispatch time: 278 ms, for event type 32777
    D: 428343 [DL]OpenThread State Changed (Flags: 0x00000001)
    D: 428349 [DL]   Thread Unicast Addresses:
    D: 428353 [DL]        fd6c:1211:8162:1:c44:b5b1:e907:5c60/64 valid preferred
    D: 428362 [DL]        fd70:2607:fbec:b10c:0:ff:fe00:c01/64 valid rloc
    D: 428368 [DL]        fd70:2607:fbec:b10c:6604:7f8a:124f:ab0d/64 valid
    D: 428375 [DL]        fe80::d0c3:a0fc:c55b:8d3a/64 valid preferred
    D: 428382 [DMG]Command handler moving to [ Preparing]
    D: 428387 [DMG]Command handler moving to [AddingComm]
    D: 428393 [DMG]Command handler moving to [AddedComma]
    D: 428398 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 848f1f2e
    D: 428405 [DMG]Decreasing reference count for CommandHandler, remaining 0
    I: 428414 [IN]Prepared secure message 0x2002f188 to 0xFFFFFFFB00000000 (1)  of type 0x9 and protocolId (0, 1) on exchange 49042r with MessageCounter:15252700.
    I: 428429 [IN]Sending encrypted msg 0x2002f188 with MessageCounter:152527004 to 0xFFFFFFFB00000000 (1) at monotonic time: 000000000006898D msec
    D: 428443 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 70)
    D: 428451 [DMG]Command handler moving to [CommandSen]
    D: 428456 [DMG]Command handler moving to [AwaitingDe]
    D: 428460 [DL]Using Thread extended MAC for hostname.
    I: 428466 [DIS]Advertise operational node 66E25C03E0B81285-000000000000000B
    I: 428472 [SVR]Operational advertising enabled
    D: 428507 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 428528 [DL]SRP update succeeded
    I: 428531 [DIS]Setting operational delegate post init
    I: 428539 [SWU]Stopping the watchdog timer
    I: 428543 [SWU]Starting the periodic query timer, timeout: 86400 seconds
    I: 428549 [DIS]Updating services using commissioning mode 0
    D: 428555 [DL]Using Thread extended MAC for hostname.
    I: 428560 [DIS]Advertise operational node 66E25C03E0B81285-000000000000000B
    I: 428567 [DL]advertising srp service: 66E25C03E0B81285-000000000000000B._matter._tcp
    D: 428575 [DL]Using Thread extended MAC for hostname.
    I: 428580 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=0
    I: 428626 [DL]advertising srp service: 0F4869A6508596A3._matterc._udp
    D: 428633 [DMG]Endpoint 0, Cluster 0x0000_002A update version to ffb35b25
    D: 428640 [DMG]Endpoint 0, Cluster 0x0000_002A update version to ffb35b26
    D: 429534 [DL]SRP update succeeded
    D: 431027 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    D: 433535 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
    D: 433637 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 436157 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    D: 438665 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
    D: 438767 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 441287 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    D: 443794 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
    D: 443852 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 446372 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    D: 448879 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
    D: 448982 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 451502 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    D: 454010 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
    D: 454067 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 456587 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    D: 459095 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
    D: 459152 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 461672 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    D: 464180 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
    D: 464282 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 466802 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    D: 469309 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
    D: 469412 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 471932 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 472759 [FS]Fail-safe timer expired
    E: 472763 [SVR]Failsafe timer expired
    D: 472766 [IN]SecureSession[0x20003570]: MarkForEviction Type:1 LSID:63222
    I: 472773 [SC]SecureSession[0x20003570]: Moving from state 'kActive' --> 'kPendingEviction'
    D: 472781 [IN]SecureSession[0x20003570]: Released - Type:1 LSID:63222
    E: 472788 [SVR]Commissioning failed (attempt 1): 32
    D: 472792 [IN]Clearing BLE pending packets.
    I: 472796 [BLE]Releasing end point's BLE connection back to application.
    I: 472803 [DL]Closing BLE GATT connection (ConnId 00)
    D: 472810 [IN]SecureSession[0x20003570]: Allocated Type:1 LSID:63224
    D: 472816 [SC]Assigned local session key ID 63224
    D: 472821 [SC]Waiting for PBKDF param request
    D: 472825 [DL]CHIPoBLE advertising set to on
    I: 472829 [DIS]Updating services using commissioning mode 1
    D: 472834 [DL]Using Thread extended MAC for hostname.
    I: 472839 [DIS]Advertise operational node 66E25C03E0B81285-000000000000000B
    D: 472846 [DL]Using Thread extended MAC for hostname.
    I: 472852 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1
    I: 472862 [DL]advertising srp service: 0F4869A6508596A3._matterc._udp
    E: 472868 [ZCL]OpCreds: Got FailSafeTimerExpired
    E: 472872 [ZCL]OpCreds: Proceeding to FailSafeCleanup on fail-safe expiry!
    D: 472916 [IN]Expiring all sessions for fabric 0x1!!
    E: 472920 [FP]Reverting pending fabric data for fabric 0x1
    D: 472926 [EVL]LogEvent event number: 0x0000000000050003 priority: 1, endpoint id:  0x0 cluster id: 0x0000_0028 event id: 0x2 Sys timestamp: 0x00000000000737E
    D: 472940 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet
    E: 472947 [FP]Warning: metadata not found during delete of fabric 0x1
    I: 473024 [FP]Fabric (0x1) deleted.
    I: 473028 [ZCL]OpCreds: Fabric index 0x1 was removed
    D: 473033 [DMG]Endpoint 0, Cluster 0x0000_003E update version to e42e51e0
    D: 473040 [DMG]Endpoint 0, Cluster 0x0000_003E update version to e42e51e1
    I: 473166 [TS]Pending Last Known Good Time: 2022-10-05T09:18:27
    I: 473173 [TS]Previous Last Known Good Time: 2022-10-05T09:18:27
    I: 473178 [TS]Reverted Last Known Good Time to previous value
    D: 473184 [EVL]LogEvent event number: 0x0000000000050004 priority: 1, endpoint id:  0x0 cluster id: 0x0000_0028 event id: 0x2 Sys timestamp: 0x000000000007380
    D: 473198 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet
    E: 473205 [FP]Warning: metadata not found during delete of fabric 0x1
    E: 473213 [ZCL]OpCreds: failed to delete fabric at index 1: d8
    D: 473219 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 848f1f2f
    D: 473226 [ZCL]Failsafe timeout, tell platform driver to revert network credentials.
    I: 473233 [NP]Reverting Thread operational dataset
    E: 473244 [DL]Long dispatch time: 481 ms, for event type 32782
    I: 473250 [FS]Fail-safe cleanly disarmed
    D: 473255 [DL]OpenThread State Changed (Flags: 0x11002046)
    D: 473260 [DL]   Device Role: DISABLED
    D: 473263 [DL]   Thread Unicast Addresses:
    D: 473267 [DL]        fd6c:1211:8162:1:c44:b5b1:e907:5c60/64 valid preferred
    I: 473275 [DL]BLE GAP connection terminated (reason 0x16)
    I: 473280 [DL]Current number of connections: 0/1
    I: 473286 [DL]CHIPoBLE advertising started
    I: 473291 [DL]NFC Tag emulation started
    I: 503290 [DL]CHIPoBLE advertising mode changed to slow
    

  • Can you also provide a sniffer trace of the 802.15.4 traffic on air using the nRF Sniffer for 802.15.4?

  • I tried to build the nRF Sniffer for 802.15.4 on Windows using a nRF52840DK.

    I followed the guide at https://infocenter.nordicsemi.com/pdf/nRF_Sniffer_802154_User_Guide_v0.7.2.pdf, but  at paragraph 4.2.1 running the suggested command i do not see the interface of the sniffer (and then also on wireshark).

    Here is what i get on the terminal: 

  • Did you flash a DK or a Dongle with the sniffer firmware and connect this to the PC before running the command? I highly recommend using the Dongle, or the native nRF_USB on the DK with the sniffer, the UART option over the interface MCU on the DKs might have some issues. 

    Have you restarted your PC after installing Wireshark or the sniffer?

    If nothing of this works, please try downgrading the Python version to v3.8.x.

Related