$ sudo ./chip-tool pairing ble-thread 1 hex:0e080000000000010000000300000f35060004001fffe0020811111111222222220708fd278ad1d0c01517051000112233445566778899aabbccddeeff030e4f70656e54687265616444656d6f010212340410445f2b5ca6f2a93a55ce570a70efeecb0c0402a0fff8 20202021 3840 [1651673707.447182][3341910:3341910] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1651673707.447303][3341910:3341910] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1651673707.447336][3341910:3341910] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1651673707.447356][3341910:3341910] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1651673707.447437][3341910:3341910] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-nVKr1L) [1651673707.447559][3341910:3341910] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1651673707.447570][3341910:3341910] CHIP:DL: NVS set: chip-counters/reboot-count = 81 (0x51) [1651673707.447751][3341910:3341910] CHIP:DL: Got Ethernet interface: enp0s31f6 [1651673707.447876][3341910:3341910] CHIP:DL: Found the primary Ethernet interface:enp0s31f6 [1651673707.448002][3341910:3341910] CHIP:DL: Got WiFi interface: wlp1s0 [1651673707.449447][3341910:3341910] CHIP:DL: Found the primary WiFi interface:wlp1s0 [1651673707.449469][3341910:3341910] CHIP:IN: UDP::Init bind&listen port=0 [1651673707.449488][3341910:3341910] CHIP:IN: UDP::Init bound to port=55489 [1651673707.449493][3341910:3341910] CHIP:IN: UDP::Init bind&listen port=0 [1651673707.449506][3341910:3341910] CHIP:IN: UDP::Init bound to port=45934 [1651673707.449510][3341910:3341910] CHIP:IN: BLEBase::Init - setting/overriding transport [1651673707.449514][3341910:3341910] CHIP:IN: TransportMgr initialized [1651673707.449521][3341910:3341910] CHIP:DIS: Init fabric pairing table with server storage [1651673707.449554][3341910:3341910] CHIP:IN: Loading from storage for fabric index 0x1 [1651673707.450415][3341910:3341910] CHIP:IN: Loading from storage for fabric index 0x2 [1651673707.450593][3341910:3341910] CHIP:IN: Loading from storage for fabric index 0x3 [1651673707.450763][3341910:3341910] CHIP:DIS: Add fabric pairing table delegate [1651673707.451228][3341910:3341910] CHIP:ZCL: Using ZAP configuration... [1651673707.451539][3341910:3341910] CHIP:DL: MDNS failed to join multicast group on enp0s31f6 for address type IPv4: ../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found [1651673707.451786][3341910:3341910] CHIP:CTL: System State Initialized... [1651673707.451805][3341910:3341910] CHIP:CTL: Setting attestation nonce to random value [1651673707.451813][3341910:3341910] CHIP:CTL: Setting CSR nonce to random value [1651673707.451825][3341910:3341910] CHIP:IN: UDP::Init bind&listen port=5550 [1651673707.451840][3341910:3341910] CHIP:IN: UDP::Init bound to port=5550 [1651673707.451844][3341910:3341910] CHIP:IN: UDP::Init bind&listen port=5550 [1651673707.451854][3341910:3341910] CHIP:IN: UDP::Init bound to port=5550 [1651673707.451857][3341910:3341910] CHIP:IN: TransportMgr initialized [1651673707.451871][3341910:3341910] CHIP:CTL: Setting attestation nonce to random value [1651673707.451878][3341910:3341910] CHIP:CTL: Setting CSR nonce to random value [1651673707.452118][3341910:3341910] CHIP:CTL: Generating NOC [1651673707.452359][3341910:3341910] CHIP:DIS: Verifying the received credentials [1651673707.452773][3341910:3341910] CHIP:DIS: Added new fabric at index: 0x1, Initialized: 1 [1651673707.452780][3341910:3341910] CHIP:DIS: Assigned compressed fabric ID: 0x161FA567065F5451, node ID: 0x000000000001B669 [1651673707.452784][3341910:3341910] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x161FA567065F5451 [1651673707.452791][3341910:3341910] CHIP:IN: UDP::Init bind&listen port=5550 [1651673707.452806][3341910:3341910] CHIP:IN: UDP::Init bound to port=5550 [1651673707.452809][3341910:3341910] CHIP:IN: UDP::Init bind&listen port=5550 [1651673707.452820][3341910:3341910] CHIP:IN: UDP::Init bound to port=5550 [1651673707.452824][3341910:3341910] CHIP:IN: TransportMgr initialized [1651673707.452840][3341910:3341910] CHIP:CTL: Setting attestation nonce to random value [1651673707.452847][3341910:3341910] CHIP:CTL: Setting CSR nonce to random value [1651673707.453042][3341910:3341910] CHIP:CTL: Generating NOC [1651673707.453272][3341910:3341910] CHIP:DIS: Verifying the received credentials [1651673707.453667][3341910:3341910] CHIP:DIS: Added new fabric at index: 0x2, Initialized: 1 [1651673707.453674][3341910:3341910] CHIP:DIS: Assigned compressed fabric ID: 0x93AFB76549E46254, node ID: 0x000000000001B669 [1651673707.453678][3341910:3341910] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x93AFB76549E46254 [1651673707.453685][3341910:3341910] CHIP:IN: UDP::Init bind&listen port=5550 [1651673707.453699][3341910:3341910] CHIP:IN: UDP::Init bound to port=5550 [1651673707.453702][3341910:3341910] CHIP:IN: UDP::Init bind&listen port=5550 [1651673707.453713][3341910:3341910] CHIP:IN: UDP::Init bound to port=5550 [1651673707.453717][3341910:3341910] CHIP:IN: TransportMgr initialized [1651673707.453736][3341910:3341910] CHIP:CTL: Setting attestation nonce to random value [1651673707.453743][3341910:3341910] CHIP:CTL: Setting CSR nonce to random value [1651673707.453937][3341910:3341910] CHIP:CTL: Generating NOC [1651673707.454176][3341910:3341910] CHIP:DIS: Verifying the received credentials [1651673707.454568][3341910:3341910] CHIP:DIS: Added new fabric at index: 0x3, Initialized: 1 [1651673707.454575][3341910:3341910] CHIP:DIS: Assigned compressed fabric ID: 0xBADA1E8D777C7B0D, node ID: 0x000000000001B669 [1651673707.454578][3341910:3341910] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0xBADA1E8D777C7B0D [1651673707.454585][3341910:3341910] CHIP:IN: UDP::Init bind&listen port=5550 [1651673707.454599][3341910:3341910] CHIP:IN: UDP::Init bound to port=5550 [1651673707.454603][3341910:3341910] CHIP:IN: UDP::Init bind&listen port=5550 [1651673707.454613][3341910:3341910] CHIP:IN: UDP::Init bound to port=5550 [1651673707.454617][3341910:3341910] CHIP:IN: TransportMgr initialized [1651673707.460483][3341910:3341915] CHIP:DL: CHIP task running [1651673707.460566][3341910:3341915] CHIP:SC: Assigned local session key ID 15371 [1651673707.460581][3341910:3341915] CHIP:SC: Including MRP parameters in PBKDF param request [1651673707.460594][3341910:3341915] CHIP:IN: Prepared unauthenticated message 0x7fa8192e6400 to 0x0000000000000000 (0) of type 0x20 and protocolId (0, 0) on exchange 43603i with MessageCounter:337378119. [1651673707.460602][3341910:3341915] CHIP:IN: Sending unauthenticated msg 0x7fa8192e6400 with MessageCounter:337378119 to 0x0000000000000000 at monotonic time: 000000001B0BA508 msec [1651673707.460609][3341910:3341915] CHIP:IN: Message appended to BLE send queue [1651673707.460613][3341910:3341915] CHIP:SC: Sent PBKDF param request [1651673707.460617][3341910:3341915] CHIP:CTL: Setting thread operational dataset from parameters [1651673707.460620][3341910:3341915] CHIP:CTL: Setting attestation nonce to random value [1651673707.460626][3341910:3341915] CHIP:CTL: Setting CSR nonce to random value [1651673707.460632][3341910:3341915] CHIP:CTL: Commission called for node ID 0x0000000000000001 [1651673707.460704][3341910:3341916] CHIP:DL: TRACE: Bluez mainloop starting Thread [1651673707.460712][3341910:3341913] CHIP:DL: TRACE: Bus acquired for name C-fe56 [1651673707.464155][3341910:3341915] CHIP:DL: PlatformBlueZInit init success [1651673707.466792][3341910:3341913] CHIP:BLE: BLE removing known devices. [1651673707.477828][3341910:3341913] CHIP:BLE: BLE initiating scan. [1651673707.614755][3341910:3341913] CHIP:BLE: Device 12:3A:E2:D3:C8:44 does not look like a CHIP device. [1651673707.638329][3341910:3341913] CHIP:BLE: Device CF:4C:91:8A:C5:A3 does not look like a CHIP device. [1651673707.639714][3341910:3341913] CHIP:BLE: Device 3B:50:CF:3F:B0:07 does not look like a CHIP device. [1651673707.640761][3341910:3341913] CHIP:BLE: Device 2D:65:02:06:7E:34 does not look like a CHIP device. [1651673707.644140][3341910:3341913] CHIP:BLE: Device 45:70:22:F5:53:66 does not look like a CHIP device. [1651673707.651878][3341910:3341913] CHIP:BLE: Device 5C:C1:D7:64:C8:B5 does not look like a CHIP device. [1651673707.666770][3341910:3341913] CHIP:BLE: Device 1F:5D:36:33:F2:D6 does not look like a CHIP device. [1651673707.670837][3341910:3341913] CHIP:BLE: Device 4F:F8:5A:62:CB:F3 does not look like a CHIP device. [1651673707.678798][3341910:3341913] CHIP:BLE: Device 54:C7:C4:60:95:F8 does not look like a CHIP device. [1651673707.682471][3341910:3341913] CHIP:BLE: Device 06:94:DF:E6:C9:FE does not look like a CHIP device. [1651673707.686363][3341910:3341913] CHIP:BLE: Device 38:A1:6E:1E:FE:C9 does not look like a CHIP device. [1651673707.687266][3341910:3341913] CHIP:BLE: Device 40:47:C2:1C:4F:6A does not look like a CHIP device. [1651673707.688555][3341910:3341913] CHIP:BLE: Device 29:6D:74:D3:3A:D6 does not look like a CHIP device. [1651673707.691062][3341910:3341913] CHIP:BLE: Device 3D:37:81:99:C6:43 does not look like a CHIP device. [1651673707.691952][3341910:3341913] CHIP:BLE: Device 68:E7:16:A6:39:8B does not look like a CHIP device. [1651673707.729331][3341910:3341913] CHIP:BLE: Device 3F:4E:5C:27:49:F5 does not look like a CHIP device. [1651673707.748339][3341910:3341913] CHIP:BLE: Device 19:60:47:1A:52:BF does not look like a CHIP device. [1651673707.814152][3341910:3341913] CHIP:BLE: Device 20:7E:2E:D6:8A:83 does not look like a CHIP device. [1651673707.837388][3341910:3341913] CHIP:BLE: Device CF:4C:91:8A:C5:A3 does not look like a CHIP device. [1651673707.838873][3341910:3341913] CHIP:BLE: Device 2F:EF:7D:5C:C6:BD does not look like a CHIP device. [1651673707.853554][3341910:3341913] CHIP:BLE: New device scanned: E2:89:50:F0:CD:AA [1651673707.853600][3341910:3341913] CHIP:BLE: Device discriminator match. Attempting to connect. [1651673707.865698][3341910:3341913] CHIP:BLE: Scan complete notification without an active scan. [1651673708.216165][3341910:3341913] CHIP:DL: ConnectDevice complete [1651673708.585395][3341910:3341913] CHIP:DL: Char1 /org/bluez/hci0/dev_E2_89_50_F0_CD_AA/service0010 [1651673708.585441][3341910:3341913] CHIP:DL: Char1 /org/bluez/hci0/dev_E2_89_50_F0_CD_AA/service0010 [1651673708.585470][3341910:3341913] CHIP:DL: Char1 /org/bluez/hci0/dev_E2_89_50_F0_CD_AA/service0001 [1651673708.585483][3341910:3341913] CHIP:DL: Char1 /org/bluez/hci0/dev_E2_89_50_F0_CD_AA/service0010 [1651673708.585500][3341910:3341913] CHIP:DL: Char1 /org/bluez/hci0/dev_E2_89_50_F0_CD_AA/service0001 [1651673708.585513][3341910:3341913] CHIP:DL: Char1 /org/bluez/hci0/dev_E2_89_50_F0_CD_AA/service0010 [1651673708.585530][3341910:3341913] CHIP:DL: Char1 /org/bluez/hci0/dev_E2_89_50_F0_CD_AA/service0001 [1651673708.585542][3341910:3341913] CHIP:DL: Char1 /org/bluez/hci0/dev_E2_89_50_F0_CD_AA/service0010 [1651673708.585569][3341910:3341913] CHIP:DL: Char1 /org/bluez/hci0/dev_E2_89_50_F0_CD_AA/service0010 [1651673708.585582][3341910:3341913] CHIP:DL: Char1 /org/bluez/hci0/dev_E2_89_50_F0_CD_AA/service0010 [1651673708.585600][3341910:3341913] CHIP:DL: Char1 /org/bluez/hci0/dev_E2_89_50_F0_CD_AA/service0010 [1651673708.585612][3341910:3341913] CHIP:DL: Char1 /org/bluez/hci0/dev_E2_89_50_F0_CD_AA/service0010 [1651673708.585632][3341910:3341913] CHIP:DL: New BLE connection 0x7fa81004ac20, device E2:89:50:F0:CD:AA, path /org/bluez/hci0/dev_E2_89_50_F0_CD_AA [1651673708.585802][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16385 [1651673708.585832][3341910:3341915] CHIP:IN: BleConnectionComplete: endPoint 0x55a5b9c4eb80 [1651673709.043029][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673709.140675][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16388 [1651673709.140687][3341910:3341915] CHIP:BLE: subscribe complete, ep = 0x55a5b9c4eb80 [1651673709.141261][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673709.141313][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673709.141321][3341910:3341915] CHIP:BLE: peripheral chose BTP version 4; central expected between 4 and 4 [1651673709.141325][3341910:3341915] CHIP:BLE: using BTP fragment sizes rx 20 / tx 20. [1651673709.141328][3341910:3341915] CHIP:BLE: local and remote recv window size = 5 [1651673709.141351][3341910:3341915] CHIP:IN: BLE EndPoint 0x55a5b9c4eb80 Connection Complete [1651673709.238083][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673709.335761][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673709.433601][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673709.530799][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673709.532198][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673709.532363][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673709.628319][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673709.774840][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673709.774915][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673709.873803][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673709.873985][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673709.970766][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673709.970950][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673710.066872][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673710.067838][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673710.067935][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673710.165765][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673710.165917][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673710.262443][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673710.262502][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673710.360928][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673710.361120][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673710.457025][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673710.458755][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673710.458908][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673710.458980][3341910:3341915] CHIP:EM: Received message of type 0x21 with protocolId (0, 0) and MessageCounter:692407989 on exchange 43603i [1651673710.458999][3341910:3341915] CHIP:EM: Found matching exchange: 43603i, Delegate: 0x7fa804000bb0 [1651673710.459021][3341910:3341915] CHIP:SC: Received PBKDF param response [1651673710.459051][3341910:3341915] CHIP:SC: Peer assigned session ID 2 [1651673710.459071][3341910:3341915] CHIP:SC: Found MRP parameters in the message [1651673710.465975][3341910:3341915] CHIP:IN: Prepared unauthenticated message 0x7fa8192e5ff0 to 0x0000000000000000 (0) of type 0x22 and protocolId (0, 0) on exchange 43603i with MessageCounter:337378120. [1651673710.466017][3341910:3341915] CHIP:IN: Sending unauthenticated msg 0x7fa8192e5ff0 with MessageCounter:337378120 to 0x0000000000000000 at monotonic time: 000000001B0BB0C6 msec [1651673710.466080][3341910:3341915] CHIP:SC: Sent spake2p msg1 [1651673710.554840][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673710.652406][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673710.749760][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673710.751290][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673710.751430][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673710.847255][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673710.944787][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673711.041642][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673712.748574][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673712.748698][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673712.846174][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673712.846264][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673712.944792][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673712.945097][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673713.042435][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673713.042645][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673713.138455][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673713.140148][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673713.140338][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673713.237272][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673713.237419][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673713.335003][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673713.335191][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673713.431078][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673713.431147][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673713.431184][3341910:3341915] CHIP:EM: Received message of type 0x23 with protocolId (0, 0) and MessageCounter:692407990 on exchange 43603i [1651673713.431192][3341910:3341915] CHIP:EM: Found matching exchange: 43603i, Delegate: 0x7fa804000bb0 [1651673713.431199][3341910:3341915] CHIP:SC: Received spake2p msg2 [1651673713.431456][3341910:3341915] CHIP:IN: Prepared unauthenticated message 0x7fa8192e60f0 to 0x0000000000000000 (0) of type 0x24 and protocolId (0, 0) on exchange 43603i with MessageCounter:337378121. [1651673713.431466][3341910:3341915] CHIP:IN: Sending unauthenticated msg 0x7fa8192e60f0 with MessageCounter:337378121 to 0x0000000000000000 at monotonic time: 000000001B0BBC5B msec [1651673713.431473][3341910:3341915] CHIP:SC: Sent spake2p msg3 [1651673713.528192][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673713.630067][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673713.719718][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673713.809716][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673713.811240][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673713.811391][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673713.899386][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673714.034931][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673714.035018][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673714.214825][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673714.214939][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673714.214970][3341910:3341915] CHIP:EM: Received message of type 0x40 with protocolId (0, 0) and MessageCounter:692407991 on exchange 43603i [1651673714.214976][3341910:3341915] CHIP:EM: Found matching exchange: 43603i, Delegate: 0x7fa804000bb0 [1651673714.215005][3341910:3341915] CHIP:IN: New secure session created for device , LSID:15371 PSID:2! [1651673714.215013][3341910:3341915] CHIP:CTL: Remote device completed SPAKE2+ handshake [1651673714.215017][3341910:3341915] CHIP:TOO: Pairing Success [1651673714.215022][3341910:3341915] CHIP:CTL: Commissioning stage next step: 'SecurePairing' -> 'ReadCommissioningInfo' [1651673714.215026][3341910:3341915] CHIP:CTL: Performing next commissioning step 'ReadCommissioningInfo' [1651673714.215030][3341910:3341915] CHIP:CTL: Sending request for commissioning information [1651673714.215040][3341910:3341915] CHIP:DMG: SendReadRequest ReadClient[0x7fa804012cb0]: Sending Read Request [1651673714.215072][3341910:3341915] CHIP:IN: Prepared secure message 0x7fa8192e5980 to 0xFFFFFFFB00000000 (0) of type 0x2 and protocolId (0, 1) on exchange 43604i with MessageCounter:7804566. [1651673714.215089][3341910:3341915] CHIP:IN: Sending encrypted msg 0x7fa8192e5980 with MessageCounter:7804566 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000001B0BBF6B msec [1651673714.215117][3341910:3341915] CHIP:DMG: MoveToState ReadClient[0x7fa804012cb0]: Moving to [AwaitingIn] [1651673714.304839][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673714.394885][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673714.484979][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673714.574797][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673714.576629][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673714.576838][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673714.664868][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673714.754438][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673714.844473][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673714.934457][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673714.935917][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673714.936010][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673715.069953][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673715.070048][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673715.160724][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673715.160921][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673715.249677][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673715.249750][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673715.249799][3341910:3341915] CHIP:EM: Received message of type 0x1 with protocolId (0, 1) and MessageCounter:16337831 on exchange 43604i [1651673715.249808][3341910:3341915] CHIP:EM: Found matching exchange: 43604i, Delegate: 0x7fa804012cb0 [1651673715.249825][3341910:3341915] CHIP:DMG: StatusResponseMessage = [1651673715.249831][3341910:3341915] CHIP:DMG: { [1651673715.249836][3341910:3341915] CHIP:DMG: Status = 0x01 (FAILURE), [1651673715.249841][3341910:3341915] CHIP:DMG: InteractionModelRevision = 1 [1651673715.249846][3341910:3341915] CHIP:DMG: } [1651673715.249852][3341910:3341915] CHIP:IM: Received status response, status is 0x01 (FAILURE) [1651673715.249860][3341910:3341915] CHIP:DMG: mResubscribePolicy is null [1651673715.249876][3341910:3341915] CHIP:CTL: Successfully finished commissioning step 'ReadCommissioningInfo' [1651673715.249883][3341910:3341915] CHIP:CTL: Commissioning stage next step: 'ReadCommissioningInfo' -> 'ArmFailSafe' [1651673715.249889][3341910:3341915] CHIP:CTL: Performing next commissioning step 'ArmFailSafe' [1651673715.249893][3341910:3341915] CHIP:CTL: Arming failsafe (60 seconds) [1651673715.249916][3341910:3341915] CHIP:DMG: ICR moving to [AddingComm] [1651673715.249927][3341910:3341915] CHIP:DMG: ICR moving to [AddedComma] [1651673715.249946][3341910:3341915] CHIP:IN: Prepared secure message 0x7fa8192e5700 to 0xFFFFFFFB00000000 (0) of type 0x8 and protocolId (0, 1) on exchange 43605i with MessageCounter:7804567. [1651673715.249956][3341910:3341915] CHIP:IN: Sending encrypted msg 0x7fa8192e5700 with MessageCounter:7804567 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000001B0BC376 msec [1651673715.249964][3341910:3341915] CHIP:DMG: ICR moving to [CommandSen] [1651673715.339228][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673715.429446][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673715.519783][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673715.609795][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673715.611055][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673715.611172][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673715.699681][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673715.881197][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673715.881305][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673715.970977][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673715.971138][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673716.060799][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673716.060962][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673716.149739][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673716.151255][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673716.151413][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673716.151501][3341910:3341915] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:16337832 on exchange 43605i [1651673716.151530][3341910:3341915] CHIP:EM: Found matching exchange: 43605i, Delegate: 0x7fa804007800 [1651673716.151554][3341910:3341915] CHIP:DMG: ICR moving to [ResponseRe] [1651673716.151615][3341910:3341915] CHIP:DMG: InvokeResponseMessage = [1651673716.151632][3341910:3341915] CHIP:DMG: { [1651673716.151644][3341910:3341915] CHIP:DMG: suppressResponse = false, [1651673716.151661][3341910:3341915] CHIP:DMG: InvokeResponseIBs = [1651673716.151691][3341910:3341915] CHIP:DMG: [ [1651673716.151706][3341910:3341915] CHIP:DMG: InvokeResponseIB = [1651673716.151730][3341910:3341915] CHIP:DMG: { [1651673716.151745][3341910:3341915] CHIP:DMG: CommandDataIB = [1651673716.151759][3341910:3341915] CHIP:DMG: { [1651673716.151778][3341910:3341915] CHIP:DMG: CommandPathIB = [1651673716.151795][3341910:3341915] CHIP:DMG: { [1651673716.151812][3341910:3341915] CHIP:DMG: EndpointId = 0x0, [1651673716.151830][3341910:3341915] CHIP:DMG: ClusterId = 0x30, [1651673716.151847][3341910:3341915] CHIP:DMG: CommandId = 0x1, [1651673716.151862][3341910:3341915] CHIP:DMG: }, [1651673716.151880][3341910:3341915] CHIP:DMG: [1651673716.151895][3341910:3341915] CHIP:DMG: CommandData = [1651673716.151911][3341910:3341915] CHIP:DMG: { [1651673716.151929][3341910:3341915] CHIP:DMG: 0x0 = 0, [1651673716.151948][3341910:3341915] CHIP:DMG: 0x1 = "", [1651673716.151965][3341910:3341915] CHIP:DMG: }, [1651673716.151980][3341910:3341915] CHIP:DMG: }, [1651673716.152001][3341910:3341915] CHIP:DMG: [1651673716.152015][3341910:3341915] CHIP:DMG: }, [1651673716.152036][3341910:3341915] CHIP:DMG: [1651673716.152049][3341910:3341915] CHIP:DMG: ], [1651673716.152070][3341910:3341915] CHIP:DMG: [1651673716.152084][3341910:3341915] CHIP:DMG: InteractionModelRevision = 1 [1651673716.152097][3341910:3341915] CHIP:DMG: }, [1651673716.152148][3341910:3341915] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001 [1651673716.152176][3341910:3341915] CHIP:CTL: Received ArmFailSafe response errorCode=0 [1651673716.152196][3341910:3341915] CHIP:CTL: Successfully finished commissioning step 'ArmFailSafe' [1651673716.152211][3341910:3341915] CHIP:CTL: Commissioning stage next step: 'ArmFailSafe' -> 'ConfigRegulatory' [1651673716.152228][3341910:3341915] CHIP:CTL: Performing next commissioning step 'ConfigRegulatory' [1651673716.152243][3341910:3341915] CHIP:CTL: Setting Regulatory Config [1651673716.152256][3341910:3341915] CHIP:CTL: No regulatory config supplied by controller, leaving as device default (2) [1651673716.152299][3341910:3341915] CHIP:DMG: ICR moving to [AddingComm] [1651673716.152323][3341910:3341915] CHIP:DMG: ICR moving to [AddedComma] [1651673716.152379][3341910:3341915] CHIP:IN: Prepared secure message 0x7fa8192e5290 to 0xFFFFFFFB00000000 (0) of type 0x8 and protocolId (0, 1) on exchange 43606i with MessageCounter:7804568. [1651673716.152410][3341910:3341915] CHIP:IN: Sending encrypted msg 0x7fa8192e5290 with MessageCounter:7804568 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000001B0BC6FC msec [1651673716.152473][3341910:3341915] CHIP:DMG: ICR moving to [CommandSen] [1651673716.152517][3341910:3341915] CHIP:DMG: ICR moving to [AwaitingDe] [1651673716.239819][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673716.329196][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673716.422157][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673716.422334][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673716.422374][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673716.555039][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673716.645128][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673716.825826][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673716.825965][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673716.916505][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673716.916677][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673717.006058][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673717.006183][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673717.096529][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673717.096711][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673717.096833][3341910:3341915] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:16337833 on exchange 43606i [1651673717.096860][3341910:3341915] CHIP:EM: Found matching exchange: 43606i, Delegate: 0x7fa8040107d0 [1651673717.096883][3341910:3341915] CHIP:DMG: ICR moving to [ResponseRe] [1651673717.096921][3341910:3341915] CHIP:DMG: InvokeResponseMessage = [1651673717.096950][3341910:3341915] CHIP:DMG: { [1651673717.096966][3341910:3341915] CHIP:DMG: suppressResponse = false, [1651673717.096978][3341910:3341915] CHIP:DMG: InvokeResponseIBs = [1651673717.096999][3341910:3341915] CHIP:DMG: [ [1651673717.097014][3341910:3341915] CHIP:DMG: InvokeResponseIB = [1651673717.097036][3341910:3341915] CHIP:DMG: { [1651673717.097052][3341910:3341915] CHIP:DMG: CommandDataIB = [1651673717.097069][3341910:3341915] CHIP:DMG: { [1651673717.097083][3341910:3341915] CHIP:DMG: CommandPathIB = [1651673717.097101][3341910:3341915] CHIP:DMG: { [1651673717.097118][3341910:3341915] CHIP:DMG: EndpointId = 0x0, [1651673717.097135][3341910:3341915] CHIP:DMG: ClusterId = 0x30, [1651673717.097152][3341910:3341915] CHIP:DMG: CommandId = 0x3, [1651673717.097167][3341910:3341915] CHIP:DMG: }, [1651673717.097186][3341910:3341915] CHIP:DMG: [1651673717.097200][3341910:3341915] CHIP:DMG: CommandData = [1651673717.097216][3341910:3341915] CHIP:DMG: { [1651673717.097234][3341910:3341915] CHIP:DMG: 0x0 = 0, [1651673717.097255][3341910:3341915] CHIP:DMG: 0x1 = "", [1651673717.097273][3341910:3341915] CHIP:DMG: }, [1651673717.097286][3341910:3341915] CHIP:DMG: }, [1651673717.097306][3341910:3341915] CHIP:DMG: [1651673717.097320][3341910:3341915] CHIP:DMG: }, [1651673717.097340][3341910:3341915] CHIP:DMG: [1651673717.097353][3341910:3341915] CHIP:DMG: ], [1651673717.097375][3341910:3341915] CHIP:DMG: [1651673717.097390][3341910:3341915] CHIP:DMG: InteractionModelRevision = 1 [1651673717.097404][3341910:3341915] CHIP:DMG: }, [1651673717.097457][3341910:3341915] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0003 [1651673717.097485][3341910:3341915] CHIP:CTL: Received SetRegulatoryConfig response errorCode=0 [1651673717.097503][3341910:3341915] CHIP:CTL: Successfully finished commissioning step 'ConfigRegulatory' [1651673717.097515][3341910:3341915] CHIP:CTL: Commissioning stage next step: 'ConfigRegulatory' -> 'SendPAICertificateRequest' [1651673717.097529][3341910:3341915] CHIP:CTL: Performing next commissioning step 'SendPAICertificateRequest' [1651673717.097539][3341910:3341915] CHIP:CTL: Sending request for PAI certificate [1651673717.097548][3341910:3341915] CHIP:CTL: Sending Certificate Chain request to 0x7fa804000b60 device [1651673717.097585][3341910:3341915] CHIP:DMG: ICR moving to [AddingComm] [1651673717.097619][3341910:3341915] CHIP:DMG: ICR moving to [AddedComma] [1651673717.097672][3341910:3341915] CHIP:IN: Prepared secure message 0x7fa8192e5200 to 0xFFFFFFFB00000000 (0) of type 0x8 and protocolId (0, 1) on exchange 43607i with MessageCounter:7804569. [1651673717.097697][3341910:3341915] CHIP:IN: Sending encrypted msg 0x7fa8192e5200 with MessageCounter:7804569 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000001B0BCAAE msec [1651673717.097720][3341910:3341915] CHIP:DMG: ICR moving to [CommandSen] [1651673717.097761][3341910:3341915] CHIP:DMG: ICR moving to [AwaitingDe] [1651673717.229913][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673717.319360][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673717.409904][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673717.499752][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673717.501260][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673717.501416][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673717.589639][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673717.769708][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673717.769742][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673717.860101][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673717.860164][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673717.950663][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673717.950793][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673718.039800][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673718.041862][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673718.042047][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673718.131315][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673718.131516][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673718.220692][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673718.220850][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673718.310721][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673718.310877][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673718.399244][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673718.445943][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673718.446136][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673718.534685][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673718.534746][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673718.624977][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673718.625076][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673718.715922][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673718.716124][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673718.805306][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673718.807034][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673718.807230][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673718.894945][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673718.895048][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673718.986273][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673718.986472][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673719.076083][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673719.076284][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673719.164812][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673719.166412][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673719.166569][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673719.256074][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673719.256223][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673719.346061][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673719.346258][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673719.435953][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673719.436049][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673719.524729][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673719.526426][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673719.526635][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673719.616107][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673719.616342][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673719.705027][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673719.705104][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673719.796098][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673719.796215][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673719.884259][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673719.885388][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673719.885425][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673719.975995][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673719.976116][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673720.066149][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673720.066325][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673720.155954][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673720.156134][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673720.244239][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673720.245418][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673720.245460][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673720.336022][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673720.336216][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673720.425783][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673720.425920][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673720.426027][3341910:3341915] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:16337834 on exchange 43607i [1651673720.426055][3341910:3341915] CHIP:EM: Found matching exchange: 43607i, Delegate: 0x7fa804007800 [1651673720.426083][3341910:3341915] CHIP:DMG: ICR moving to [ResponseRe] [1651673720.426129][3341910:3341915] CHIP:DMG: InvokeResponseMessage = [1651673720.426145][3341910:3341915] CHIP:DMG: { [1651673720.426160][3341910:3341915] CHIP:DMG: suppressResponse = false, [1651673720.426177][3341910:3341915] CHIP:DMG: InvokeResponseIBs = [1651673720.426204][3341910:3341915] CHIP:DMG: [ [1651673720.426220][3341910:3341915] CHIP:DMG: InvokeResponseIB = [1651673720.426246][3341910:3341915] CHIP:DMG: { [1651673720.426262][3341910:3341915] CHIP:DMG: CommandDataIB = [1651673720.426282][3341910:3341915] CHIP:DMG: { [1651673720.426305][3341910:3341915] CHIP:DMG: CommandPathIB = [1651673720.426324][3341910:3341915] CHIP:DMG: { [1651673720.426343][3341910:3341915] CHIP:DMG: EndpointId = 0x0, [1651673720.426364][3341910:3341915] CHIP:DMG: ClusterId = 0x3e, [1651673720.426386][3341910:3341915] CHIP:DMG: CommandId = 0x3, [1651673720.426404][3341910:3341915] CHIP:DMG: }, [1651673720.426427][3341910:3341915] CHIP:DMG: [1651673720.426444][3341910:3341915] CHIP:DMG: CommandData = [1651673720.426463][3341910:3341915] CHIP:DMG: { [1651673720.426481][3341910:3341915] CHIP:DMG: 0x0 = [ [1651673720.426500][3341910:3341915] CHIP:DMG: ... (byte string too long) ... [1651673720.426527][3341910:3341915] CHIP:DMG: ] [1651673720.426550][3341910:3341915] CHIP:DMG: }, [1651673720.426567][3341910:3341915] CHIP:DMG: }, [1651673720.426591][3341910:3341915] CHIP:DMG: [1651673720.426607][3341910:3341915] CHIP:DMG: }, [1651673720.426631][3341910:3341915] CHIP:DMG: [1651673720.426661][3341910:3341915] CHIP:DMG: ], [1651673720.426683][3341910:3341915] CHIP:DMG: [1651673720.426697][3341910:3341915] CHIP:DMG: InteractionModelRevision = 1 [1651673720.426710][3341910:3341915] CHIP:DMG: }, [1651673720.426763][3341910:3341915] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003 [1651673720.426788][3341910:3341915] CHIP:CTL: Received certificate chain from the device [1651673720.426807][3341910:3341915] CHIP:CTL: Successfully finished commissioning step 'SendPAICertificateRequest' [1651673720.426825][3341910:3341915] CHIP:CTL: Commissioning stage next step: 'SendPAICertificateRequest' -> 'SendDACCertificateRequest' [1651673720.426841][3341910:3341915] CHIP:CTL: Performing next commissioning step 'SendDACCertificateRequest' [1651673720.426855][3341910:3341915] CHIP:CTL: Sending request for DAC certificate [1651673720.426867][3341910:3341915] CHIP:CTL: Sending Certificate Chain request to 0x7fa804000b60 device [1651673720.426908][3341910:3341915] CHIP:DMG: ICR moving to [AddingComm] [1651673720.426927][3341910:3341915] CHIP:DMG: ICR moving to [AddedComma] [1651673720.426981][3341910:3341915] CHIP:IN: Prepared secure message 0x7fa8192e5230 to 0xFFFFFFFB00000000 (0) of type 0x8 and protocolId (0, 1) on exchange 43608i with MessageCounter:7804570. [1651673720.427008][3341910:3341915] CHIP:IN: Sending encrypted msg 0x7fa8192e5230 with MessageCounter:7804570 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000001B0BD7AF msec [1651673720.427083][3341910:3341915] CHIP:DMG: ICR moving to [CommandSen] [1651673720.427128][3341910:3341915] CHIP:DMG: ICR moving to [AwaitingDe] [1651673720.514289][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673720.606148][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673720.739569][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673720.829223][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673720.830273][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673720.830325][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673721.055903][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673721.056120][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673721.145744][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673721.145894][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673721.236819][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673721.237019][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673721.369988][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673721.371463][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673721.371677][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673721.460799][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673721.460978][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673721.550062][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673721.550124][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673721.640928][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673721.641042][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673721.729743][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673721.731276][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673721.731442][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673721.819906][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673721.819992][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673721.911021][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673721.911208][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673722.001103][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673722.001239][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673722.089780][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673722.091320][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673722.091466][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673722.180906][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673722.181082][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673722.271073][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673722.271259][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673722.362059][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673722.362235][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673722.494785][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673722.496811][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673722.496920][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673722.585221][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673722.585312][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673722.676099][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673722.676241][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673722.765944][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673722.766077][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673722.854471][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673722.856720][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673722.856875][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673722.946528][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673722.946735][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673723.036523][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673723.036751][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673723.125614][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673723.125778][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673723.214785][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673723.216726][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673723.216908][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673723.306130][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673723.306345][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673723.396249][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673723.396452][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673723.485588][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673723.485745][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673723.575877][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673723.576548][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673723.576690][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673723.665529][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673723.665663][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673723.756819][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673723.756991][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673723.844973][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673723.845065][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673723.935002][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673723.936374][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673723.936511][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673723.936620][3341910:3341915] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:16337835 on exchange 43608i [1651673723.936645][3341910:3341915] CHIP:EM: Found matching exchange: 43608i, Delegate: 0x7fa8040107d0 [1651673723.936669][3341910:3341915] CHIP:DMG: ICR moving to [ResponseRe] [1651673723.936707][3341910:3341915] CHIP:DMG: InvokeResponseMessage = [1651673723.936727][3341910:3341915] CHIP:DMG: { [1651673723.936744][3341910:3341915] CHIP:DMG: suppressResponse = false, [1651673723.936757][3341910:3341915] CHIP:DMG: InvokeResponseIBs = [1651673723.936781][3341910:3341915] CHIP:DMG: [ [1651673723.936795][3341910:3341915] CHIP:DMG: InvokeResponseIB = [1651673723.936819][3341910:3341915] CHIP:DMG: { [1651673723.936834][3341910:3341915] CHIP:DMG: CommandDataIB = [1651673723.936851][3341910:3341915] CHIP:DMG: { [1651673723.936867][3341910:3341915] CHIP:DMG: CommandPathIB = [1651673723.936885][3341910:3341915] CHIP:DMG: { [1651673723.936902][3341910:3341915] CHIP:DMG: EndpointId = 0x0, [1651673723.936921][3341910:3341915] CHIP:DMG: ClusterId = 0x3e, [1651673723.936940][3341910:3341915] CHIP:DMG: CommandId = 0x3, [1651673723.936956][3341910:3341915] CHIP:DMG: }, [1651673723.936977][3341910:3341915] CHIP:DMG: [1651673723.936992][3341910:3341915] CHIP:DMG: CommandData = [1651673723.937010][3341910:3341915] CHIP:DMG: { [1651673723.937028][3341910:3341915] CHIP:DMG: 0x0 = [ [1651673723.937044][3341910:3341915] CHIP:DMG: ... (byte string too long) ... [1651673723.937062][3341910:3341915] CHIP:DMG: ] [1651673723.937078][3341910:3341915] CHIP:DMG: }, [1651673723.937093][3341910:3341915] CHIP:DMG: }, [1651673723.937116][3341910:3341915] CHIP:DMG: [1651673723.937130][3341910:3341915] CHIP:DMG: }, [1651673723.937151][3341910:3341915] CHIP:DMG: [1651673723.937165][3341910:3341915] CHIP:DMG: ], [1651673723.937188][3341910:3341915] CHIP:DMG: [1651673723.937205][3341910:3341915] CHIP:DMG: InteractionModelRevision = 1 [1651673723.937219][3341910:3341915] CHIP:DMG: }, [1651673723.937277][3341910:3341915] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003 [1651673723.937301][3341910:3341915] CHIP:CTL: Received certificate chain from the device [1651673723.937319][3341910:3341915] CHIP:CTL: Successfully finished commissioning step 'SendDACCertificateRequest' [1651673723.937334][3341910:3341915] CHIP:CTL: Commissioning stage next step: 'SendDACCertificateRequest' -> 'SendAttestationRequest' [1651673723.937352][3341910:3341915] CHIP:CTL: Performing next commissioning step 'SendAttestationRequest' [1651673723.937366][3341910:3341915] CHIP:CTL: Sending Attestation Request to the device. [1651673723.937380][3341910:3341915] CHIP:CTL: Sending Attestation request to 0x7fa804000b60 device [1651673723.937421][3341910:3341915] CHIP:DMG: ICR moving to [AddingComm] [1651673723.937441][3341910:3341915] CHIP:DMG: ICR moving to [AddedComma] [1651673723.937493][3341910:3341915] CHIP:IN: Prepared secure message 0x7fa8192e5210 to 0xFFFFFFFB00000000 (0) of type 0x8 and protocolId (0, 1) on exchange 43609i with MessageCounter:7804571. [1651673723.937521][3341910:3341915] CHIP:IN: Sending encrypted msg 0x7fa8192e5210 with MessageCounter:7804571 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000001B0BE565 msec [1651673723.937588][3341910:3341915] CHIP:DMG: ICR moving to [CommandSen] [1651673723.937609][3341910:3341915] CHIP:CTL: Sent Attestation request, waiting for the Attestation Information [1651673723.937646][3341910:3341915] CHIP:DMG: ICR moving to [AwaitingDe] [1651673724.024953][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673724.115152][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673724.204966][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673724.206361][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673724.206534][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673724.295962][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673724.429913][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673724.519720][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673724.745170][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673724.745256][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673724.836464][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673724.836651][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673724.925908][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673724.926086][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673725.016389][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673725.016521][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673725.104842][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673725.106547][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673725.106685][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673725.195227][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673725.195309][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673725.286213][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673725.286351][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673725.376067][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673725.376262][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673725.464856][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673725.466387][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673725.466545][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673725.601034][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673725.601227][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673725.645944][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673725.646154][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673725.735708][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673725.735812][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673725.824836][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673725.826559][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673725.826741][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673725.915996][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673725.916191][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673726.051012][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673726.051175][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673726.139988][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673726.140042][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673726.229772][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673726.231486][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673726.231693][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673726.319969][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673726.320051][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673726.411184][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673726.411376][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673726.501056][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673726.501248][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673726.589891][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673726.591539][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673726.591747][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673726.681203][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673726.681354][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673726.769900][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673726.769974][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673726.860979][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673726.861124][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673726.949644][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673726.952020][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673726.952189][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673727.041396][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673727.041577][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673727.131072][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673727.131262][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673727.220919][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673727.221077][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673727.309392][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673727.310652][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673727.310725][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673727.400561][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673727.400706][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673727.490271][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673727.490383][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673727.579995][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673727.580048][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673727.669822][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673727.671514][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673727.671721][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673727.762118][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673727.762281][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673727.850413][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673727.850517][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673727.940206][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673727.940287][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673728.029810][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673728.031437][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673728.031552][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673728.165967][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673728.166243][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673728.256284][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673728.256521][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673728.346843][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673728.347373][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673728.436051][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673728.436683][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673728.436796][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673728.436863][3341910:3341915] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:16337836 on exchange 43609i [1651673728.436878][3341910:3341915] CHIP:EM: Found matching exchange: 43609i, Delegate: 0x7fa804007800 [1651673728.436898][3341910:3341915] CHIP:DMG: ICR moving to [ResponseRe] [1651673728.436924][3341910:3341915] CHIP:DMG: InvokeResponseMessage = [1651673728.436933][3341910:3341915] CHIP:DMG: { [1651673728.436942][3341910:3341915] CHIP:DMG: suppressResponse = false, [1651673728.436953][3341910:3341915] CHIP:DMG: InvokeResponseIBs = [1651673728.436966][3341910:3341915] CHIP:DMG: [ [1651673728.436975][3341910:3341915] CHIP:DMG: InvokeResponseIB = [1651673728.436990][3341910:3341915] CHIP:DMG: { [1651673728.436999][3341910:3341915] CHIP:DMG: CommandDataIB = [1651673728.437009][3341910:3341915] CHIP:DMG: { [1651673728.437019][3341910:3341915] CHIP:DMG: CommandPathIB = [1651673728.437030][3341910:3341915] CHIP:DMG: { [1651673728.437041][3341910:3341915] CHIP:DMG: EndpointId = 0x0, [1651673728.437052][3341910:3341915] CHIP:DMG: ClusterId = 0x3e, [1651673728.437064][3341910:3341915] CHIP:DMG: CommandId = 0x1, [1651673728.437074][3341910:3341915] CHIP:DMG: }, [1651673728.437085][3341910:3341915] CHIP:DMG: [1651673728.437095][3341910:3341915] CHIP:DMG: CommandData = [1651673728.437105][3341910:3341915] CHIP:DMG: { [1651673728.437116][3341910:3341915] CHIP:DMG: 0x0 = [ [1651673728.437127][3341910:3341915] CHIP:DMG: ... (byte string too long) ... [1651673728.437138][3341910:3341915] CHIP:DMG: ] [1651673728.437148][3341910:3341915] CHIP:DMG: 0x1 = [ [1651673728.437167][3341910:3341915] CHIP:DMG: 0xba, 0x91, 0x98, 0x4e, 0x99, 0xc1, 0x96, 0x2f, 0xef, 0x8e, 0x14, 0x4a, 0x68, 0x5e, 0xda, 0xc6, 0x79, 0xbf, 0x17, 0x67, 0x83, 0x7d, 0xe, 0x83, 0xbf, 0x48, 0xa7, 0xe8, 0xde, 0x1, 0x61, 0xb8, 0x1c, 0x9f, 0x9b, 0xdf, 0xea, 0x77, 0x62, 0xf2, 0x63, 0x36, [1651673728.437182][3341910:3341915] CHIP:DMG: ] [1651673728.437192][3341910:3341915] CHIP:DMG: }, [1651673728.437203][3341910:3341915] CHIP:DMG: }, [1651673728.437216][3341910:3341915] CHIP:DMG: [1651673728.437225][3341910:3341915] CHIP:DMG: }, [1651673728.437240][3341910:3341915] CHIP:DMG: [1651673728.437248][3341910:3341915] CHIP:DMG: ], [1651673728.437262][3341910:3341915] CHIP:DMG: [1651673728.437271][3341910:3341915] CHIP:DMG: InteractionModelRevision = 1 [1651673728.437280][3341910:3341915] CHIP:DMG: }, [1651673728.437317][3341910:3341915] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0001 [1651673728.437335][3341910:3341915] CHIP:CTL: Received Attestation Information from the device [1651673728.437349][3341910:3341915] CHIP:CTL: Successfully finished commissioning step 'SendAttestationRequest' [1651673728.437376][3341910:3341915] CHIP:CTL: Commissioning stage next step: 'SendAttestationRequest' -> 'AttestationVerification' [1651673728.437386][3341910:3341915] CHIP:CTL: Performing next commissioning step 'AttestationVerification' [1651673728.437395][3341910:3341915] CHIP:CTL: Verifying attestation [1651673728.440229][3341910:3341915] CHIP:CTL: Failed in verifying 'Attestation Information' command received from the device: err 604. Look at AttestationVerificationResult enum to understand the errors [1651673728.440257][3341910:3341915] CHIP:CTL: Error on commissioning step 'AttestationVerification': '../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:945: CHIP Error 0x000000AC: Internal error' [1651673728.440267][3341910:3341915] CHIP:CTL: Failed to perform commissioning step 8 [1651673728.440276][3341910:3341915] CHIP:CTL: Going from commissioning step 'AttestationVerification' with lastErr = '../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:945: CHIP Error 0x000000AC: Internal error' -> 'Cleanup' [1651673728.440288][3341910:3341915] CHIP:CTL: Performing next commissioning step 'Cleanup' with completion status = '../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:945: CHIP Error 0x000000AC: Internal error' [1651673728.440299][3341910:3341915] CHIP:CTL: Expiring failsafe on proxy 0x7fa804000b60 [1651673728.440332][3341910:3341915] CHIP:DMG: ICR moving to [AddingComm] [1651673728.440347][3341910:3341915] CHIP:DMG: ICR moving to [AddedComma] [1651673728.440384][3341910:3341915] CHIP:IN: Prepared secure message 0x7fa8192e4840 to 0xFFFFFFFB00000000 (0) of type 0x8 and protocolId (0, 1) on exchange 43610i with MessageCounter:7804572. [1651673728.440411][3341910:3341915] CHIP:IN: Sending encrypted msg 0x7fa8192e4840 with MessageCounter:7804572 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000001B0BF6FC msec [1651673728.440454][3341910:3341915] CHIP:DMG: ICR moving to [CommandSen] [1651673728.440488][3341910:3341915] CHIP:DMG: ICR moving to [AwaitingDe] [1651673728.570191][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673728.660511][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673728.749471][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673728.750354][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673728.750428][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673728.839830][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1651673729.019956][3341910:3341913] CHIP:DL: Indication received, conn = 0x7fa81004ac20 [1651673729.020007][3341910:3341915] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1651673729.155620][3341910:3341913] CHIP:DL: Bluez disconnected [1651673729.155634][3341910:3341913] CHIP:DL: Bluez notify CHIPoBluez connection disconnected [1651673729.155684][3341910:3341915] CHIP:IN: Clearing BLE pending packets. [1651673740.441622][3341910:3341915] CHIP:DMG: Time out! failed to receive invoke command response from Exchange: 43610i [1651673740.441651][3341910:3341915] CHIP:CTL: Received failure response when disarming failsafe../examples/chip-tool/third_party/connectedhomeip/src/app/CommandSender.cpp:211: CHIP Error 0x00000032: Timeout [1651673740.441664][3341910:3341915] CHIP:CTL: Successfully finished commissioning step 'Cleanup' [1651673740.441674][3341910:3341915] CHIP:TOO: Device commissioning Failure: ../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:945: CHIP Error 0x000000AC: Internal error [1651673740.441703][3341910:3341915] CHIP:DIS: Closing all BLE connections [1651673740.441732][3341910:3341915] CHIP:DMG: ICR moving to [AwaitingDe] [1651673740.441877][3341910:3341910] CHIP:CTL: Shutting down the commissioner [1651673740.441921][3341910:3341910] CHIP:CTL: Shutting down the controller [1651673740.441935][3341910:3341910] CHIP:CTL: Shutting down the commissioner [1651673740.441953][3341910:3341910] CHIP:CTL: Shutting down the controller [1651673740.441959][3341910:3341910] CHIP:IN: Expiring all connections for fabric 1!! [1651673740.441973][3341910:3341910] CHIP:CTL: Shutting down the commissioner [1651673740.441988][3341910:3341910] CHIP:CTL: Shutting down the controller [1651673740.441993][3341910:3341910] CHIP:IN: Expiring all connections for fabric 2!! [1651673740.442002][3341910:3341910] CHIP:CTL: Shutting down the commissioner [1651673740.442017][3341910:3341910] CHIP:CTL: Shutting down the controller [1651673740.442021][3341910:3341910] CHIP:IN: Expiring all connections for fabric 3!! [1651673740.442029][3341910:3341910] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1651673740.442114][3341910:3341910] CHIP:DMG: IM WH moving to [Uninitialized] [1651673740.442120][3341910:3341910] CHIP:DMG: IM WH moving to [Uninitialized] [1651673740.442124][3341910:3341910] CHIP:DMG: IM WH moving to [Uninitialized] [1651673740.442128][3341910:3341910] CHIP:DMG: IM WH moving to [Uninitialized] [1651673740.442133][3341910:3341910] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1651673740.442150][3341910:3341910] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented. [1651673740.442251][3341910:3341910] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-dGLb4K) [1651673740.442437][3341910:3341910] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1651673740.442456][3341910:3341910] CHIP:DL: NVS set: chip-counters/total-operational-hours = 17 (0x11) [1651673740.442462][3341910:3341910] CHIP:DL: Inet Layer shutdown [1651673740.442467][3341910:3341910] CHIP:DL: BLE shutdown [1651673740.442807][3341910:3341910] CHIP:DL: System Layer shutdown [1651673740.442863][3341910:3341910] CHIP:TOO: Run command failure: ../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:945: CHIP Error 0x000000AC: Internal error