$ sudo ./chip-tool-release pairing ble-thread 1 hex:0e080000000000010000000300000f35060004001fffe0020811111111222222220708fdb1035eae19b4b4051000112233445566778899aabbccddeeff030e4f70656e54687265616444656d6f010212340410445f2b5ca6f2a93a55ce570a70efeecb0c0402a0f7f8 20202021 3840 [1652085372.891668][465400:465400] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-TJw2lB) [1652085372.891793][465400:465400] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1652085372.891803][465400:465400] CHIP:DL: NVS set: chip-counters/reboot-count = 7 (0x7) [1652085372.891975][465400:465400] CHIP:DL: Got Ethernet interface: enp0s31f6 [1652085372.892096][465400:465400] CHIP:DL: Found the primary Ethernet interface:enp0s31f6 [1652085372.892219][465400:465400] CHIP:DL: Got WiFi interface: wlp1s0 [1652085372.893787][465400:465400] CHIP:DL: Found the primary WiFi interface:wlp1s0 [1652085372.893847][465400:465400] CHIP:IN: Loading from storage for fabric index 1 [1652085372.894721][465400:465400] CHIP:IN: Loading from storage for fabric index 2 [1652085372.894889][465400:465400] CHIP:IN: Loading from storage for fabric index 3 [1652085372.895047][465400:465400] CHIP:IN: Loading from storage for fabric index 4 [1652085372.895065][465400:465400] CHIP:IN: Loading from storage for fabric index 5 [1652085372.895079][465400:465400] CHIP:IN: Loading from storage for fabric index 6 [1652085372.895092][465400:465400] CHIP:IN: Loading from storage for fabric index 7 [1652085372.895106][465400:465400] CHIP:IN: Loading from storage for fabric index 8 [1652085372.895120][465400:465400] CHIP:IN: Loading from storage for fabric index 9 [1652085372.895133][465400:465400] CHIP:IN: Loading from storage for fabric index 10 [1652085372.895146][465400:465400] CHIP:IN: Loading from storage for fabric index 11 [1652085372.895160][465400:465400] CHIP:IN: Loading from storage for fabric index 12 [1652085372.895174][465400:465400] CHIP:IN: Loading from storage for fabric index 13 [1652085372.895209][465400:465400] CHIP:IN: Loading from storage for fabric index 14 [1652085372.895260][465400:465400] CHIP:IN: Loading from storage for fabric index 15 [1652085372.895274][465400:465400] CHIP:IN: Loading from storage for fabric index 16 [1652085372.895384][465400:465400] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-WyKB9x) [1652085372.895520][465400:465400] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1652085372.895532][465400:465400] CHIP:DL: NVS set: chip-counters/GlobalMCTR = 7000 (0x1B58) [1652085372.896000][465400:465400] CHIP:ZCL: Using ZAP configuration... [1652085372.897543][465400:465400] CHIP:DL: Avahi client registered [1652085372.897900][465400:465400] CHIP:CTL: Setting attestation nonce to random value [1652085372.897911][465400:465400] CHIP:CTL: Setting CSR nonce to random value [1652085372.897938][465400:465400] CHIP:CTL: Setting attestation nonce to random value [1652085372.897945][465400:465400] CHIP:CTL: Setting CSR nonce to random value [1652085372.898167][465400:465400] CHIP:CTL: Generating NOC [1652085372.898382][465400:465400] CHIP:DIS: Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage [1652085372.898401][465400:465400] CHIP:DIS: Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage [1652085372.898446][465400:465400] CHIP:DIS: Verifying the received credentials [1652085372.898865][465400:465400] CHIP:DIS: Added new fabric at index: 1, Initialized: 1 [1652085372.898872][465400:465400] CHIP:DIS: Assigned compressed fabric ID: 0x5C5F54E6DCDF1E42, node ID: 0x000000000001B669 [1652085372.898877][465400:465400] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x5C5F54E6DCDF1E42 [1652085372.898894][465400:465400] CHIP:CTL: Setting attestation nonce to random value [1652085372.898903][465400:465400] CHIP:CTL: Setting CSR nonce to random value [1652085372.899067][465400:465400] CHIP:CTL: Generating NOC [1652085372.899253][465400:465400] CHIP:DIS: Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage [1652085372.899271][465400:465400] CHIP:DIS: Fabric (2) loaded from storage. Calling OnFabricRetrievedFromStorage [1652085372.899285][465400:465400] CHIP:DIS: Fabric (2) loaded from storage. Calling OnFabricRetrievedFromStorage [1652085372.899323][465400:465400] CHIP:DIS: Verifying the received credentials [1652085372.899706][465400:465400] CHIP:DIS: Added new fabric at index: 2, Initialized: 1 [1652085372.899712][465400:465400] CHIP:DIS: Assigned compressed fabric ID: 0x11086265F3884825, node ID: 0x000000000001B669 [1652085372.899716][465400:465400] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x11086265F3884825 [1652085372.899730][465400:465400] CHIP:CTL: Setting attestation nonce to random value [1652085372.899737][465400:465400] CHIP:CTL: Setting CSR nonce to random value [1652085372.899900][465400:465400] CHIP:CTL: Generating NOC [1652085372.900083][465400:465400] CHIP:DIS: Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage [1652085372.900101][465400:465400] CHIP:DIS: Fabric (2) loaded from storage. Calling OnFabricRetrievedFromStorage [1652085372.900114][465400:465400] CHIP:DIS: Fabric (3) loaded from storage. Calling OnFabricRetrievedFromStorage [1652085372.900128][465400:465400] CHIP:DIS: Fabric (3) loaded from storage. Calling OnFabricRetrievedFromStorage [1652085372.900168][465400:465400] CHIP:DIS: Verifying the received credentials [1652085372.900546][465400:465400] CHIP:DIS: Added new fabric at index: 3, Initialized: 1 [1652085372.900553][465400:465400] CHIP:DIS: Assigned compressed fabric ID: 0x9BEFC269D3A437EF, node ID: 0x000000000001B669 [1652085372.900557][465400:465400] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0x9BEFC269D3A437EF [1652085372.905282][465400:465405] CHIP:IN: Prepared unauthenticated message 0x7f2852ffc380 to 0x0000000000000000 (0) of type 0x20 and protocolId (0, 0) on exchange 1153i with MessageCounter:3734599857. [1652085372.905296][465400:465405] CHIP:IN: Sending unauthenticated msg 0x7f2852ffc380 with MessageCounter:3734599857 to 0x0000000000000000 at monotonic time: 000000000FCB3133 msec [1652085372.905304][465400:465405] CHIP:CTL: Setting thread operational dataset from parameters [1652085372.905307][465400:465405] CHIP:CTL: Setting attestation nonce to random value [1652085372.905313][465400:465405] CHIP:CTL: Setting CSR nonce to random value [1652085372.905319][465400:465405] CHIP:CTL: Commission called for node ID 0x0000000000000001 [1652085372.920045][465400:465403] CHIP:BLE: BLE removing known devices. [1652085372.939089][465400:465403] CHIP:BLE: BLE initiating scan. [1652085373.663760][465400:465403] CHIP:BLE: New device scanned: D8:F6:4A:A2:2D:4D [1652085373.663786][465400:465403] CHIP:BLE: Device discriminator match. Attempting to connect. [1652085373.666956][465400:465403] CHIP:BLE: Scan complete notification without an active scan. [1652085376.106440][465400:465405] CHIP:BLE: subscribe complete, ep = 0x556b58661f20 [1652085376.106488][465400:465405] CHIP:BLE: peripheral chose BTP version 4; central expected between 4 and 4 [1652085376.106513][465400:465405] CHIP:BLE: using BTP fragment sizes rx 20 / tx 20. [1652085376.106526][465400:465405] CHIP:BLE: local and remote recv window size = 5 [1652085377.325041][465400:465405] CHIP:EM: Received message of type 0x21 with protocolId (0, 0) and MessageCounter:215078883 on exchange 1153i [1652085377.331776][465400:465405] CHIP:IN: Prepared unauthenticated message 0x7f2852ffbf10 to 0x0000000000000000 (0) of type 0x22 and protocolId (0, 0) on exchange 1153i with MessageCounter:3734599858. [1652085377.331818][465400:465405] CHIP:IN: Sending unauthenticated msg 0x7f2852ffbf10 with MessageCounter:3734599858 to 0x0000000000000000 at monotonic time: 000000000FCB427D msec [1652085380.223444][465400:465405] CHIP:EM: Received message of type 0x23 with protocolId (0, 0) and MessageCounter:215078884 on exchange 1153i [1652085380.224516][465400:465405] CHIP:IN: Prepared unauthenticated message 0x7f2852ffc010 to 0x0000000000000000 (0) of type 0x24 and protocolId (0, 0) on exchange 1153i with MessageCounter:3734599859. [1652085380.224558][465400:465405] CHIP:IN: Sending unauthenticated msg 0x7f2852ffc010 with MessageCounter:3734599859 to 0x0000000000000000 at monotonic time: 000000000FCB4DCA msec [1652085380.808345][465400:465405] CHIP:EM: Received message of type 0x40 with protocolId (0, 0) and MessageCounter:215078885 on exchange 1153i [1652085380.808478][465400:465405] CHIP:CTL: Going from commissioning step 'SecurePairing' with lastErr = '../../src/controller/AutoCommissioner.cpp:253: Success' --> 'ReadCommissioningInfo' [1652085380.808503][465400:465405] CHIP:CTL: Performing next commissioning step 'ReadCommissioningInfo' with completion status = '../../src/controller/CommissioningDelegate.h:341: Success' [1652085380.808516][465400:465405] CHIP:CTL: Sending request for commissioning information [1652085380.808599][465400:465405] CHIP:IN: Prepared secure message 0x7f2852ffb990 to 0x0000000000000001 (1) of type 0x2 and protocolId (0, 1) on exchange 1154i with MessageCounter:5725624. [1652085380.808648][465400:465405] CHIP:IN: Sending encrypted msg 0x7f2852ffb990 with MessageCounter:5725624 to 0x0000000000000001 (1) at monotonic time: 000000000FCB5012 msec [1652085383.103838][465400:465405] CHIP:EM: Received message of type 0x5 with protocolId (0, 1) and MessageCounter:6594972 on exchange 1154i [1652085383.105012][465400:465405] CHIP:CTL: Finished commissioning step 'ReadCommissioningInfo' with error '../../src/controller/CHIPDeviceController.cpp:1631: Success' [1652085383.105051][465400:465405] CHIP:CTL: Going from commissioning step 'ReadCommissioningInfo' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1631: Success' --> 'ArmFailSafe' [1652085383.105073][465400:465405] CHIP:CTL: Performing next commissioning step 'ArmFailSafe' with completion status = '../../src/controller/CHIPDeviceController.cpp:1631: Success' [1652085383.105091][465400:465405] CHIP:CTL: Arming failsafe (60 seconds) [1652085383.105195][465400:465405] CHIP:IN: Prepared secure message 0x7f2852ffb500 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 1155i with MessageCounter:5725625. [1652085383.105235][465400:465405] CHIP:IN: Sending encrypted msg 0x7f2852ffb500 with MessageCounter:5725625 to 0x0000000000000001 (1) at monotonic time: 000000000FCB590B msec [1652085383.914050][465400:465405] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:6594973 on exchange 1155i [1652085383.914287][465400:465405] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001 [1652085383.914344][465400:465405] CHIP:CTL: Received ArmFailSafe response [1652085383.914366][465400:465405] CHIP:CTL: Finished commissioning step 'ArmFailSafe' with error '../../src/controller/CHIPDeviceController.cpp:1783: Success' [1652085383.914388][465400:465405] CHIP:CTL: Going from commissioning step 'ArmFailSafe' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1783: Success' --> 'ConfigRegulatory' [1652085383.914410][465400:465405] CHIP:CTL: Performing next commissioning step 'ConfigRegulatory' with completion status = '../../src/controller/CHIPDeviceController.cpp:1783: Success' [1652085383.914426][465400:465405] CHIP:CTL: Setting Regulatory Config [1652085383.914438][465400:465405] CHIP:CTL: Device does not support configurable regulatory location [1652085383.914479][465400:465405] CHIP:CTL: Unable to find country code, defaulting to XX [1652085383.914586][465400:465405] CHIP:IN: Prepared secure message 0x7f2852ffb100 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 1156i with MessageCounter:5725626. [1652085383.914626][465400:465405] CHIP:IN: Sending encrypted msg 0x7f2852ffb100 with MessageCounter:5725626 to 0x0000000000000001 (1) at monotonic time: 000000000FCB5C34 msec [1652085384.768879][465400:465405] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:6594974 on exchange 1156i [1652085384.769079][465400:465405] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0003 [1652085384.769118][465400:465405] CHIP:CTL: Received SetRegulatoryConfig response [1652085384.769145][465400:465405] CHIP:CTL: Finished commissioning step 'ConfigRegulatory' with error '../../src/controller/CHIPDeviceController.cpp:1792: Success' [1652085384.769166][465400:465405] CHIP:CTL: Going from commissioning step 'ConfigRegulatory' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1792: Success' --> 'SendPAICertificateRequest' [1652085384.769186][465400:465405] CHIP:CTL: Performing next commissioning step 'SendPAICertificateRequest' with completion status = '../../src/controller/CHIPDeviceController.cpp:1792: Success' [1652085384.769205][465400:465405] CHIP:CTL: Sending request for PAI certificate [1652085384.769317][465400:465405] CHIP:IN: Prepared secure message 0x7f2852ffb070 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 1157i with MessageCounter:5725627. [1652085384.769356][465400:465405] CHIP:IN: Sending encrypted msg 0x7f2852ffb070 with MessageCounter:5725627 to 0x0000000000000001 (1) at monotonic time: 000000000FCB5F8B msec [1652085388.008443][465400:465405] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:6594975 on exchange 1157i [1652085388.008628][465400:465405] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003 [1652085388.008658][465400:465405] CHIP:CTL: Received certificate chain from the device [1652085388.008677][465400:465405] CHIP:CTL: Finished commissioning step 'SendPAICertificateRequest' with error '../../src/controller/CHIPDeviceController.cpp:1127: Success' [1652085388.008694][465400:465405] CHIP:CTL: Going from commissioning step 'SendPAICertificateRequest' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1127: Success' --> 'SendDACCertificateRequest' [1652085388.008713][465400:465405] CHIP:CTL: Performing next commissioning step 'SendDACCertificateRequest' with completion status = '../../src/controller/CHIPDeviceController.cpp:1127: Success' [1652085388.008728][465400:465405] CHIP:CTL: Sending request for DAC certificate [1652085388.008812][465400:465405] CHIP:IN: Prepared secure message 0x7f2852ffb030 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 1158i with MessageCounter:5725628. [1652085388.008843][465400:465405] CHIP:IN: Sending encrypted msg 0x7f2852ffb030 with MessageCounter:5725628 to 0x0000000000000001 (1) at monotonic time: 000000000FCB6C32 msec [1652085391.248719][465400:465405] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:6594976 on exchange 1158i [1652085391.248900][465400:465405] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003 [1652085391.248930][465400:465405] CHIP:CTL: Received certificate chain from the device [1652085391.248949][465400:465405] CHIP:CTL: Finished commissioning step 'SendDACCertificateRequest' with error '../../src/controller/CHIPDeviceController.cpp:1127: Success' [1652085391.248966][465400:465405] CHIP:CTL: Going from commissioning step 'SendDACCertificateRequest' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1127: Success' --> 'SendAttestationRequest' [1652085391.248985][465400:465405] CHIP:CTL: Performing next commissioning step 'SendAttestationRequest' with completion status = '../../src/controller/CHIPDeviceController.cpp:1127: Success' [1652085391.249000][465400:465405] CHIP:CTL: Sending Attestation Request to the device. [1652085391.249084][465400:465405] CHIP:IN: Prepared secure message 0x7f2852ffb010 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 1159i with MessageCounter:5725629. [1652085391.249115][465400:465405] CHIP:IN: Sending encrypted msg 0x7f2852ffb010 with MessageCounter:5725629 to 0x0000000000000001 (1) at monotonic time: 000000000FCB78DB msec [1652085395.658866][465400:465405] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:6594977 on exchange 1159i [1652085395.659065][465400:465405] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0001 [1652085395.659097][465400:465405] CHIP:CTL: Received Attestation Information from the device [1652085395.659117][465400:465405] CHIP:CTL: Finished commissioning step 'SendAttestationRequest' with error '../../src/controller/CHIPDeviceController.cpp:1162: Success' [1652085395.659156][465400:465405] CHIP:CTL: Going from commissioning step 'SendAttestationRequest' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1162: Success' --> 'AttestationVerification' [1652085395.659173][465400:465405] CHIP:CTL: Performing next commissioning step 'AttestationVerification' with completion status = '../../src/controller/CHIPDeviceController.cpp:1162: Success' [1652085395.659185][465400:465405] CHIP:CTL: Verifying attestation [1652085395.663972][465400:465405] CHIP:CTL: Successfully validated 'Attestation Information' command received from the device. [1652085395.664012][465400:465405] CHIP:CTL: Finished commissioning step 'AttestationVerification' with error '../../src/controller/CHIPDeviceController.cpp:1194: Success' [1652085395.664027][465400:465405] CHIP:CTL: Going from commissioning step 'AttestationVerification' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1194: Success' --> 'SendOpCertSigningRequest' [1652085395.664041][465400:465405] CHIP:CTL: Performing next commissioning step 'SendOpCertSigningRequest' with completion status = '../../src/controller/CHIPDeviceController.cpp:1194: Success' [1652085395.664147][465400:465405] CHIP:IN: Prepared secure message 0x7f2852ffa590 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 1160i with MessageCounter:5725630. [1652085395.664184][465400:465405] CHIP:IN: Sending encrypted msg 0x7f2852ffa590 with MessageCounter:5725630 to 0x0000000000000001 (1) at monotonic time: 000000000FCB8A1A msec [1652085398.628642][465400:465405] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:6594978 on exchange 1160i [1652085398.628847][465400:465405] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0005 [1652085398.628881][465400:465405] CHIP:CTL: Received certificate signing request from the device [1652085398.628902][465400:465405] CHIP:CTL: Finished commissioning step 'SendOpCertSigningRequest' with error '../../src/controller/CHIPDeviceController.cpp:1243: Success' [1652085398.628923][465400:465405] CHIP:CTL: Going from commissioning step 'SendOpCertSigningRequest' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1243: Success' --> 'GenerateNOCChain' [1652085398.628943][465400:465405] CHIP:CTL: Performing next commissioning step 'GenerateNOCChain' with completion status = '../../src/controller/CHIPDeviceController.cpp:1243: Success' [1652085398.628961][465400:465405] CHIP:CTL: Getting certificate chain for the device from the issuer [1652085398.629977][465400:465405] CHIP:CTL: Verifying Certificate Signing Request [1652085398.630555][465400:465405] CHIP:CTL: Generating NOC [1652085398.630907][465400:465405] CHIP:CTL: Providing certificate chain to the commissioner [1652085398.630934][465400:465405] CHIP:CTL: Received callback from the CA for NOC Chain generation. Status ../../src/controller/ExampleOperationalCredentialsIssuer.cpp:229: Success [1652085398.630955][465400:465405] CHIP:CTL: Finished commissioning step 'GenerateNOCChain' with error '../../src/controller/ExampleOperationalCredentialsIssuer.cpp:229: Success' [1652085398.631122][465400:465405] CHIP:CTL: Performing next commissioning step 'SendTrustedRootCert' with completion status = '../../src/controller/CHIPDeviceController.cpp:1243: Success' [1652085398.631146][465400:465405] CHIP:CTL: Sending root certificate to the device [1652085398.631247][465400:465405] CHIP:IN: Prepared secure message 0x7f2852ffa3c0 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 1161i with MessageCounter:5725631. [1652085398.631284][465400:465405] CHIP:IN: Sending encrypted msg 0x7f2852ffa3c0 with MessageCounter:5725631 to 0x0000000000000001 (1) at monotonic time: 000000000FCB95B1 msec [1652085398.631370][465400:465405] CHIP:CTL: Sent root certificate to the device [1652085400.609006][465400:465405] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:6594979 on exchange 1161i [1652085400.609178][465400:465405] CHIP:DMG: Received Command Response Status for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B Status=0x0 [1652085400.609204][465400:465405] CHIP:CTL: Device confirmed that it has received the root certificate [1652085400.609222][465400:465405] CHIP:CTL: Finished commissioning step 'SendTrustedRootCert' with error '../../src/controller/CHIPDeviceController.cpp:1414: Success' [1652085400.609236][465400:465405] CHIP:CTL: Going from commissioning step 'SendTrustedRootCert' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1414: Success' --> 'SendNOC' [1652085400.609251][465400:465405] CHIP:CTL: Performing next commissioning step 'SendNOC' with completion status = '../../src/controller/CHIPDeviceController.cpp:1414: Success' [1652085400.609353][465400:465405] CHIP:IN: Prepared secure message 0x7f2852ffb030 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 1162i with MessageCounter:5725632. [1652085400.609384][465400:465405] CHIP:IN: Sending encrypted msg 0x7f2852ffb030 with MessageCounter:5725632 to 0x0000000000000001 (1) at monotonic time: 000000000FCB9D6B msec [1652085400.609456][465400:465405] CHIP:CTL: Sent operational certificate to the device [1652085404.524482][465400:465405] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:6594980 on exchange 1162i [1652085404.524679][465400:465405] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0008 [1652085404.524736][465400:465405] CHIP:CTL: Device returned status 0 on receiving the NOC [1652085404.524752][465400:465405] CHIP:CTL: Operational credentials provisioned on device 0x7f2840001730 [1652085404.524776][465400:465405] CHIP:TOO: Secure Pairing Success [1652085404.524798][465400:465405] CHIP:CTL: Finished commissioning step 'SendNOC' with error '../../src/controller/CHIPDeviceController.cpp:1440: Success' [1652085404.524817][465400:465405] CHIP:CTL: Going from commissioning step 'SendNOC' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1440: Success' --> 'ThreadNetworkSetup' [1652085404.524837][465400:465405] CHIP:CTL: Performing next commissioning step 'ThreadNetworkSetup' with completion status = '../../src/controller/CHIPDeviceController.cpp:1440: Success' [1652085404.524933][465400:465405] CHIP:IN: Prepared secure message 0x7f2852ffb010 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 1163i with MessageCounter:5725633. [1652085404.524966][465400:465405] CHIP:IN: Sending encrypted msg 0x7f2852ffb010 with MessageCounter:5725633 to 0x0000000000000001 (1) at monotonic time: 000000000FCBACB6 msec [1652085405.784649][465400:465405] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:6594981 on exchange 1163i [1652085405.784840][465400:465405] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0005 [1652085405.784877][465400:465405] CHIP:CTL: Received NetworkConfig response [1652085405.784899][465400:465405] CHIP:CTL: Finished commissioning step 'ThreadNetworkSetup' with error '../../src/controller/CHIPDeviceController.cpp:1801: Success' [1652085405.784921][465400:465405] CHIP:CTL: Going from commissioning step 'ThreadNetworkSetup' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1801: Success' --> 'ThreadNetworkEnable' [1652085405.784951][465400:465405] CHIP:CTL: Performing next commissioning step 'ThreadNetworkEnable' with completion status = '../../src/controller/CHIPDeviceController.cpp:1801: Success' [1652085405.785054][465400:465405] CHIP:IN: Prepared secure message 0x7f2852ffb100 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 1164i with MessageCounter:5725634. [1652085405.785084][465400:465405] CHIP:IN: Sending encrypted msg 0x7f2852ffb100 with MessageCounter:5725634 to 0x0000000000000001 (1) at monotonic time: 000000000FCBB1A3 msec [1652085409.293882][465400:465405] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:6594982 on exchange 1164i [1652085409.294089][465400:465405] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0007 [1652085409.294129][465400:465405] CHIP:CTL: Received ConnectNetwork response [1652085409.294155][465400:465405] CHIP:CTL: Finished commissioning step 'ThreadNetworkEnable' with error '../../src/controller/CHIPDeviceController.cpp:1810: Success' [1652085409.294180][465400:465405] CHIP:CTL: Going from commissioning step 'ThreadNetworkEnable' with lastErr = '../../src/controller/CHIPDeviceController.cpp:1810: Success' --> 'FindOperational' [1652085409.294201][465400:465405] CHIP:CTL: Performing next commissioning step 'FindOperational' with completion status = '../../src/controller/CHIPDeviceController.cpp:1810: Success' [1652085409.294230][465400:465405] CHIP:DIS: Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage [1652085409.294244][465400:465405] CHIP:DIS: Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage [1652085409.294262][465400:465405] CHIP:DIS: Resolving 5C5F54E6DCDF1E42:0000000000000001 ... [1652085409.295332][465400:465405] CHIP:DIS: Operational node lookup already in progress. Will NOT start a new one. [1652085409.494893][465400:465405] CHIP:DIS: Checking node lookup status after 200 ms [1652085410.176277][465400:465405] CHIP:DL: Avahi resolve found [1652085410.176351][465400:465405] CHIP:DIS: Node ID resolved for 5C5F54E6DCDF1E42:0000000000000001 [1652085410.176378][465400:465405] CHIP:DIS: Addr 0: [fd11:22::8a29:aa5:51df:aeff]:5540 [1652085410.176789][465400:465405] CHIP:DIS: UDP:[fd11:22::8a29:aa5:51df:aeff%wlp1s0]:5540: new best score: 4 [1652085410.176815][465400:465405] CHIP:DIS: Checking node lookup status after 882 ms [1652085410.176883][465400:465405] CHIP:SC: Establishing CASE session to UDP:[fd11:22::8a29:aa5:51df:aeff]:5540 [1652085410.177330][465400:465405] CHIP:IN: Prepared unauthenticated message 0x556b5a798468 to 0x0000000000000000 (0) of type 0x30 and protocolId (0, 0) on exchange 1165i with MessageCounter:3734599860. [1652085410.177375][465400:465405] CHIP:IN: Sending unauthenticated msg 0x556b5a798468 with MessageCounter:3734599860 to 0x0000000000000000 at monotonic time: 000000000FCBC2CB msec [1652085410.177450][465400:465405] CHIP:DIS: Discovery does not require any more timeouts [1652085443.711570][465400:465403] CHIP:DL: Bluez notify CHIPoBluez connection disconnected