$ ./out/debug/chip-tool pairing ble-wifi 12344321 $SSID $PASSWORD 20202021 3840 [1657719495.979444][3305:3305] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1657719495.980323][3305:3305] CHIP:DL: writing settings to file (/tmp/chip_kvs-82mKd5) [1657719495.980738][3305:3305] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1657719495.981220][3305:3305] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1657719495.981534][3305:3305] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-gcO606) [1657719495.981883][3305:3305] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1657719495.982130][3305:3305] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1657719495.982404][3305:3305] CHIP:DL: writing settings to file (/tmp/chip_config.ini-FpjjX5) [1657719495.982737][3305:3305] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1657719495.982978][3305:3305] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1657719495.983251][3305:3305] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-hJBX37) [1657719495.983618][3305:3305] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1657719495.984024][3305:3305] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-ocLwz5) [1657719495.984744][3305:3305] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1657719495.984994][3305:3305] CHIP:DL: NVS set: chip-factory/unique-id = "7E711E98573AB502" [1657719495.985377][3305:3305] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-GO8Iw6) [1657719495.986048][3305:3305] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1657719495.986274][3305:3305] CHIP:DL: NVS set: chip-factory/vendor-id = 65521 (0xFFF1) [1657719495.986586][3305:3305] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-SZEZk5) [1657719495.987235][3305:3305] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1657719495.987463][3305:3305] CHIP:DL: NVS set: chip-factory/product-id = 32769 (0x8001) [1657719495.987874][3305:3305] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-gUi6r8) [1657719495.988453][3305:3305] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1657719495.988737][3305:3305] CHIP:DL: NVS set: chip-counters/reboot-count = 1 (0x1) [1657719495.989050][3305:3305] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-wtspE5) [1657719495.989684][3305:3305] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1657719495.992527][3305:3305] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1657719495.992951][3305:3305] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-mDGa68) [1657719495.993720][3305:3305] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1657719495.993961][3305:3305] CHIP:DL: NVS set: chip-counters/boot-reason = 0 (0x0) [1657719495.994342][3305:3305] CHIP:DL: writing settings to file (/tmp/chip_config.ini-HAn6U6) [1657719495.995050][3305:3305] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1657719495.995207][3305:3305] CHIP:DL: NVS set: chip-config/regulatory-location = 0 (0x0) [1657719495.995373][3305:3305] CHIP:DL: writing settings to file (/tmp/chip_config.ini-9NShl7) [1657719495.996030][3305:3305] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1657719495.996109][3305:3305] CHIP:DL: NVS set: chip-config/location-capability = 2 (0x2) [1657719495.996580][3305:3305] CHIP:DL: Failed to get Ethernet interface [1657719495.997073][3305:3305] CHIP:DL: Failed to reset Ethernet statistic counts [1657719495.997396][3305:3305] CHIP:DL: Got WiFi interface: wlp1s0 [1657719495.998708][3305:3305] CHIP:DL: Found the primary WiFi interface:wlp1s0 [1657719495.998825][3305:3305] CHIP:IN: UDP::Init bind&listen port=0 [1657719495.999052][3305:3305] CHIP:IN: UDP::Init bound to port=41018 [1657719495.999070][3305:3305] CHIP:IN: UDP::Init bind&listen port=0 [1657719495.999194][3305:3305] CHIP:IN: UDP::Init bound to port=35392 [1657719495.999212][3305:3305] CHIP:IN: BLEBase::Init - setting/overriding transport [1657719495.999222][3305:3305] CHIP:IN: TransportMgr initialized [1657719495.999245][3305:3305] CHIP:FP: Initializing FabricTable from persistent storage [1657719495.999364][3305:3305] CHIP:TS: Last Known Good Time: [unknown] [1657719495.999386][3305:3305] CHIP:TS: Setting Last Known Good Time to firmware build time 2022-07-13T21:11:01 [1657719496.001562][3305:3305] CHIP:ZCL: Using ZAP configuration... [1657719496.002613][3305:3305] CHIP:CTL: System State Initialized... [1657719496.002872][3305:3305] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1657719496.003048][3305:3305] CHIP:CTL: Setting attestation nonce to random value [1657719496.003238][3305:3305] CHIP:CTL: Setting CSR nonce to random value [1657719496.003444][3305:3305] CHIP:IN: UDP::Init bind&listen port=5550 [1657719496.003707][3305:3305] CHIP:IN: UDP::Init bound to port=5550 [1657719496.003880][3305:3305] CHIP:IN: UDP::Init bind&listen port=5550 [1657719496.004072][3305:3305] CHIP:IN: UDP::Init bound to port=5550 [1657719496.004238][3305:3305] CHIP:IN: TransportMgr initialized [1657719496.004493][3305:3305] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1657719496.004667][3305:3305] CHIP:CTL: Setting attestation nonce to random value [1657719496.004845][3305:3305] CHIP:CTL: Setting CSR nonce to random value [1657719496.007033][3305:3305] CHIP:CTL: Couldn't get ExampleOpCredsCAKey from storage: ../../config/PersistentStorage.cpp:85: CHIP Error 0x000000A0: Value not found in the persisted storage [1657719496.010988][3305:3305] CHIP:CTL: Couldn't get ExampleOpCredsICAKey from storage: ../../config/PersistentStorage.cpp:85: CHIP Error 0x000000A0: Value not found in the persisted storage [1657719496.016404][3305:3305] CHIP:CTL: Generating RCAC [1657719496.017821][3305:3305] CHIP:CTL: Generating ICAC [1657719496.019289][3305:3305] CHIP:CTL: Generating NOC [1657719496.020823][3305:3305] CHIP:FP: Validating NOC chain [1657719496.023626][3305:3305] CHIP:FP: NOC chain validation successful [1657719496.024057][3305:3305] CHIP:FP: Added new fabric at index: 0x1 [1657719496.024230][3305:3305] CHIP:FP: Assigned compressed fabric ID: 0x17A3FD1E872A364A, node ID: 0x000000000001B669 [1657719496.024421][3305:3305] CHIP:TS: Last Known Good Time: 2022-07-13T21:11:01 [1657719496.024586][3305:3305] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1657719496.024745][3305:3305] CHIP:TS: Retaining current Last Known Good Time [1657719496.029820][3305:3305] CHIP:FP: Metadata for Fabric 0x1 persisted to storage. [1657719496.032222][3305:3305] CHIP:TS: Committing Last Known Good Time to storage: 2022-07-13T21:11:01 [1657719496.034424][3305:3305] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x0000000000000000 [1657719496.034678][3305:3305] CHIP:IN: UDP::Init bind&listen port=5550 [1657719496.034906][3305:3305] CHIP:IN: UDP::Init bound to port=5550 [1657719496.035077][3305:3305] CHIP:IN: UDP::Init bind&listen port=5550 [1657719496.035401][3305:3305] CHIP:IN: UDP::Init bound to port=5550 [1657719496.035833][3305:3305] CHIP:IN: TransportMgr initialized [1657719496.036317][3305:3305] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1657719496.040644][3305:3305] CHIP:CTL: Setting attestation nonce to random value [1657719496.040886][3305:3305] CHIP:CTL: Setting CSR nonce to random value [1657719496.042645][3305:3305] CHIP:CTL: Generating NOC [1657719496.043845][3305:3305] CHIP:FP: Validating NOC chain [1657719496.046346][3305:3305] CHIP:FP: NOC chain validation successful [1657719496.046714][3305:3305] CHIP:FP: Added new fabric at index: 0x2 [1657719496.046886][3305:3305] CHIP:FP: Assigned compressed fabric ID: 0xFB6F676AC991DB22, node ID: 0x000000000001B669 [1657719496.047055][3305:3305] CHIP:TS: Last Known Good Time: 2022-07-13T21:11:01 [1657719496.047220][3305:3305] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1657719496.047417][3305:3305] CHIP:TS: Retaining current Last Known Good Time [1657719496.049239][3305:3305] CHIP:FP: Metadata for Fabric 0x2 persisted to storage. [1657719496.052182][3305:3305] CHIP:TS: Committing Last Known Good Time to storage: 2022-07-13T21:11:01 [1657719496.054587][3305:3305] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x0000000000000000 [1657719496.054844][3305:3305] CHIP:IN: UDP::Init bind&listen port=5550 [1657719496.055065][3305:3305] CHIP:IN: UDP::Init bound to port=5550 [1657719496.055234][3305:3305] CHIP:IN: UDP::Init bind&listen port=5550 [1657719496.055431][3305:3305] CHIP:IN: UDP::Init bound to port=5550 [1657719496.055837][3305:3305] CHIP:IN: TransportMgr initialized [1657719496.056169][3305:3305] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1657719496.056347][3305:3305] CHIP:CTL: Setting attestation nonce to random value [1657719496.056533][3305:3305] CHIP:CTL: Setting CSR nonce to random value [1657719496.058239][3305:3305] CHIP:CTL: Generating NOC [1657719496.059333][3305:3305] CHIP:FP: Validating NOC chain [1657719496.062302][3305:3305] CHIP:FP: NOC chain validation successful [1657719496.062692][3305:3305] CHIP:FP: Added new fabric at index: 0x3 [1657719496.062865][3305:3305] CHIP:FP: Assigned compressed fabric ID: 0xBD49B85350124E22, node ID: 0x000000000001B669 [1657719496.063034][3305:3305] CHIP:TS: Last Known Good Time: 2022-07-13T21:11:01 [1657719496.063201][3305:3305] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1657719496.063359][3305:3305] CHIP:TS: Retaining current Last Known Good Time [1657719496.065270][3305:3305] CHIP:FP: Metadata for Fabric 0x3 persisted to storage. [1657719496.067897][3305:3305] CHIP:TS: Committing Last Known Good Time to storage: 2022-07-13T21:11:01 [1657719496.076281][3305:3305] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0x0000000000000000 [1657719496.076571][3305:3305] CHIP:IN: UDP::Init bind&listen port=5550 [1657719496.076795][3305:3305] CHIP:IN: UDP::Init bound to port=5550 [1657719496.076986][3305:3305] CHIP:IN: UDP::Init bind&listen port=5550 [1657719496.077185][3305:3305] CHIP:IN: UDP::Init bound to port=5550 [1657719496.077350][3305:3305] CHIP:IN: TransportMgr initialized [1657719496.161460][3305:3310] CHIP:DL: CHIP task running [1657719496.161827][3305:3310] CHIP:IN: SecureSession[0x7f7e30001a30]: Allocated Type:1 LSID:9583 [1657719496.161861][3305:3310] CHIP:SC: Assigned local session key ID 9583 [1657719496.161916][3305:3310] CHIP:SC: Including MRP parameters in PBKDF param request [1657719496.161974][3305:3310] CHIP:IN: Prepared unauthenticated message 0x7f7e437fd3f0 to 0x0000000000000000 (0) of type 0x20 and protocolId (0, 0) on exchange 21415i with MessageCounter:52219577. [1657719496.162009][3305:3310] CHIP:IN: Sending unauthenticated msg 0x7f7e437fd3f0 with MessageCounter:52219577 to 0x0000000000000000 at monotonic time: 000000000003ED4F msec [1657719496.162033][3305:3310] CHIP:IN: Message appended to BLE send queue [1657719496.162048][3305:3310] CHIP:SC: Sent PBKDF param request [1657719496.162066][3305:3310] CHIP:CTL: Setting wifi credentials from parameters [1657719496.162078][3305:3310] CHIP:CTL: Setting attestation nonce to random value [1657719496.162105][3305:3310] CHIP:CTL: Setting CSR nonce to random value [1657719496.162129][3305:3310] CHIP:CTL: Commission called for node ID 0x0000000000BC5C01 [1657719496.162346][3305:3311] CHIP:DL: TRACE: Bluez mainloop starting Thread [1657719496.162468][3305:3308] CHIP:DL: TRACE: Bus acquired for name C-0ce9 [1657719496.187906][3305:3310] CHIP:DL: PlatformBlueZInit init success [1657719496.218488][3305:3308] CHIP:BLE: BLE removing known devices. [1657719496.231039][3305:3308] CHIP:BLE: BLE initiating scan. [1657719496.328344][3305:3308] CHIP:BLE: New device scanned: C3:F4:36:29:FC:94 [1657719496.328394][3305:3308] CHIP:BLE: Device discriminator match. Attempting to connect. [1657719496.329952][3305:3308] CHIP:BLE: Scan complete notification without an active scan. [1657719496.720522][3305:3308] CHIP:DL: ConnectDevice complete [1657719497.697185][3305:3308] CHIP:DL: Char1 /org/bluez/hci0/dev_C3_F4_36_29_FC_94/service0006 [1657719497.697228][3305:3308] CHIP:DL: Char1 /org/bluez/hci0/dev_C3_F4_36_29_FC_94/service000a [1657719497.697244][3305:3308] CHIP:DL: Char1 /org/bluez/hci0/dev_C3_F4_36_29_FC_94/service0006 [1657719497.697259][3305:3308] CHIP:DL: Char1 /org/bluez/hci0/dev_C3_F4_36_29_FC_94/service000a [1657719497.697275][3305:3308] CHIP:DL: Char1 /org/bluez/hci0/dev_C3_F4_36_29_FC_94/service0006 [1657719497.697285][3305:3308] CHIP:DL: Char1 /org/bluez/hci0/dev_C3_F4_36_29_FC_94/service000a [1657719497.697307][3305:3308] CHIP:DL: Char1 /org/bluez/hci0/dev_C3_F4_36_29_FC_94/service000a [1657719497.697317][3305:3308] CHIP:DL: Char1 /org/bluez/hci0/dev_C3_F4_36_29_FC_94/service000a [1657719497.697343][3305:3308] CHIP:DL: Char1 /org/bluez/hci0/dev_C3_F4_36_29_FC_94/service000a [1657719497.697356][3305:3308] CHIP:DL: Char1 /org/bluez/hci0/dev_C3_F4_36_29_FC_94/service000a [1657719497.697373][3305:3308] CHIP:DL: Char1 /org/bluez/hci0/dev_C3_F4_36_29_FC_94/service000a [1657719497.697387][3305:3308] CHIP:DL: Char1 /org/bluez/hci0/dev_C3_F4_36_29_FC_94/service000a [1657719497.697408][3305:3308] CHIP:DL: New BLE connection 0x7f7e380360b0, device C3:F4:36:29:FC:94, path /org/bluez/hci0/dev_C3_F4_36_29_FC_94 [1657719497.697534][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16385 [1657719497.697557][3305:3310] CHIP:IN: BleConnectionComplete: endPoint 0x558c2ae5aae0 [1657719498.067372][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1657719498.168906][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16388 [1657719498.168950][3305:3310] CHIP:BLE: subscribe complete, ep = 0x558c2ae5aae0 [1657719498.218909][3305:3308] CHIP:DL: Indication received, conn = 0x7f7e380360b0 [1657719498.219064][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1657719498.219092][3305:3310] CHIP:BLE: peripheral chose BTP version 4; central expected between 4 and 4 [1657719498.219107][3305:3310] CHIP:BLE: using BTP fragment sizes rx 244 / tx 244. [1657719498.219117][3305:3310] CHIP:BLE: local and remote recv window size = 5 [1657719498.219196][3305:3310] CHIP:IN: BLE EndPoint 0x558c2ae5aae0 Connection Complete [1657719498.467330][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1657719498.768237][3305:3308] CHIP:DL: Indication received, conn = 0x7f7e380360b0 [1657719498.768373][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1657719498.768479][3305:3310] CHIP:EM: Received message of type 0x21 with protocolId (0, 0) and MessageCounter:112259361 on exchange 21415i [1657719498.768502][3305:3310] CHIP:EM: Found matching exchange: 21415i, Delegate: 0x7f7e30000bb0 [1657719498.768528][3305:3310] CHIP:SC: Received PBKDF param response [1657719498.768562][3305:3310] CHIP:SC: Peer assigned session ID 32646 [1657719498.768585][3305:3310] CHIP:SC: Found MRP parameters in the message [1657719498.774945][3305:3310] CHIP:IN: Prepared unauthenticated message 0x7f7e437fcfe0 to 0x0000000000000000 (0) of type 0x22 and protocolId (0, 0) on exchange 21415i with MessageCounter:52219578. [1657719498.775987][3305:3310] CHIP:IN: Sending unauthenticated msg 0x7f7e437fcfe0 with MessageCounter:52219578 to 0x0000000000000000 at monotonic time: 000000000003F785 msec [1657719498.776244][3305:3310] CHIP:SC: Sent spake2p msg1 [1657719499.017229][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1657719499.970324][3305:3308] CHIP:DL: Indication received, conn = 0x7f7e380360b0 [1657719499.970565][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1657719499.970669][3305:3310] CHIP:EM: Received message of type 0x23 with protocolId (0, 0) and MessageCounter:112259362 on exchange 21415i [1657719499.970690][3305:3310] CHIP:EM: Found matching exchange: 21415i, Delegate: 0x7f7e30000bb0 [1657719499.970713][3305:3310] CHIP:SC: Received spake2p msg2 [1657719499.972481][3305:3310] CHIP:IN: Prepared unauthenticated message 0x7f7e437fd0e0 to 0x0000000000000000 (0) of type 0x24 and protocolId (0, 0) on exchange 21415i with MessageCounter:52219579. [1657719499.972516][3305:3310] CHIP:IN: Sending unauthenticated msg 0x7f7e437fd0e0 with MessageCounter:52219579 to 0x0000000000000000 at monotonic time: 000000000003FC31 msec [1657719499.972597][3305:3310] CHIP:SC: Sent spake2p msg3 [1657719500.066292][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1657719500.167791][3305:3308] CHIP:DL: Indication received, conn = 0x7f7e380360b0 [1657719500.168048][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1657719500.168151][3305:3310] CHIP:EM: Received message of type 0x40 with protocolId (0, 0) and MessageCounter:112259363 on exchange 21415i [1657719500.168173][3305:3310] CHIP:EM: Found matching exchange: 21415i, Delegate: 0x7f7e30000bb0 [1657719500.168251][3305:3310] CHIP:SC: SecureSession[0x7f7e30001a30]: Moving from state 'kEstablishing' --> 'kActive' [1657719500.168267][3305:3310] CHIP:IN: SecureSession[0x7f7e30001a30]: Activated - Type:1 LSID:9583 [1657719500.168277][3305:3310] CHIP:IN: New secure session activated for device , LSID:9583 PSID:32646! [1657719500.168295][3305:3310] CHIP:CTL: Remote device completed SPAKE2+ handshake [1657719500.168305][3305:3310] CHIP:TOO: Pairing Success [1657719500.168311][3305:3310] CHIP:TOO: PASE establishment successful [1657719500.168321][3305:3310] CHIP:CTL: Commissioning stage next step: 'SecurePairing' -> 'ReadCommissioningInfo' [1657719500.168335][3305:3310] CHIP:CTL: Performing next commissioning step 'ReadCommissioningInfo' [1657719500.168344][3305:3310] CHIP:CTL: Sending request for commissioning information [1657719500.168373][3305:3310] CHIP:DMG: SendReadRequest ReadClient[0x7f7e38002c10]: Sending Read Request [1657719500.168484][3305:3310] CHIP:IN: Prepared secure message 0x7f7e437fc960 to 0xFFFFFFFB00000000 (0) of type 0x2 and protocolId (0, 1) on exchange 21416i with MessageCounter:255649376. [1657719500.168541][3305:3310] CHIP:IN: Sending encrypted msg 0x7f7e437fc960 with MessageCounter:255649376 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000003FCF5 msec [1657719500.168627][3305:3310] CHIP:DMG: MoveToState ReadClient[0x7f7e38002c10]: Moving to [AwaitingIn] [1657719500.266499][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1657719500.422126][3305:3308] CHIP:DL: Indication received, conn = 0x7f7e380360b0 [1657719500.422281][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1657719500.467315][3305:3308] CHIP:DL: Indication received, conn = 0x7f7e380360b0 [1657719500.467648][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1657719500.467785][3305:3310] CHIP:EM: Received message of type 0x5 with protocolId (0, 1) and MessageCounter:87106217 on exchange 21416i [1657719500.467808][3305:3310] CHIP:EM: Found matching exchange: 21416i, Delegate: 0x7f7e38002c10 [1657719500.467910][3305:3310] CHIP:DMG: ReportDataMessage = [1657719500.467927][3305:3310] CHIP:DMG: { [1657719500.467937][3305:3310] CHIP:DMG: AttributeReportIBs = [1657719500.467955][3305:3310] CHIP:DMG: [ [1657719500.467966][3305:3310] CHIP:DMG: AttributeReportIB = [1657719500.467986][3305:3310] CHIP:DMG: { [1657719500.467997][3305:3310] CHIP:DMG: AttributeDataIB = [1657719500.468020][3305:3310] CHIP:DMG: { [1657719500.468040][3305:3310] CHIP:DMG: DataVersion = 0x3823d072, [1657719500.468053][3305:3310] CHIP:DMG: AttributePathIB = [1657719500.468067][3305:3310] CHIP:DMG: { [1657719500.468081][3305:3310] CHIP:DMG: Endpoint = 0x0, [1657719500.468096][3305:3310] CHIP:DMG: Cluster = 0x31, [1657719500.468115][3305:3310] CHIP:DMG: Attribute = 0x0000_0003, [1657719500.468131][3305:3310] CHIP:DMG: } [1657719500.468149][3305:3310] CHIP:DMG: [1657719500.468169][3305:3310] CHIP:DMG: Data = 30, [1657719500.468184][3305:3310] CHIP:DMG: }, [1657719500.468204][3305:3310] CHIP:DMG: [1657719500.468218][3305:3310] CHIP:DMG: }, [1657719500.468246][3305:3310] CHIP:DMG: [1657719500.468260][3305:3310] CHIP:DMG: AttributeReportIB = [1657719500.468281][3305:3310] CHIP:DMG: { [1657719500.468296][3305:3310] CHIP:DMG: AttributeDataIB = [1657719500.468308][3305:3310] CHIP:DMG: { [1657719500.468326][3305:3310] CHIP:DMG: DataVersion = 0xa05d5a76, [1657719500.468341][3305:3310] CHIP:DMG: AttributePathIB = [1657719500.468357][3305:3310] CHIP:DMG: { [1657719500.468374][3305:3310] CHIP:DMG: Endpoint = 0x0, [1657719500.468392][3305:3310] CHIP:DMG: Cluster = 0x28, [1657719500.468409][3305:3310] CHIP:DMG: Attribute = 0x0000_0004, [1657719500.468424][3305:3310] CHIP:DMG: } [1657719500.468443][3305:3310] CHIP:DMG: [1657719500.468461][3305:3310] CHIP:DMG: Data = 32769, [1657719500.468475][3305:3310] CHIP:DMG: }, [1657719500.468496][3305:3310] CHIP:DMG: [1657719500.468510][3305:3310] CHIP:DMG: }, [1657719500.468537][3305:3310] CHIP:DMG: [1657719500.468551][3305:3310] CHIP:DMG: AttributeReportIB = [1657719500.468572][3305:3310] CHIP:DMG: { [1657719500.468587][3305:3310] CHIP:DMG: AttributeDataIB = [1657719500.468602][3305:3310] CHIP:DMG: { [1657719500.468619][3305:3310] CHIP:DMG: DataVersion = 0xa05d5a76, [1657719500.468635][3305:3310] CHIP:DMG: AttributePathIB = [1657719500.468650][3305:3310] CHIP:DMG: { [1657719500.468668][3305:3310] CHIP:DMG: Endpoint = 0x0, [1657719500.468685][3305:3310] CHIP:DMG: Cluster = 0x28, [1657719500.468703][3305:3310] CHIP:DMG: Attribute = 0x0000_0002, [1657719500.468718][3305:3310] CHIP:DMG: } [1657719500.468736][3305:3310] CHIP:DMG: [1657719500.468755][3305:3310] CHIP:DMG: Data = 65521, [1657719500.468769][3305:3310] CHIP:DMG: }, [1657719500.468788][3305:3310] CHIP:DMG: [1657719500.468802][3305:3310] CHIP:DMG: }, [1657719500.468828][3305:3310] CHIP:DMG: [1657719500.468843][3305:3310] CHIP:DMG: AttributeReportIB = [1657719500.468863][3305:3310] CHIP:DMG: { [1657719500.468878][3305:3310] CHIP:DMG: AttributeDataIB = [1657719500.468894][3305:3310] CHIP:DMG: { [1657719500.468911][3305:3310] CHIP:DMG: DataVersion = 0xfa35224a, [1657719500.468926][3305:3310] CHIP:DMG: AttributePathIB = [1657719500.468942][3305:3310] CHIP:DMG: { [1657719500.468958][3305:3310] CHIP:DMG: Endpoint = 0x0, [1657719500.468976][3305:3310] CHIP:DMG: Cluster = 0x30, [1657719500.468994][3305:3310] CHIP:DMG: Attribute = 0x0000_0003, [1657719500.469008][3305:3310] CHIP:DMG: } [1657719500.469026][3305:3310] CHIP:DMG: [1657719500.469044][3305:3310] CHIP:DMG: Data = 0, [1657719500.469059][3305:3310] CHIP:DMG: }, [1657719500.469077][3305:3310] CHIP:DMG: [1657719500.469091][3305:3310] CHIP:DMG: }, [1657719500.469117][3305:3310] CHIP:DMG: [1657719500.469130][3305:3310] CHIP:DMG: AttributeReportIB = [1657719500.469150][3305:3310] CHIP:DMG: { [1657719500.469165][3305:3310] CHIP:DMG: AttributeDataIB = [1657719500.469180][3305:3310] CHIP:DMG: { [1657719500.469196][3305:3310] CHIP:DMG: DataVersion = 0xfa35224a, [1657719500.469212][3305:3310] CHIP:DMG: AttributePathIB = [1657719500.469227][3305:3310] CHIP:DMG: { [1657719500.469244][3305:3310] CHIP:DMG: Endpoint = 0x0, [1657719500.469261][3305:3310] CHIP:DMG: Cluster = 0x30, [1657719500.469279][3305:3310] CHIP:DMG: Attribute = 0x0000_0002, [1657719500.469294][3305:3310] CHIP:DMG: } [1657719500.469312][3305:3310] CHIP:DMG: [1657719500.469329][3305:3310] CHIP:DMG: Data = 0, [1657719500.469345][3305:3310] CHIP:DMG: }, [1657719500.469364][3305:3310] CHIP:DMG: [1657719500.469378][3305:3310] CHIP:DMG: }, [1657719500.469413][3305:3310] CHIP:DMG: [1657719500.469428][3305:3310] CHIP:DMG: AttributeReportIB = [1657719500.469451][3305:3310] CHIP:DMG: { [1657719500.469465][3305:3310] CHIP:DMG: AttributeDataIB = [1657719500.469481][3305:3310] CHIP:DMG: { [1657719500.469498][3305:3310] CHIP:DMG: DataVersion = 0xfa35224a, [1657719500.469514][3305:3310] CHIP:DMG: AttributePathIB = [1657719500.469530][3305:3310] CHIP:DMG: { [1657719500.469547][3305:3310] CHIP:DMG: Endpoint = 0x0, [1657719500.469565][3305:3310] CHIP:DMG: Cluster = 0x30, [1657719500.469583][3305:3310] CHIP:DMG: Attribute = 0x0000_0001, [1657719500.469597][3305:3310] CHIP:DMG: } [1657719500.469616][3305:3310] CHIP:DMG: [1657719500.469631][3305:3310] CHIP:DMG: Data = [1657719500.469646][3305:3310] CHIP:DMG: { [1657719500.469667][3305:3310] CHIP:DMG: 0x0 = 60, [1657719500.469686][3305:3310] CHIP:DMG: 0x1 = 900, [1657719500.469703][3305:3310] CHIP:DMG: }, [1657719500.469717][3305:3310] CHIP:DMG: }, [1657719500.469737][3305:3310] CHIP:DMG: [1657719500.469751][3305:3310] CHIP:DMG: }, [1657719500.469779][3305:3310] CHIP:DMG: [1657719500.469793][3305:3310] CHIP:DMG: AttributeReportIB = [1657719500.469814][3305:3310] CHIP:DMG: { [1657719500.469828][3305:3310] CHIP:DMG: AttributeDataIB = [1657719500.469845][3305:3310] CHIP:DMG: { [1657719500.469862][3305:3310] CHIP:DMG: DataVersion = 0xfa35224a, [1657719500.469877][3305:3310] CHIP:DMG: AttributePathIB = [1657719500.469893][3305:3310] CHIP:DMG: { [1657719500.469910][3305:3310] CHIP:DMG: Endpoint = 0x0, [1657719500.469927][3305:3310] CHIP:DMG: Cluster = 0x30, [1657719500.469945][3305:3310] CHIP:DMG: Attribute = 0x0000_0000, [1657719500.469960][3305:3310] CHIP:DMG: } [1657719500.469979][3305:3310] CHIP:DMG: [1657719500.469997][3305:3310] CHIP:DMG: Data = 0, [1657719500.470011][3305:3310] CHIP:DMG: }, [1657719500.470030][3305:3310] CHIP:DMG: [1657719500.470043][3305:3310] CHIP:DMG: }, [1657719500.470070][3305:3310] CHIP:DMG: [1657719500.470083][3305:3310] CHIP:DMG: AttributeReportIB = [1657719500.470104][3305:3310] CHIP:DMG: { [1657719500.470118][3305:3310] CHIP:DMG: AttributeDataIB = [1657719500.470134][3305:3310] CHIP:DMG: { [1657719500.470153][3305:3310] CHIP:DMG: DataVersion = 0x3823d072, [1657719500.470168][3305:3310] CHIP:DMG: AttributePathIB = [1657719500.470184][3305:3310] CHIP:DMG: { [1657719500.470201][3305:3310] CHIP:DMG: Endpoint = 0x0, [1657719500.470219][3305:3310] CHIP:DMG: Cluster = 0x31, [1657719500.470237][3305:3310] CHIP:DMG: Attribute = 0x0000_FFFC, [1657719500.470252][3305:3310] CHIP:DMG: } [1657719500.470270][3305:3310] CHIP:DMG: [1657719500.470289][3305:3310] CHIP:DMG: Data = 1, [1657719500.470303][3305:3310] CHIP:DMG: }, [1657719500.470322][3305:3310] CHIP:DMG: [1657719500.470336][3305:3310] CHIP:DMG: }, [1657719500.470355][3305:3310] CHIP:DMG: [1657719500.470368][3305:3310] CHIP:DMG: ], [1657719500.470431][3305:3310] CHIP:DMG: [1657719500.470446][3305:3310] CHIP:DMG: SuppressResponse = true, [1657719500.470461][3305:3310] CHIP:DMG: InteractionModelRevision = 1 [1657719500.470474][3305:3310] CHIP:DMG: } [1657719500.471494][3305:3310] CHIP:CTL: Successfully finished commissioning step 'ReadCommissioningInfo' [1657719500.471521][3305:3310] CHIP:CTL: Commissioning stage next step: 'ReadCommissioningInfo' -> 'ArmFailSafe' [1657719500.471539][3305:3310] CHIP:CTL: Performing next commissioning step 'ArmFailSafe' [1657719500.472294][3305:3310] CHIP:CTL: Arming failsafe (60 seconds) [1657719500.472454][3305:3310] CHIP:DMG: ICR moving to [AddingComm] [1657719500.472481][3305:3310] CHIP:DMG: ICR moving to [AddedComma] [1657719500.472718][3305:3310] CHIP:IN: Prepared secure message 0x7f7e437fc6f0 to 0xFFFFFFFB00000000 (0) of type 0x8 and protocolId (0, 1) on exchange 21417i with MessageCounter:255649377. [1657719500.472756][3305:3310] CHIP:IN: Sending encrypted msg 0x7f7e437fc6f0 with MessageCounter:255649377 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000003FE25 msec [1657719500.473002][3305:3310] CHIP:DMG: ICR moving to [CommandSen] [1657719500.665984][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1657719500.817417][3305:3308] CHIP:DL: Indication received, conn = 0x7f7e380360b0 [1657719500.818076][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1657719500.818257][3305:3310] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:87106218 on exchange 21417i [1657719500.818285][3305:3310] CHIP:EM: Found matching exchange: 21417i, Delegate: 0x7f7e30004400 [1657719500.818315][3305:3310] CHIP:DMG: ICR moving to [ResponseRe] [1657719500.818365][3305:3310] CHIP:DMG: InvokeResponseMessage = [1657719500.818385][3305:3310] CHIP:DMG: { [1657719500.818402][3305:3310] CHIP:DMG: suppressResponse = false, [1657719500.818418][3305:3310] CHIP:DMG: InvokeResponseIBs = [1657719500.818443][3305:3310] CHIP:DMG: [ [1657719500.818458][3305:3310] CHIP:DMG: InvokeResponseIB = [1657719500.818484][3305:3310] CHIP:DMG: { [1657719500.818515][3305:3310] CHIP:DMG: CommandDataIB = [1657719500.818535][3305:3310] CHIP:DMG: { [1657719500.818551][3305:3310] CHIP:DMG: CommandPathIB = [1657719500.818570][3305:3310] CHIP:DMG: { [1657719500.818590][3305:3310] CHIP:DMG: EndpointId = 0x0, [1657719500.818610][3305:3310] CHIP:DMG: ClusterId = 0x30, [1657719500.818629][3305:3310] CHIP:DMG: CommandId = 0x1, [1657719500.818645][3305:3310] CHIP:DMG: }, [1657719500.818666][3305:3310] CHIP:DMG: [1657719500.818684][3305:3310] CHIP:DMG: CommandFields = [1657719500.818701][3305:3310] CHIP:DMG: { [1657719500.818721][3305:3310] CHIP:DMG: 0x0 = 0, [1657719500.818743][3305:3310] CHIP:DMG: 0x1 = "", [1657719500.818762][3305:3310] CHIP:DMG: }, [1657719500.818775][3305:3310] CHIP:DMG: }, [1657719500.818796][3305:3310] CHIP:DMG: [1657719500.818811][3305:3310] CHIP:DMG: }, [1657719500.818834][3305:3310] CHIP:DMG: [1657719500.818848][3305:3310] CHIP:DMG: ], [1657719500.818872][3305:3310] CHIP:DMG: [1657719500.818888][3305:3310] CHIP:DMG: InteractionModelRevision = 1 [1657719500.818898][3305:3310] CHIP:DMG: }, [1657719500.818962][3305:3310] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001 [1657719500.819020][3305:3310] CHIP:CTL: Received ArmFailSafe response errorCode=0 [1657719500.819049][3305:3310] CHIP:CTL: Successfully finished commissioning step 'ArmFailSafe' [1657719500.819062][3305:3310] CHIP:CTL: Commissioning stage next step: 'ArmFailSafe' -> 'ConfigRegulatory' [1657719500.819079][3305:3310] CHIP:CTL: Performing next commissioning step 'ConfigRegulatory' [1657719500.819090][3305:3310] CHIP:CTL: Setting Regulatory Config [1657719500.819098][3305:3310] CHIP:CTL: Device does not support configurable regulatory location [1657719500.819154][3305:3310] CHIP:DMG: ICR moving to [AddingComm] [1657719500.819178][3305:3310] CHIP:DMG: ICR moving to [AddedComma] [1657719500.819243][3305:3310] CHIP:IN: Prepared secure message 0x7f7e437fc1e0 to 0xFFFFFFFB00000000 (0) of type 0x8 and protocolId (0, 1) on exchange 21418i with MessageCounter:255649378. [1657719500.819280][3305:3310] CHIP:IN: Sending encrypted msg 0x7f7e437fc1e0 with MessageCounter:255649378 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000003FF80 msec [1657719500.819366][3305:3310] CHIP:DMG: ICR moving to [CommandSen] [1657719500.819423][3305:3310] CHIP:DMG: ICR moving to [AwaitingDe] [1657719500.916252][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1657719501.067164][3305:3308] CHIP:DL: Indication received, conn = 0x7f7e380360b0 [1657719501.068001][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1657719501.068193][3305:3310] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:87106219 on exchange 21418i [1657719501.068221][3305:3310] CHIP:EM: Found matching exchange: 21418i, Delegate: 0x7f7e30013a10 [1657719501.068249][3305:3310] CHIP:DMG: ICR moving to [ResponseRe] [1657719501.068312][3305:3310] CHIP:DMG: InvokeResponseMessage = [1657719501.068330][3305:3310] CHIP:DMG: { [1657719501.068346][3305:3310] CHIP:DMG: suppressResponse = false, [1657719501.068360][3305:3310] CHIP:DMG: InvokeResponseIBs = [1657719501.068384][3305:3310] CHIP:DMG: [ [1657719501.068398][3305:3310] CHIP:DMG: InvokeResponseIB = [1657719501.068422][3305:3310] CHIP:DMG: { [1657719501.068436][3305:3310] CHIP:DMG: CommandDataIB = [1657719501.068452][3305:3310] CHIP:DMG: { [1657719501.068466][3305:3310] CHIP:DMG: CommandPathIB = [1657719501.068483][3305:3310] CHIP:DMG: { [1657719501.068501][3305:3310] CHIP:DMG: EndpointId = 0x0, [1657719501.068520][3305:3310] CHIP:DMG: ClusterId = 0x30, [1657719501.068539][3305:3310] CHIP:DMG: CommandId = 0x3, [1657719501.068554][3305:3310] CHIP:DMG: }, [1657719501.068573][3305:3310] CHIP:DMG: [1657719501.068588][3305:3310] CHIP:DMG: CommandFields = [1657719501.068604][3305:3310] CHIP:DMG: { [1657719501.068623][3305:3310] CHIP:DMG: 0x0 = 0, [1657719501.068643][3305:3310] CHIP:DMG: 0x1 = "", [1657719501.068660][3305:3310] CHIP:DMG: }, [1657719501.068674][3305:3310] CHIP:DMG: }, [1657719501.068695][3305:3310] CHIP:DMG: [1657719501.068708][3305:3310] CHIP:DMG: }, [1657719501.068730][3305:3310] CHIP:DMG: [1657719501.068742][3305:3310] CHIP:DMG: ], [1657719501.068765][3305:3310] CHIP:DMG: [1657719501.068778][3305:3310] CHIP:DMG: InteractionModelRevision = 1 [1657719501.068790][3305:3310] CHIP:DMG: }, [1657719501.068857][3305:3310] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0003 [1657719501.068919][3305:3310] CHIP:CTL: Received SetRegulatoryConfig response errorCode=0 [1657719501.068946][3305:3310] CHIP:CTL: Successfully finished commissioning step 'ConfigRegulatory' [1657719501.068971][3305:3310] CHIP:CTL: Commissioning stage next step: 'ConfigRegulatory' -> 'SendPAICertificateRequest' [1657719501.068996][3305:3310] CHIP:CTL: Performing next commissioning step 'SendPAICertificateRequest' [1657719501.069010][3305:3310] CHIP:CTL: Sending request for PAI certificate [1657719501.069020][3305:3310] CHIP:CTL: Sending Certificate Chain request to 0x7f7e30000b60 device [1657719501.069081][3305:3310] CHIP:DMG: ICR moving to [AddingComm] [1657719501.069120][3305:3310] CHIP:DMG: ICR moving to [AddedComma] [1657719501.069196][3305:3310] CHIP:IN: Prepared secure message 0x7f7e437fc110 to 0xFFFFFFFB00000000 (0) of type 0x8 and protocolId (0, 1) on exchange 21419i with MessageCounter:255649379. [1657719501.069237][3305:3310] CHIP:IN: Sending encrypted msg 0x7f7e437fc110 with MessageCounter:255649379 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000004007A msec [1657719501.069332][3305:3310] CHIP:DMG: ICR moving to [CommandSen] [1657719501.069395][3305:3310] CHIP:DMG: ICR moving to [AwaitingDe] [1657719501.166335][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1657719501.321521][3305:3308] CHIP:DL: Indication received, conn = 0x7f7e380360b0 [1657719501.322256][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1657719501.718122][3305:3308] CHIP:DL: Indication received, conn = 0x7f7e380360b0 [1657719501.718704][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1657719501.866839][3305:3308] CHIP:DL: Indication received, conn = 0x7f7e380360b0 [1657719501.867650][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1657719501.867809][3305:3310] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:87106220 on exchange 21419i [1657719501.867840][3305:3310] CHIP:EM: Found matching exchange: 21419i, Delegate: 0x7f7e30004400 [1657719501.867875][3305:3310] CHIP:DMG: ICR moving to [ResponseRe] [1657719501.867930][3305:3310] CHIP:DMG: InvokeResponseMessage = [1657719501.867951][3305:3310] CHIP:DMG: { [1657719501.867970][3305:3310] CHIP:DMG: suppressResponse = false, [1657719501.867987][3305:3310] CHIP:DMG: InvokeResponseIBs = [1657719501.868015][3305:3310] CHIP:DMG: [ [1657719501.868033][3305:3310] CHIP:DMG: InvokeResponseIB = [1657719501.868060][3305:3310] CHIP:DMG: { [1657719501.868077][3305:3310] CHIP:DMG: CommandDataIB = [1657719501.868097][3305:3310] CHIP:DMG: { [1657719501.868115][3305:3310] CHIP:DMG: CommandPathIB = [1657719501.868134][3305:3310] CHIP:DMG: { [1657719501.868156][3305:3310] CHIP:DMG: EndpointId = 0x0, [1657719501.868178][3305:3310] CHIP:DMG: ClusterId = 0x3e, [1657719501.868199][3305:3310] CHIP:DMG: CommandId = 0x3, [1657719501.868217][3305:3310] CHIP:DMG: }, [1657719501.868239][3305:3310] CHIP:DMG: [1657719501.868258][3305:3310] CHIP:DMG: CommandFields = [1657719501.868277][3305:3310] CHIP:DMG: { [1657719501.868298][3305:3310] CHIP:DMG: 0x0 = [ [1657719501.868455][3305:3310] CHIP:DMG: 0x30, 0x82, 0x1, 0xcb, 0x30, 0x82, 0x1, 0x71, 0xa0, 0x3, 0x2, 0x1, 0x2, 0x2, 0x8, 0x56, 0xad, 0x82, 0x22, 0xad, 0x94, 0x5b, 0x64, 0x30, 0xa, 0x6, 0x8, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x4, 0x3, 0x2, 0x30, 0x30, 0x31, 0x18, 0x30, 0x16, 0x6, 0x3, 0x55, 0x4, 0x3, 0xc, 0xf, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x54, 0x65, 0x73, 0x74, 0x20, 0x50, 0x41, 0x41, 0x31, 0x14, 0x30, 0x12, 0x6, 0xa, 0x2b, 0x6, 0x1, 0x4, 0x1, 0x82, 0xa2, 0x7c, 0x2, 0x1, 0xc, 0x4, 0x46, 0x46, 0x46, 0x31, 0x30, 0x20, 0x17, 0xd, 0x32, 0x32, 0x30, 0x32, 0x30, 0x35, 0x30, 0x30, 0x30, 0x30, 0x30, 0x30, 0x5a, 0x18, 0xf, 0x39, 0x39, 0x39, 0x39, 0x31, 0x32, 0x33, 0x31, 0x32, 0x33, 0x35, 0x39, 0x35, 0x39, 0x5a, 0x30, 0x3d, 0x31, 0x25, 0x30, 0x23, 0x6, 0x3, 0x55, 0x4, 0x3, 0xc, 0x1c, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x44, 0x65, 0x76, 0x20, 0x50, 0x41, 0x49, 0x20, 0x30, 0x78, 0x46, 0x46, 0x46, 0x31, 0x20, 0x6e, 0x6f, 0x20, 0x50, 0x49, 0x44, 0x31, 0x14, 0x30, 0x12, 0x6, 0xa, 0x2b, 0x6, 0x1, 0x4, 0x1, 0x82, 0xa2, 0x7c, 0x2, 0x1, 0xc, 0x4, 0x46, 0x46, 0x46, 0x31, 0x30, 0x59, 0x30, 0x13, 0x6, 0x7, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x2, 0x1, 0x6, 0x8, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x3, 0x1, 0x7, 0x3, 0x42, 0x0, 0x4, 0x41, 0x9a, 0x93, 0x15, 0xc2, 0x17, 0x3e, 0xc, 0x8c, 0x87, 0x6d, 0x3, 0xcc, 0xfc, 0x94, 0x48, 0x52, 0x64, 0x7f, 0x7f, 0xec, 0x5e, 0x50, 0x82, 0xf4, 0x5, 0x99, 0x28, 0xec, 0xa8, 0x94, 0xc5, 0x94, 0x15, 0x13, 0x9, 0xac, 0x63, 0x1e, 0x4c, 0xb0, 0x33, 0x92, 0xaf, 0x68, 0x4b, 0xb, 0xaf, 0xb7, 0xe6, 0x5b, 0x3b, 0x81, 0x62, 0xc2, 0xf5, 0x2b, 0xf9, 0x31, 0xb8, 0xe7, 0x7a, 0xaa, 0x82, 0xa3, 0x66, 0x30, 0x64, 0x30, 0x12, 0x6, 0x3, 0x55, 0x1d, 0x13, 0x1, 0x1, 0xff, 0x4, 0x8, 0x30, 0x6, 0x1, 0x1, 0xff, 0x2, 0x1, [1657719501.868527][3305:3310] CHIP:DMG: ] [1657719501.868548][3305:3310] CHIP:DMG: }, [1657719501.868565][3305:3310] CHIP:DMG: }, [1657719501.868589][3305:3310] CHIP:DMG: [1657719501.868606][3305:3310] CHIP:DMG: }, [1657719501.868631][3305:3310] CHIP:DMG: [1657719501.868646][3305:3310] CHIP:DMG: ], [1657719501.868672][3305:3310] CHIP:DMG: [1657719501.868691][3305:3310] CHIP:DMG: InteractionModelRevision = 1 [1657719501.868707][3305:3310] CHIP:DMG: }, [1657719501.868777][3305:3310] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003 [1657719501.868812][3305:3310] CHIP:CTL: Received certificate chain from the device [1657719501.868841][3305:3310] CHIP:CTL: Successfully finished commissioning step 'SendPAICertificateRequest' [1657719501.868865][3305:3310] CHIP:CTL: Commissioning stage next step: 'SendPAICertificateRequest' -> 'SendDACCertificateRequest' [1657719501.868886][3305:3310] CHIP:CTL: Performing next commissioning step 'SendDACCertificateRequest' [1657719501.868898][3305:3310] CHIP:CTL: Sending request for DAC certificate [1657719501.868907][3305:3310] CHIP:CTL: Sending Certificate Chain request to 0x7f7e30000b60 device [1657719501.868968][3305:3310] CHIP:DMG: ICR moving to [AddingComm] [1657719501.868995][3305:3310] CHIP:DMG: ICR moving to [AddedComma] [1657719501.869072][3305:3310] CHIP:IN: Prepared secure message 0x7f7e437fc140 to 0xFFFFFFFB00000000 (0) of type 0x8 and protocolId (0, 1) on exchange 21420i with MessageCounter:255649380. [1657719501.869111][3305:3310] CHIP:IN: Sending encrypted msg 0x7f7e437fc140 with MessageCounter:255649380 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000004039A msec [1657719501.869205][3305:3310] CHIP:DMG: ICR moving to [CommandSen] [1657719501.869264][3305:3310] CHIP:DMG: ICR moving to [AwaitingDe] [1657719501.965437][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1657719502.121034][3305:3308] CHIP:DL: Indication received, conn = 0x7f7e380360b0 [1657719502.121658][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1657719502.416783][3305:3308] CHIP:DL: Indication received, conn = 0x7f7e380360b0 [1657719502.416950][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1657719502.417019][3305:3310] CHIP:BLE: HandleCharacteristicReceived failed, err = ../../third_party/connectedhomeip/src/ble/BtpEngine.cpp:298: Ble Error 0x0000041E: Received invalid BLE transport protocol sequence number, rx_flags = 6 [1657719502.417035][3305:3310] CHIP:BLE: With rx buf data length = 239 [1657719502.417044][3305:3310] CHIP:BLE: mAppState: 0x558c2ae5aae0 [1657719502.417054][3305:3310] CHIP:BLE: mRxFragmentSize: 244 [1657719502.417062][3305:3310] CHIP:BLE: mRxState: 3 [1657719502.417070][3305:3310] CHIP:BLE: mRxBuf: 1 [1657719502.417078][3305:3310] CHIP:BLE: mRxNextSeqNum: 12 [1657719502.417085][3305:3310] CHIP:BLE: mRxNewestUnackedSeqNum: 13 [1657719502.417093][3305:3310] CHIP:BLE: mRxOldestUnackedSeqNum: 11 [1657719502.417100][3305:3310] CHIP:BLE: mRxCharCount: 12 [1657719502.417108][3305:3310] CHIP:BLE: mRxPacketCount: 7 [1657719502.417115][3305:3310] CHIP:BLE: mTxFragmentSize: 244 [1657719502.417123][3305:3310] CHIP:BLE: mTxState: 0 [1657719502.417130][3305:3310] CHIP:BLE: mTxBuf: 0 [1657719502.417138][3305:3310] CHIP:BLE: mTxNextSeqNum: 8 [1657719502.417145][3305:3310] CHIP:BLE: mTxNewestUnackedSeqNum: 7 [1657719502.417153][3305:3310] CHIP:BLE: mTxOldestUnackedSeqNum: 7 [1657719502.417160][3305:3310] CHIP:BLE: mTxCharCount: 8 [1657719502.417167][3305:3310] CHIP:BLE: mTxPacketCount: 8 [1657719502.417183][3305:3310] CHIP:IN: Clearing BLE pending packets. [1657719502.417248][3305:3310] CHIP:BLE: BLEEndPoint rcv failed, err = ../../third_party/connectedhomeip/src/ble/BtpEngine.cpp:298: Ble Error 0x0000041E: Received invalid BLE transport protocol sequence number [1657719502.422186][3305:3310] CHIP:DL: HandlePlatformSpecificBLEEvent 16388 [1657719502.422236][3305:3310] CHIP:BLE: Auto-closing end point's BLE connection. [1657719502.422246][3305:3310] CHIP:DL: Closing BLE GATT connection (con 0x7f7e380360b0) [1657719502.422432][3305:3308] CHIP:DL: BluezDisconnect peer=C3:F4:36:29:FC:94 [1657719504.831701][3305:3308] CHIP:DL: Bluez disconnected [1657719504.831741][3305:3308] CHIP:DL: Bluez notify CHIPoBluez connection disconnected [1657719531.875695][3305:3310] CHIP:DMG: Time out! failed to receive invoke command response from Exchange: 21420i [1657719531.875772][3305:3310] CHIP:CTL: Device failed to receive the Certificate Chain request Response: ../../third_party/connectedhomeip/src/app/CommandSender.cpp:214: CHIP Error 0x00000032: Timeout [1657719531.875808][3305:3310] CHIP:CTL: Error on commissioning step 'SendDACCertificateRequest': '../../third_party/connectedhomeip/src/app/CommandSender.cpp:214: CHIP Error 0x00000032: Timeout' [1657719531.875824][3305:3310] CHIP:CTL: Failed to perform commissioning step 6 [1657719531.875841][3305:3310] CHIP:CTL: Going from commissioning step 'SendDACCertificateRequest' with lastErr = '../../third_party/connectedhomeip/src/app/CommandSender.cpp:214: CHIP Error 0x00000032: Timeout' -> 'Cleanup' [1657719531.875872][3305:3310] CHIP:CTL: Performing next commissioning step 'Cleanup' with completion status = '../../third_party/connectedhomeip/src/app/CommandSender.cpp:214: CHIP Error 0x00000032: Timeout' [1657719531.875888][3305:3310] CHIP:CTL: Expiring failsafe on proxy 0x7f7e30000b60 [1657719531.875955][3305:3310] CHIP:DMG: ICR moving to [AddingComm] [1657719531.875979][3305:3310] CHIP:DMG: ICR moving to [AddedComma] [1657719531.876083][3305:3310] CHIP:IN: Prepared secure message 0x7f7e437fcd90 to 0xFFFFFFFB00000000 (0) of type 0x8 and protocolId (0, 1) on exchange 21421i with MessageCounter:255649381. [1657719531.876123][3305:3310] CHIP:IN: Sending encrypted msg 0x7f7e437fcd90 with MessageCounter:255649381 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000000478D1 msec [1657719531.876152][3305:3310] CHIP:IN: Message appended to BLE send queue [1657719531.876168][3305:3310] CHIP:DMG: ICR moving to [CommandSen] [1657719531.876191][3305:3310] CHIP:DMG: ICR moving to [AwaitingDe] [1657719536.163683][3305:3310] CHIP:DIS: Closing all BLE connections [1657719536.163814][3305:3310] CHIP:TOO: Pairing Failure: ../../third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:1406: CHIP Error 0x00000032: Timeout [1657719536.167249][3305:3305] CHIP:CTL: Shutting down the commissioner [1657719536.167396][3305:3305] CHIP:CTL: Shutting down the controller [1657719536.167428][3305:3305] CHIP:CTL: Shutting down the commissioner [1657719536.167479][3305:3305] CHIP:CTL: Shutting down the controller [1657719536.167500][3305:3305] CHIP:IN: Expiring all sessions for fabric 0x1!! [1657719536.167519][3305:3305] CHIP:FP: Forgetting fabric 0x1 [1657719536.167550][3305:3305] CHIP:TS: Pending Last Known Good Time: 2022-07-13T21:11:01 [1657719536.167853][3305:3305] CHIP:TS: Previous Last Known Good Time: 2022-07-13T21:11:01 [1657719536.167874][3305:3305] CHIP:TS: Reverted Last Known Good Time to previous value [1657719536.167913][3305:3305] CHIP:CTL: Shutting down the commissioner [1657719536.167969][3305:3305] CHIP:CTL: Shutting down the controller [1657719536.167989][3305:3305] CHIP:IN: Expiring all sessions for fabric 0x2!! [1657719536.168000][3305:3305] CHIP:FP: Forgetting fabric 0x2 [1657719536.168017][3305:3305] CHIP:TS: Pending Last Known Good Time: 2022-07-13T21:11:01 [1657719536.168169][3305:3305] CHIP:TS: Previous Last Known Good Time: 2022-07-13T21:11:01 [1657719536.168188][3305:3305] CHIP:TS: Reverted Last Known Good Time to previous value [1657719536.168215][3305:3305] CHIP:CTL: Shutting down the commissioner [1657719536.168263][3305:3305] CHIP:CTL: Shutting down the controller [1657719536.168282][3305:3305] CHIP:IN: Expiring all sessions for fabric 0x3!! [1657719536.168294][3305:3305] CHIP:FP: Forgetting fabric 0x3 [1657719536.168310][3305:3305] CHIP:TS: Pending Last Known Good Time: 2022-07-13T21:11:01 [1657719536.168456][3305:3305] CHIP:TS: Previous Last Known Good Time: 2022-07-13T21:11:01 [1657719536.168475][3305:3305] CHIP:TS: Reverted Last Known Good Time to previous value [1657719536.168497][3305:3305] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1657719536.168601][3305:3305] CHIP:DMG: IM WH moving to [Uninitialized] [1657719536.168620][3305:3305] CHIP:DMG: IM WH moving to [Uninitialized] [1657719536.168630][3305:3305] CHIP:DMG: IM WH moving to [Uninitialized] [1657719536.168639][3305:3305] CHIP:DMG: IM WH moving to [Uninitialized] [1657719536.168649][3305:3305] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1657719536.168725][3305:3305] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented. [1657719536.169038][3305:3305] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-QbdhO5) [1657719536.169593][3305:3305] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1657719536.169718][3305:3305] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1657719536.169738][3305:3305] CHIP:DL: Inet Layer shutdown [1657719536.169749][3305:3305] CHIP:DL: BLE shutdown [1657719536.170699][3305:3305] CHIP:DL: System Layer shutdown [1657719536.170770][3305:3305] CHIP:IN: SecureSession[0x7f7e30001a30]: MarkForEviction Type:1 LSID:9583 [1657719536.170789][3305:3305] CHIP:SC: SecureSession[0x7f7e30001a30]: Moving from state 'kActive' --> 'kPendingEviction' Segmentation fault (core dumped)