$ sudo ./chip-tool-release pairing ble-thread 1 hex:0e080000000000010000000300000f35060004001fffe0020811111111222222220708fda55b6b5f370b59051000112233445566778899aabbccddeeff030e4f70656e54687265616444656d6f010212340410445f2b5ca6f2a93a55ce570a70efeecb0c0402a0f7f8 20202021 3840
[1652085532.353873][9875:9875] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-Mh5M9U)
[1652085532.354802][9875:9875] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1652085532.354892][9875:9875] CHIP:DL: NVS set: chip-counters/reboot-count = 9 (0x9)
[1652085532.355788][9875:9875] CHIP:DL: Got Ethernet interface: eth0
[1652085532.356296][9875:9875] CHIP:DL: Found the primary Ethernet interface:eth0
[1652085532.356780][9875:9875] CHIP:DL: Got WiFi interface: wlan0
[1652085532.359259][9875:9875] CHIP:DL: Found the primary WiFi interface:wlan0
[1652085532.359714][9875:9875] CHIP:IN: Loading from storage for fabric index 1
[1652085532.364012][9875:9875] CHIP:IN: Loading from storage for fabric index 2
[1652085532.365015][9875:9875] CHIP:IN: Loading from storage for fabric index 3
[1652085532.366089][9875:9875] CHIP:IN: Loading from storage for fabric index 4
[1652085532.366200][9875:9875] CHIP:IN: Loading from storage for fabric index 5
[1652085532.366288][9875:9875] CHIP:IN: Loading from storage for fabric index 6
[1652085532.366382][9875:9875] CHIP:IN: Loading from storage for fabric index 7
[1652085532.366514][9875:9875] CHIP:IN: Loading from storage for fabric index 8
[1652085532.366621][9875:9875] CHIP:IN: Loading from storage for fabric index 9
[1652085532.366731][9875:9875] CHIP:IN: Loading from storage for fabric index 10
[1652085532.366825][9875:9875] CHIP:IN: Loading from storage for fabric index 11
[1652085532.366914][9875:9875] CHIP:IN: Loading from storage for fabric index 12
[1652085532.367004][9875:9875] CHIP:IN: Loading from storage for fabric index 13
[1652085532.367115][9875:9875] CHIP:IN: Loading from storage for fabric index 14
[1652085532.367210][9875:9875] CHIP:IN: Loading from storage for fabric index 15
[1652085532.367299][9875:9875] CHIP:IN: Loading from storage for fabric index 16
[1652085532.367733][9875:9875] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-ucV4fU)
[1652085532.368597][9875:9875] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1652085532.368682][9875:9875] CHIP:DL: NVS set: chip-counters/GlobalMCTR = 9000 (0x2328)
[1652085532.373344][9875:9875] CHIP:ZCL: Using ZAP configuration...
[1652085532.378914][9875:9875] CHIP:DL: Avahi client registered
[1652085532.380722][9875:9875] CHIP:CTL: Setting attestation nonce to random value
[1652085532.380812][9875:9875] CHIP:CTL: Setting CSR nonce to random value
[1652085532.380964][9875:9875] CHIP:CTL: Setting attestation nonce to random value
[1652085532.381023][9875:9875] CHIP:CTL: Setting CSR nonce to random value
[1652085532.382589][9875:9875] CHIP:CTL: Generating NOC
[1652085532.384049][9875:9875] CHIP:DIS: Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage
[1652085532.384355][9875:9875] CHIP:DIS: Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage
[1652085532.384780][9875:9875] CHIP:DIS: Verifying the received credentials
[1652085532.387724][9875:9875] CHIP:DIS: Added new fabric at index: 1, Initialized: 1
[1652085532.387795][9875:9875] CHIP:DIS: Assigned compressed fabric ID: 0xFD744A7D5E7C34C8, node ID: 0x000000000001B669
[1652085532.387836][9875:9875] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0xFD744A7D5E7C34C8
[1652085532.388014][9875:9875] CHIP:CTL: Setting attestation nonce to random value
[1652085532.388155][9875:9875] CHIP:CTL: Setting CSR nonce to random value
[1652085532.389601][9875:9875] CHIP:CTL: Generating NOC
[1652085532.390925][9875:9875] CHIP:DIS: Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage
[1652085532.391043][9875:9875] CHIP:DIS: Fabric (2) loaded from storage. Calling OnFabricRetrievedFromStorage
[1652085532.391133][9875:9875] CHIP:DIS: Fabric (2) loaded from storage. Calling OnFabricRetrievedFromStorage
[1652085532.391459][9875:9875] CHIP:DIS: Verifying the received credentials
[1652085532.394516][9875:9875] CHIP:DIS: Added new fabric at index: 2, Initialized: 1
[1652085532.394591][9875:9875] CHIP:DIS: Assigned compressed fabric ID: 0xFC354AF27321C0C0, node ID: 0x000000000001B669
[1652085532.394679][9875:9875] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0xFC354AF27321C0C0
[1652085532.394867][9875:9875] CHIP:CTL: Setting attestation nonce to random value
[1652085532.395025][9875:9875] CHIP:CTL: Setting CSR nonce to random value
[1652085532.396598][9875:9875] CHIP:CTL: Generating NOC
[1652085532.398043][9875:9875] CHIP:DIS: Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage
[1652085532.398243][9875:9875] CHIP:DIS: Fabric (2) loaded from storage. Calling OnFabricRetrievedFromStorage
[1652085532.398368][9875:9875] CHIP:DIS: Fabric (3) loaded from storage. Calling OnFabricRetrievedFromStorage
[1652085532.398518][9875:9875] CHIP:DIS: Fabric (3) loaded from storage. Calling OnFabricRetrievedFromStorage
[1652085532.398933][9875:9875] CHIP:DIS: Verifying the received credentials
[1652085532.402186][9875:9875] CHIP:DIS: Added new fabric at index: 3, Initialized: 1
[1652085532.402327][9875:9875] CHIP:DIS: Assigned compressed fabric ID: 0x7975A918FB5FA41A, node ID: 0x000000000001B669
[1652085532.402401][9875:9875] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0x7975A918FB5FA41A
[1652085532.456629][9875:9880] CHIP:IN: Prepared unauthenticated message 0x7f991cddd8 to 0x0000000000000000 (0)  of type 0x20 and protocolId (0, 0) on exchange 59055i with MessageCounter:514411863.
[1652085532.456774][9875:9880] CHIP:IN: Sending unauthenticated msg 0x7f991cddd8 with MessageCounter:514411863 to 0x0000000000000000 at monotonic time: 000000000EA3812D msec
[1652085532.457477][9875:9880] CHIP:CTL: Setting thread operational dataset from parameters
[1652085532.457536][9875:9880] CHIP:CTL: Setting attestation nonce to random value
[1652085532.457972][9875:9880] CHIP:CTL: Setting CSR nonce to random value
[1652085532.458235][9875:9880] CHIP:CTL: Commission called for node ID 0x0000000000000001
[1652085532.486485][9875:9878] CHIP:BLE: BLE removing known devices.
[1652085532.488821][9875:9878] CHIP:BLE: BLE initiating scan.
[1652085533.212875][9875:9878] CHIP:BLE: New device scanned: C2:98:19:62:AA:CC
[1652085533.213024][9875:9878] CHIP:BLE: Device discriminator match. Attempting to connect.
[1652085533.219852][9875:9878] CHIP:BLE: Scan complete notification without an active scan.
[1652085535.759026][9875:9880] CHIP:BLE: subscribe complete, ep = 0x556dc539b8
[1652085535.759280][9875:9880] CHIP:BLE: peripheral chose BTP version 4; central expected between 4 and 4
[1652085535.759328][9875:9880] CHIP:BLE: using BTP fragment sizes rx 20 / tx 20.
[1652085535.759412][9875:9880] CHIP:BLE: local and remote recv window size = 5
[1652085536.977639][9875:9880] CHIP:EM: Received message of type 0x21 with protocolId (0, 0) and MessageCounter:3704879279 on exchange 59055i
[1652085536.989515][9875:9880] CHIP:IN: Prepared unauthenticated message 0x7f991cd908 to 0x0000000000000000 (0)  of type 0x22 and protocolId (0, 0) on exchange 59055i with MessageCounter:514411864.
[1652085536.989615][9875:9880] CHIP:IN: Sending unauthenticated msg 0x7f991cd908 with MessageCounter:514411864 to 0x0000000000000000 at monotonic time: 000000000EA392E2 msec
[1652085539.822549][9875:9880] CHIP:EM: Received message of type 0x23 with protocolId (0, 0) and MessageCounter:3704879280 on exchange 59055i
[1652085539.829171][9875:9880] CHIP:IN: Prepared unauthenticated message 0x7f991cda48 to 0x0000000000000000 (0)  of type 0x24 and protocolId (0, 0) on exchange 59055i with MessageCounter:514411865.
[1652085539.829448][9875:9880] CHIP:IN: Sending unauthenticated msg 0x7f991cda48 with MessageCounter:514411865 to 0x0000000000000000 at monotonic time: 000000000EA39DF9 msec
[1652085540.407624][9875:9880] CHIP:EM: Received message of type 0x40 with protocolId (0, 0) and MessageCounter:3704879281 on exchange 59055i
[1652085540.408154][9875:9880] CHIP:CTL: Going from commissioning step 'SecurePairing' with lastErr = '../../src/controller/AutoCommissioner.cpp:253: Success' --> 'ReadCommissioningInfo'
[1652085540.408302][9875:9880] CHIP:CTL: Performing next commissioning step 'ReadCommissioningInfo' with completion status = '../../src/controller/CommissioningDelegate.h:341: Success'
[1652085540.408368][9875:9880] CHIP:CTL: Sending request for commissioning information
[1652085540.408929][9875:9880] CHIP:IN: Prepared secure message 0x7f991cd388 to 0x0000000000000001 (1)  of type 0x2 and protocolId (0, 1) on exchange 59056i with MessageCounter:2382648.
[1652085540.409046][9875:9880] CHIP:IN: Sending encrypted msg 0x7f991cd388 with MessageCounter:2382648 to 0x0000000000000001 (1) at monotonic time: 000000000EA3A03D msec
[1652085542.657511][9875:9880] CHIP:EM: Received message of type 0x5 with protocolId (0, 1) and MessageCounter:12758104 on exchange 59056i
[1652085542.661825][9875:9880] CHIP:CTL: Finished commissioning step 'ReadCommissioningInfo' with error '../../src/controller/CHIPDeviceController.cpp:1631: Success'
[1652085542.661997][9875:9880] CHIP:CTL: Going from commissioning step 'ReadCommissioningInfo' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1631: Success' --> 'ArmFailSafe'
[1652085542.662158][9875:9880] CHIP:CTL: Performing next commissioning step 'ArmFailSafe' with completion status = '../../src/controller/CHIPDeviceController.cpp:1631: Success'
[1652085542.662238][9875:9880] CHIP:CTL: Arming failsafe (60 seconds)
[1652085542.662651][9875:9880] CHIP:IN: Prepared secure message 0x7f991ccf48 to 0x0000000000000001 (1)  of type 0x8 and protocolId (0, 1) on exchange 59057i with MessageCounter:2382649.
[1652085542.662765][9875:9880] CHIP:IN: Sending encrypted msg 0x7f991ccf48 with MessageCounter:2382649 to 0x0000000000000001 (1) at monotonic time: 000000000EA3A90B msec
[1652085543.467777][9875:9880] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:12758105 on exchange 59057i
[1652085543.468356][9875:9880] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1652085543.468503][9875:9880] CHIP:CTL: Received ArmFailSafe response
[1652085543.468589][9875:9880] CHIP:CTL: Finished commissioning step 'ArmFailSafe' with error '../../src/controller/CHIPDeviceController.cpp:1783: Success'
[1652085543.468715][9875:9880] CHIP:CTL: Going from commissioning step 'ArmFailSafe' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1783: Success' --> 'ConfigRegulatory'
[1652085543.468896][9875:9880] CHIP:CTL: Performing next commissioning step 'ConfigRegulatory' with completion status = '../../src/controller/CHIPDeviceController.cpp:1783: Success'
[1652085543.469049][9875:9880] CHIP:CTL: Setting Regulatory Config
[1652085543.469197][9875:9880] CHIP:CTL: Device does not support configurable regulatory location
[1652085543.469480][9875:9880] CHIP:CTL: Unable to find country code, defaulting to XX
[1652085543.469974][9875:9880] CHIP:IN: Prepared secure message 0x7f991ccb08 to 0x0000000000000001 (1)  of type 0x8 and protocolId (0, 1) on exchange 59058i with MessageCounter:2382650.
[1652085543.470238][9875:9880] CHIP:IN: Sending encrypted msg 0x7f991ccb08 with MessageCounter:2382650 to 0x0000000000000001 (1) at monotonic time: 000000000EA3AC32 msec
[1652085544.277815][9875:9880] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:12758106 on exchange 59058i
[1652085544.278396][9875:9880] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0003
[1652085544.278525][9875:9880] CHIP:CTL: Received SetRegulatoryConfig response
[1652085544.278612][9875:9880] CHIP:CTL: Finished commissioning step 'ConfigRegulatory' with error '../../src/controller/CHIPDeviceController.cpp:1792: Success'
[1652085544.278701][9875:9880] CHIP:CTL: Going from commissioning step 'ConfigRegulatory' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1792: Success' --> 'SendPAICertificateRequest'
[1652085544.278782][9875:9880] CHIP:CTL: Performing next commissioning step 'SendPAICertificateRequest' with completion status = '../../src/controller/CHIPDeviceController.cpp:1792: Success'
[1652085544.278852][9875:9880] CHIP:CTL: Sending request for PAI certificate
[1652085544.279298][9875:9880] CHIP:IN: Prepared secure message 0x7f991cca68 to 0x0000000000000001 (1)  of type 0x8 and protocolId (0, 1) on exchange 59059i with MessageCounter:2382651.
[1652085544.279437][9875:9880] CHIP:IN: Sending encrypted msg 0x7f991cca68 with MessageCounter:2382651 to 0x0000000000000001 (1) at monotonic time: 000000000EA3AF5B msec
[1652085547.427826][9875:9880] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:12758107 on exchange 59059i
[1652085547.428382][9875:9880] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
[1652085547.428491][9875:9880] CHIP:CTL: Received certificate chain from the device
[1652085547.428616][9875:9880] CHIP:CTL: Finished commissioning step 'SendPAICertificateRequest' with error '../../src/controller/CHIPDeviceController.cpp:1127: Success'
[1652085547.428703][9875:9880] CHIP:CTL: Going from commissioning step 'SendPAICertificateRequest' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1127: Success' --> 'SendDACCertificateRequest'
[1652085547.428800][9875:9880] CHIP:CTL: Performing next commissioning step 'SendDACCertificateRequest' with completion status = '../../src/controller/CHIPDeviceController.cpp:1127: Success'
[1652085547.428872][9875:9880] CHIP:CTL: Sending request for DAC certificate
[1652085547.429275][9875:9880] CHIP:IN: Prepared secure message 0x7f991cca18 to 0x0000000000000001 (1)  of type 0x8 and protocolId (0, 1) on exchange 59060i with MessageCounter:2382652.
[1652085547.429520][9875:9880] CHIP:IN: Sending encrypted msg 0x7f991cca18 with MessageCounter:2382652 to 0x0000000000000001 (1) at monotonic time: 000000000EA3BBAA msec
[1652085550.667416][9875:9880] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:12758108 on exchange 59060i
[1652085550.668047][9875:9880] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
[1652085550.668441][9875:9880] CHIP:CTL: Received certificate chain from the device
[1652085550.668855][9875:9880] CHIP:CTL: Finished commissioning step 'SendDACCertificateRequest' with error '../../src/controller/CHIPDeviceController.cpp:1127: Success'
[1652085550.668945][9875:9880] CHIP:CTL: Going from commissioning step 'SendDACCertificateRequest' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1127: Success' --> 'SendAttestationRequest'
[1652085550.669021][9875:9880] CHIP:CTL: Performing next commissioning step 'SendAttestationRequest' with completion status = '../../src/controller/CHIPDeviceController.cpp:1127: Success'
[1652085550.669102][9875:9880] CHIP:CTL: Sending Attestation Request to the device.
[1652085550.670092][9875:9880] CHIP:IN: Prepared secure message 0x7f991cc9c8 to 0x0000000000000001 (1)  of type 0x8 and protocolId (0, 1) on exchange 59061i with MessageCounter:2382653.
[1652085550.670213][9875:9880] CHIP:IN: Sending encrypted msg 0x7f991cc9c8 with MessageCounter:2382653 to 0x0000000000000001 (1) at monotonic time: 000000000EA3C852 msec
[1652085554.897481][9875:9880] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:12758109 on exchange 59061i
[1652085554.897988][9875:9880] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0001
[1652085554.898183][9875:9880] CHIP:CTL: Received Attestation Information from the device
[1652085554.898810][9875:9880] CHIP:CTL: Finished commissioning step 'SendAttestationRequest' with error '../../src/controller/CHIPDeviceController.cpp:1162: Success'
[1652085554.900600][9875:9880] CHIP:CTL: Going from commissioning step 'SendAttestationRequest' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1162: Success' --> 'AttestationVerification'
[1652085554.901189][9875:9880] CHIP:CTL: Performing next commissioning step 'AttestationVerification' with completion status = '../../src/controller/CHIPDeviceController.cpp:1162: Success'
[1652085554.901896][9875:9880] CHIP:CTL: Verifying attestation
[1652085554.922918][9875:9880] CHIP:CTL: Successfully validated 'Attestation Information' command received from the device.
[1652085554.923062][9875:9880] CHIP:CTL: Finished commissioning step 'AttestationVerification' with error '../../src/controller/CHIPDeviceController.cpp:1194: Success'
[1652085554.923144][9875:9880] CHIP:CTL: Going from commissioning step 'AttestationVerification' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1194: Success' --> 'SendOpCertSigningRequest'
[1652085554.923213][9875:9880] CHIP:CTL: Performing next commissioning step 'SendOpCertSigningRequest' with completion status = '../../src/controller/CHIPDeviceController.cpp:1194: Success'
[1652085554.923916][9875:9880] CHIP:IN: Prepared secure message 0x7f991cbf78 to 0x0000000000000001 (1)  of type 0x8 and protocolId (0, 1) on exchange 59062i with MessageCounter:2382654.
[1652085554.924200][9875:9880] CHIP:IN: Sending encrypted msg 0x7f991cbf78 with MessageCounter:2382654 to 0x0000000000000001 (1) at monotonic time: 000000000EA3D8F0 msec
[1652085557.732168][9875:9880] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:12758110 on exchange 59062i
[1652085557.732737][9875:9880] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0005
[1652085557.733255][9875:9880] CHIP:CTL: Received certificate signing request from the device
[1652085557.733873][9875:9880] CHIP:CTL: Finished commissioning step 'SendOpCertSigningRequest' with error '../../src/controller/CHIPDeviceController.cpp:1243: Success'
[1652085557.734033][9875:9880] CHIP:CTL: Going from commissioning step 'SendOpCertSigningRequest' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1243: Success' --> 'GenerateNOCChain'
[1652085557.734116][9875:9880] CHIP:CTL: Performing next commissioning step 'GenerateNOCChain' with completion status = '../../src/controller/CHIPDeviceController.cpp:1243: Success'
[1652085557.734187][9875:9880] CHIP:CTL: Getting certificate chain for the device from the issuer
[1652085557.738798][9875:9880] CHIP:CTL: Verifying Certificate Signing Request
[1652085557.743663][9875:9880] CHIP:CTL: Generating NOC
[1652085557.745297][9875:9880] CHIP:CTL: Providing certificate chain to the commissioner
[1652085557.745407][9875:9880] CHIP:CTL: Received callback from the CA for NOC Chain generation. Status ../../src/controller/ExampleOperationalCredentialsIssuer.cpp:229: Success
[1652085557.745510][9875:9880] CHIP:CTL: Finished commissioning step 'GenerateNOCChain' with error '../../src/controller/ExampleOperationalCredentialsIssuer.cpp:229: Success'
[1652085557.746430][9875:9880] CHIP:CTL: Performing next commissioning step 'SendTrustedRootCert' with completion status = '../../src/controller/CHIPDeviceController.cpp:1243: Success'
[1652085557.746517][9875:9880] CHIP:CTL: Sending root certificate to the device
[1652085557.748540][9875:9880] CHIP:IN: Prepared secure message 0x7f991cbd58 to 0x0000000000000001 (1)  of type 0x8 and protocolId (0, 1) on exchange 59063i with MessageCounter:2382655.
[1652085557.748680][9875:9880] CHIP:IN: Sending encrypted msg 0x7f991cbd58 with MessageCounter:2382655 to 0x0000000000000001 (1) at monotonic time: 000000000EA3E3F9 msec
[1652085557.749826][9875:9880] CHIP:CTL: Sent root certificate to the device
[1652085559.622673][9875:9880] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:12758111 on exchange 59063i
[1652085559.623245][9875:9880] CHIP:DMG: Received Command Response Status for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B Status=0x0
[1652085559.623356][9875:9880] CHIP:CTL: Device confirmed that it has received the root certificate
[1652085559.623441][9875:9880] CHIP:CTL: Finished commissioning step 'SendTrustedRootCert' with error '../../src/controller/CHIPDeviceController.cpp:1414: Success'
[1652085559.623570][9875:9880] CHIP:CTL: Going from commissioning step 'SendTrustedRootCert' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1414: Success' --> 'SendNOC'
[1652085559.623661][9875:9880] CHIP:CTL: Performing next commissioning step 'SendNOC' with completion status = '../../src/controller/CHIPDeviceController.cpp:1414: Success'
[1652085559.624094][9875:9880] CHIP:IN: Prepared secure message 0x7f991cc9f8 to 0x0000000000000001 (1)  of type 0x8 and protocolId (0, 1) on exchange 59064i with MessageCounter:2382656.
[1652085559.624211][9875:9880] CHIP:IN: Sending encrypted msg 0x7f991cc9f8 with MessageCounter:2382656 to 0x0000000000000001 (1) at monotonic time: 000000000EA3EB4C msec
[1652085559.624538][9875:9880] CHIP:CTL: Sent operational certificate to the device
[1652085563.357615][9875:9880] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:12758112 on exchange 59064i
[1652085563.358353][9875:9880] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0008
[1652085563.358723][9875:9880] CHIP:CTL: Device returned status 0 on receiving the NOC
[1652085563.358916][9875:9880] CHIP:CTL: Operational credentials provisioned on device 0x7f84001730
[1652085563.359149][9875:9880] CHIP:TOO: Secure Pairing Success
[1652085563.359350][9875:9880] CHIP:CTL: Finished commissioning step 'SendNOC' with error '../../src/controller/CHIPDeviceController.cpp:1440: Success'
[1652085563.359625][9875:9880] CHIP:CTL: Going from commissioning step 'SendNOC' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1440: Success' --> 'ThreadNetworkSetup'
[1652085563.359823][9875:9880] CHIP:CTL: Performing next commissioning step 'ThreadNetworkSetup' with completion status = '../../src/controller/CHIPDeviceController.cpp:1440: Success'
[1652085563.360346][9875:9880] CHIP:IN: Prepared secure message 0x7f991cca28 to 0x0000000000000001 (1)  of type 0x8 and protocolId (0, 1) on exchange 59065i with MessageCounter:2382657.
[1652085563.360544][9875:9880] CHIP:IN: Sending encrypted msg 0x7f991cca28 with MessageCounter:2382657 to 0x0000000000000001 (1) at monotonic time: 000000000EA3F9E5 msec
[1652085564.617935][9875:9880] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:12758113 on exchange 59065i
[1652085564.618527][9875:9880] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0005
[1652085564.618968][9875:9880] CHIP:CTL: Received NetworkConfig response
[1652085564.619069][9875:9880] CHIP:CTL: Finished commissioning step 'ThreadNetworkSetup' with error '../../src/controller/CHIPDeviceController.cpp:1801: Success'
[1652085564.619151][9875:9880] CHIP:CTL: Going from commissioning step 'ThreadNetworkSetup' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1801: Success' --> 'ThreadNetworkEnable'
[1652085564.619227][9875:9880] CHIP:CTL: Performing next commissioning step 'ThreadNetworkEnable' with completion status = '../../src/controller/CHIPDeviceController.cpp:1801: Success'
[1652085564.620618][9875:9880] CHIP:IN: Prepared secure message 0x7f991ccb08 to 0x0000000000000001 (1)  of type 0x8 and protocolId (0, 1) on exchange 59066i with MessageCounter:2382658.
[1652085564.620773][9875:9880] CHIP:IN: Sending encrypted msg 0x7f991ccb08 with MessageCounter:2382658 to 0x0000000000000001 (1) at monotonic time: 000000000EA3FED1 msec
[1652085567.181515][9875:9880] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:12758114 on exchange 59066i
[1652085567.181834][9875:9880] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0007
[1652085567.181901][9875:9880] CHIP:CTL: Received ConnectNetwork response
[1652085567.181938][9875:9880] CHIP:CTL: Finished commissioning step 'ThreadNetworkEnable' with error '../../src/controller/CHIPDeviceController.cpp:1810: Success'
[1652085567.181970][9875:9880] CHIP:CTL: Going from commissioning step 'ThreadNetworkEnable' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1810: Success' --> 'FindOperational'
[1652085567.182007][9875:9880] CHIP:CTL: Performing next commissioning step 'FindOperational' with completion status = '../../src/controller/CHIPDeviceController.cpp:1810: Success'
[1652085567.182056][9875:9880] CHIP:DIS: Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage
[1652085567.182093][9875:9880] CHIP:DIS: Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage
[1652085567.182151][9875:9880] CHIP:DIS: Resolving FD744A7D5E7C34C8:0000000000000001 ...
[1652085567.184530][9875:9880] CHIP:DIS: Operational node lookup already in progress. Will NOT start a new one.
[1652085567.381731][9875:9880] CHIP:DIS: Checking node lookup status after 200 ms
[1652085568.156289][9875:9880] CHIP:DL: Avahi resolve found
[1652085568.156417][9875:9880] CHIP:DIS: Node ID resolved for FD744A7D5E7C34C8:0000000000000001
[1652085568.156461][9875:9880] CHIP:DIS:     Addr 0: [fd11:22::c3b6:32b5:509c:ae00]:5540
[1652085568.157472][9875:9880] CHIP:DIS: UDP:[fd11:22::c3b6:32b5:509c:ae00%wlan0]:5540: new best score: 6
[1652085568.157531][9875:9880] CHIP:DIS: Checking node lookup status after 976 ms
[1652085568.157674][9875:9880] CHIP:SC: Establishing CASE session to UDP:[fd11:22::c3b6:32b5:509c:ae00]:5540
[1652085568.158817][9875:9880] CHIP:IN: Prepared unauthenticated message 0x559ea7dc48 to 0x0000000000000000 (0)  of type 0x30 and protocolId (0, 0) on exchange 59067i with MessageCounter:514411866.
[1652085568.158910][9875:9880] CHIP:IN: Sending unauthenticated msg 0x559ea7dc48 with MessageCounter:514411866 to 0x0000000000000000 at monotonic time: 000000000EA40CA3 msec
[1652085568.159130][9875:9880] CHIP:SC: Sent Sigma1 msg
[1652085568.159455][9875:9880] CHIP:DIS: Discovery does not require any more timeouts
[1652085568.486673][9875:9878] CHIP:DL: Bluez notify CHIPoBluez connection disconnected
[1652085568.772760][9875:9880] CHIP:EM: Received message of type 0x31 with protocolId (0, 0) and MessageCounter:3704879282 on exchange 59067i
[1652085568.772971][9875:9880] CHIP:SC: Received Sigma2 msg
[1652085568.774441][9875:9880] CHIP:SC: The device does not support GetClock_RealTimeMS() API. This will eventually result in CASE session setup failures.
[1652085568.780310][9875:9880] CHIP:IN: Prepared unauthenticated message 0x559ea7dc48 to 0x0000000000000000 (0)  of type 0x32 and protocolId (0, 0) on exchange 59067i with MessageCounter:514411867.
[1652085568.780422][9875:9880] CHIP:IN: Sending unauthenticated msg 0x559ea7dc48 with MessageCounter:514411867 to 0x0000000000000000 at monotonic time: 000000000EA40F10 msec
[1652085568.780655][9875:9880] CHIP:SC: Sent Sigma3 msg
[1652085569.186575][9875:9880] CHIP:EM: Received message of type 0x40 with protocolId (0, 0) and MessageCounter:3704879283 on exchange 59067i
[1652085569.186740][9875:9880] CHIP:SC: Success status report received. Session was established
[1652085569.187223][9875:9880] CHIP:CTL: Finished commissioning step 'FindOperational' with error '../../src/controller/CHIPDeviceController.cpp:1575: Success'
[1652085569.187487][9875:9880] CHIP:CTL: Going from commissioning step 'FindOperational' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1575: Success' --> 'SendComplete'
[1652085569.187552][9875:9880] CHIP:CTL: Performing next commissioning step 'SendComplete' with completion status = '../../src/controller/CHIPDeviceController.cpp:1575: Success'
[1652085569.188099][9875:9880] CHIP:IN: Prepared secure message 0x559ea7dc48 to 0x0000000000000001 (1)  of type 0x8 and protocolId (0, 1) on exchange 59068i with MessageCounter:7691169.
[1652085569.188190][9875:9880] CHIP:IN: Sending encrypted msg 0x559ea7dc48 with MessageCounter:7691169 to 0x0000000000000001 (1) at monotonic time: 000000000EA410A8 msec
[1652085569.188837][9875:9880] CHIP:IN: Prepared unauthenticated message 0x7f991cda48 to 0x0000000000000000 (0)  of type 0x10 and protocolId (0, 0) on exchange 59067i with MessageCounter:514411868.
[1652085569.188936][9875:9880] CHIP:IN: Sending unauthenticated msg 0x7f991cda48 with MessageCounter:514411868 to 0x0000000000000000 at monotonic time: 000000000EA410A9 msec
[1652085569.294694][9875:9880] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:13854363 on exchange 59068i
[1652085569.295593][9875:9880] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0005
[1652085569.296067][9875:9880] CHIP:CTL: Received CommissioningComplete response
[1652085569.296138][9875:9880] CHIP:CTL: Finished commissioning step 'SendComplete' with error '../../src/controller/CHIPDeviceController.cpp:1819: Success'
[1652085569.296533][9875:9880] CHIP:CTL: Going from commissioning step 'SendComplete' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1819: Success' --> 'Cleanup'
[1652085569.296803][9875:9880] CHIP:CTL: Performing next commissioning step 'Cleanup' with completion status = '../../src/controller/CHIPDeviceController.cpp:1819: Success'
[1652085569.297058][9875:9880] CHIP:TOO: Device commissioning completed with success
[1652085569.297618][9875:9880] CHIP:CTL: Finished commissioning step 'Cleanup' with error '../../src/controller/CHIPDeviceController.cpp:2156: Success'
[1652085569.298034][9875:9880] CHIP:IN: Prepared secure message 0x7f991cda78 to 0x0000000000000001 (1)  of type 0x10 and protocolId (0, 0) on exchange 59068i with MessageCounter:7691170.
[1652085569.298325][9875:9880] CHIP:IN: Sending encrypted msg 0x7f991cda78 with MessageCounter:7691170 to 0x0000000000000001 (1) at monotonic time: 000000000EA41116 msec
[1652085569.301090][9875:9875] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.
[1652085569.301562][9875:9875] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-JVxlmT)
[1652085569.302653][9875:9875] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1652085569.302773][9875:9875] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1652085569.302810][9875:9875] CHIP:DL: Inet Layer shutdown
[1652085569.302840][9875:9875] CHIP:DL: BLE shutdown
[1652085569.304464][9875:9875] CHIP:DL: System Layer shutdown
pi@raspberrypi:~/matter $