ubuntu@ubuntu:~/master_cntrl/connectedhomeip/out/chip-tool$ ./chip-tool pairing ble-wifi 1 GRLPrivate grlprivatewifi092010 20202021 3840 [1708085264.928116][1895:1895] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs [1708085264.928568][1895:1895] CHIP:DL: writing settings to file (/tmp/chip_tool_kvs-3WL786) [1708085264.928959][1895:1895] CHIP:DL: renamed tmp file to file (/tmp/chip_tool_kvs) [1708085264.930673][1895:1895] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1708085264.930771][1895:1895] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs [1708085264.945474][1895:1895] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1708085264.946018][1895:1895] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-XqVof7) [1708085264.946445][1895:1895] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085264.946703][1895:1895] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1708085264.946977][1895:1895] CHIP:DL: writing settings to file (/tmp/chip_config.ini-Jr1kJk) [1708085264.947288][1895:1895] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085264.947504][1895:1895] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1708085264.947780][1895:1895] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-t8OSuk) [1708085264.948093][1895:1895] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085264.948807][1895:1895] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-iNCyQl) [1708085264.949922][1895:1895] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085264.950052][1895:1895] CHIP:DL: NVS set: chip-factory/unique-id = "303C800A924C78DB" [1708085264.950363][1895:1895] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-m4Uw4H) [1708085264.951516][1895:1895] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085264.951643][1895:1895] CHIP:DL: NVS set: chip-factory/vendor-id = 65521 (0xFFF1) [1708085264.951938][1895:1895] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-gIHLx6) [1708085264.953062][1895:1895] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085264.953181][1895:1895] CHIP:DL: NVS set: chip-factory/product-id = 32769 (0x8001) [1708085264.953488][1895:1895] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-IX9k7k) [1708085264.954543][1895:1895] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085264.954663][1895:1895] CHIP:DL: NVS set: chip-counters/reboot-count = 1 (0x1) [1708085264.954958][1895:1895] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-163uVo) [1708085264.956001][1895:1895] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085264.956119][1895:1895] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1708085264.956400][1895:1895] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-f8hEBm) [1708085264.957503][1895:1895] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085264.957621][1895:1895] CHIP:DL: NVS set: chip-counters/boot-reason = 0 (0x0) [1708085264.957970][1895:1895] CHIP:DL: writing settings to file (/tmp/chip_config.ini-1GokCM) [1708085264.959025][1895:1895] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085264.959143][1895:1895] CHIP:DL: NVS set: chip-config/regulatory-location = 0 (0x0) [1708085264.959441][1895:1895] CHIP:DL: writing settings to file (/tmp/chip_config.ini-FNvZyH) [1708085264.960653][1895:1895] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085264.960775][1895:1895] CHIP:DL: NVS set: chip-config/location-capability = 2 (0x2) [1708085264.962596][1895:1895] CHIP:DL: Got Ethernet interface: eth0 [1708085264.963868][1895:1895] CHIP:DL: Found the primary Ethernet interface:eth0 [1708085264.965153][1895:1895] CHIP:DL: Got WiFi interface: wlan0 [1708085264.965324][1895:1895] CHIP:DL: Failed to reset WiFi statistic counts [1708085264.965437][1895:1895] CHIP:IN: UDP::Init bind&listen port=0 [1708085264.965706][1895:1895] CHIP:IN: UDP::Init bound to port=40799 [1708085264.965827][1895:1895] CHIP:IN: BLEBase::Init - setting/overriding transport [1708085264.965881][1895:1895] CHIP:IN: TransportMgr initialized [1708085264.965996][1895:1895] CHIP:FP: Initializing FabricTable from persistent storage [1708085264.966090][1895:1895] CHIP:TS: Last Known Good Time: [unknown] [1708085264.966154][1895:1895] CHIP:TS: Setting Last Known Good Time to firmware build time 2023-10-14T01:16:48 [1708085264.970991][1895:1895] CHIP:ZCL: Using ZAP configuration... [1708085264.980850][1895:1895] CHIP:DL: Avahi client registered [1708085264.981097][1895:1895] CHIP:CTL: System State Initialized... [1708085264.981513][1895:1895] CHIP:CTL: Setting attestation nonce to random value [1708085264.981636][1895:1895] CHIP:CTL: Setting CSR nonce to random value [1708085264.981834][1895:1895] CHIP:IN: UDP::Init bind&listen port=5550 [1708085264.982116][1895:1895] CHIP:IN: UDP::Init bound to port=5550 [1708085264.982198][1895:1895] CHIP:IN: TransportMgr initialized [1708085264.984446][1895:1897] CHIP:DL: CHIP task running [1708085264.984864][1895:1897] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1708085264.986366][1895:1897] CHIP:CTL: Setting attestation nonce to random value [1708085264.986775][1895:1897] CHIP:CTL: Setting CSR nonce to random value [1708085264.987095][1895:1897] CHIP:CTL: Couldn't get ExampleOpCredsCAKey from storage: src/controller/ExamplePersistentStorage.cpp:106: CHIP Error 0x000000A0: Value not found in the persisted storage [1708085264.989310][1895:1897] CHIP:CTL: Couldn't get ExampleOpCredsICAKey from storage: src/controller/ExamplePersistentStorage.cpp:106: CHIP Error 0x000000A0: Value not found in the persisted storage [1708085264.992197][1895:1897] CHIP:CTL: Generating RCAC [1708085264.995936][1895:1897] CHIP:CTL: Generating ICAC [1708085264.998474][1895:1897] CHIP:CTL: Generating NOC [1708085265.000353][1895:1897] CHIP:FP: Validating NOC chain [1708085265.006600][1895:1897] CHIP:FP: NOC chain validation successful [1708085265.007050][1895:1897] CHIP:FP: Added new fabric at index: 0x1 [1708085265.007121][1895:1897] CHIP:FP: Assigned compressed fabric ID: 0x2B29E9A0927EF756, node ID: 0x000000000001B669 [1708085265.007199][1895:1897] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48 [1708085265.007253][1895:1897] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1708085265.007303][1895:1897] CHIP:TS: Retaining current Last Known Good Time [1708085265.010403][1895:1897] CHIP:FP: Metadata for Fabric 0x1 persisted to storage. [1708085265.014839][1895:1897] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-14T01:16:48 [1708085265.019081][1895:1897] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 2B29E9A0927EF756) [1708085265.019186][1895:1897] CHIP:IN: UDP::Init bind&listen port=5550 [1708085265.019444][1895:1897] CHIP:IN: UDP::Init bound to port=5550 [1708085265.019501][1895:1897] CHIP:IN: TransportMgr initialized [1708085265.093477][1895:1897] CHIP:CTL: Setting wifi credentials from parameters [1708085265.093568][1895:1897] CHIP:CTL: Setting attestation nonce to random value [1708085265.093665][1895:1897] CHIP:CTL: Setting CSR nonce to random value [1708085265.093794][1895:1897] CHIP:CTL: Checking ICD registration parameters [1708085265.093896][1895:1897] CHIP:CTL: Commission called for node ID 0x0000000000000001 [1708085265.093968][1895:1897] CHIP:DL: Long dispatch time: 109 ms, for event type 2 [1708085265.121709][1895:1897] CHIP:DL: BlueZ integration init success [1708085265.134822][1895:1896] CHIP:BLE: BLE removing known devices. [1708085265.138725][1895:1896] CHIP:BLE: BLE initiating scan. [1708085265.143509][1895:1897] CHIP:BLE: ChipDeviceScanner has started scanning! [1708085265.152323][1895:1896] CHIP:BLE: Device 04:D0:56:32:9B:CE does not look like a CHIP device. [1708085265.155566][1895:1896] CHIP:BLE: Device 22:B0:2A:35:1C:4A does not look like a CHIP device. [1708085265.159416][1895:1896] CHIP:BLE: Device 3F:AA:F5:DE:B5:A4 does not look like a CHIP device. [1708085265.169424][1895:1896] CHIP:BLE: Device 07:A6:F0:78:C9:41 does not look like a CHIP device. [1708085265.172607][1895:1896] CHIP:BLE: Device 3E:DE:74:31:A5:18 does not look like a CHIP device. [1708085265.176370][1895:1896] CHIP:BLE: Device 13:0D:19:C4:3A:07 does not look like a CHIP device. [1708085265.179427][1895:1896] CHIP:BLE: Device 3A:6A:E7:A7:A9:14 does not look like a CHIP device. [1708085265.182914][1895:1896] CHIP:BLE: Device 37:82:12:92:B2:98 does not look like a CHIP device. [1708085265.186149][1895:1896] CHIP:BLE: Device 0C:C9:E9:A5:F1:97 does not look like a CHIP device. [1708085265.189027][1895:1896] CHIP:BLE: Device 1A:AF:42:26:D8:75 does not look like a CHIP device. [1708085265.202056][1895:1896] CHIP:BLE: Device 2D:22:DB:8F:23:0D does not look like a CHIP device. [1708085265.205306][1895:1896] CHIP:BLE: Device 19:D7:04:92:AC:7A does not look like a CHIP device. [1708085265.208086][1895:1896] CHIP:BLE: Device 3F:E8:37:74:B0:11 does not look like a CHIP device. [1708085265.211106][1895:1896] CHIP:BLE: Device 30:46:32:3C:3E:A6 does not look like a CHIP device. [1708085265.216274][1895:1896] CHIP:BLE: Device B4:9A:95:77:96:1B does not look like a CHIP device. [1708085265.219356][1895:1896] CHIP:BLE: Device 04:69:72:B6:FD:43 does not look like a CHIP device. [1708085265.227446][1895:1896] CHIP:BLE: Device 15:E1:37:08:60:2D does not look like a CHIP device. [1708085265.230426][1895:1896] CHIP:BLE: Device 27:4C:13:C5:21:D3 does not look like a CHIP device. [1708085265.240814][1895:1896] CHIP:BLE: Device 2D:1D:2F:94:7E:BF does not look like a CHIP device. [1708085265.259972][1895:1896] CHIP:BLE: Device 38:04:C1:18:55:15 does not look like a CHIP device. [1708085265.263792][1895:1896] CHIP:BLE: Device 40:18:25:98:27:E3 does not look like a CHIP device. [1708085265.268667][1895:1896] CHIP:BLE: Device 06:C2:D2:C5:FA:FE does not look like a CHIP device. [1708085265.272809][1895:1896] CHIP:BLE: Device 15:3F:39:F3:69:DA does not look like a CHIP device. [1708085265.318045][1895:1896] CHIP:BLE: Device 1B:B1:6A:1E:48:29 does not look like a CHIP device. [1708085265.339081][1895:1896] CHIP:BLE: Device 7F:AF:97:2A:3E:90 does not look like a CHIP device. [1708085265.342028][1895:1896] CHIP:BLE: Device 68:27:37:08:85:43 does not look like a CHIP device. [1708085265.367061][1895:1896] CHIP:BLE: Device 5F:CD:E9:A6:D9:65 does not look like a CHIP device. [1708085265.379795][1895:1896] CHIP:BLE: Device 15:66:56:ED:9B:44 does not look like a CHIP device. [1708085265.403261][1895:1896] CHIP:BLE: New device scanned: 88:B1:11:E3:F8:E5 [1708085265.403352][1895:1896] CHIP:BLE: Device discriminator match. Attempting to connect. [1708085265.409236][1895:1896] CHIP:BLE: ChipDeviceScanner has stopped scanning! [1708085265.476042][1895:1896] CHIP:DL: FAIL: ConnectDevice: GDBus.Error:org.freedesktop.DBus.Error.UnknownObject: Method "Connect" with signature "" on interface "org.bluez.Device1" doesn't exist (41) [1708085265.476258][1895:1896] CHIP:BLE: Device connection failed: src/platform/Linux/bluez/BluezEndpoint.cpp:749: CHIP Error 0x000000AC: Internal error [1708085265.476377][1895:1897] CHIP:DL: HandlePlatformSpecificBLEEvent 16386 [1708085265.476450][1895:1897] CHIP:DIS: Closing all BLE connections [1708085265.476549][1895:1897] CHIP:TOO: Pairing Failure: src/platform/Linux/bluez/BluezEndpoint.cpp:748: CHIP Error 0x000000AC: Internal error [1708085265.477276][1895:1895] CHIP:CTL: Shutting down the commissioner [1708085265.477497][1895:1895] CHIP:CTL: Shutting down the controller [1708085265.477612][1895:1895] CHIP:IN: Expiring all sessions for fabric 0x1!! [1708085265.477669][1895:1895] CHIP:FP: Forgetting fabric 0x1 [1708085265.477885][1895:1895] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48 [1708085265.478273][1895:1895] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48 [1708085265.478425][1895:1895] CHIP:TS: Reverted Last Known Good Time to previous value [1708085265.478526][1895:1895] CHIP:CTL: Shutting down the commissioner [1708085265.478730][1895:1895] CHIP:CTL: Shutting down the controller [1708085265.478788][1895:1895] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1708085265.479151][1895:1895] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1708085265.479506][1895:1895] CHIP:FP: Shutting down FabricTable [1708085265.479611][1895:1895] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48 [1708085265.479926][1895:1895] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48 [1708085265.480000][1895:1895] CHIP:TS: Reverted Last Known Good Time to previous value [1708085265.480584][1895:1895] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-wxrt3S) [1708085265.482117][1895:1895] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085265.482402][1895:1895] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1708085265.482472][1895:1895] CHIP:DL: Inet Layer shutdown [1708085265.482522][1895:1895] CHIP:DL: BLE shutdown [1708085265.497609][1895:1895] CHIP:DL: System Layer shutdown [1708085265.499234][1895:1895] CHIP:TOO: Run command failure: src/platform/Linux/bluez/BluezEndpoint.cpp:748: CHIP Error 0x000000AC: Internal error ubuntu@ubuntu:~/master_cntrl/connectedhomeip/out/chip-tool$ sudo rm -rf /tmp/chip_* ubuntu@ubuntu:~/master_cntrl/connectedhomeip/out/chip-tool$ ./chip-tool pairing ble-wifi 1 GRLPrivate grlprivatewifi092010 20202021 3840 [1708085280.678863][1905:1905] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs [1708085280.679066][1905:1905] CHIP:DL: writing settings to file (/tmp/chip_tool_kvs-SbGQSd) [1708085280.679224][1905:1905] CHIP:DL: renamed tmp file to file (/tmp/chip_tool_kvs) [1708085280.679958][1905:1905] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1708085280.679998][1905:1905] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs [1708085280.685310][1905:1905] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1708085280.685619][1905:1905] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-hGtIMG) [1708085280.685868][1905:1905] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085280.686036][1905:1905] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1708085280.686190][1905:1905] CHIP:DL: writing settings to file (/tmp/chip_config.ini-OwffkP) [1708085280.686322][1905:1905] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085280.686407][1905:1905] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1708085280.686505][1905:1905] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-572bvh) [1708085280.686615][1905:1905] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085280.686911][1905:1905] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-JFKIO3) [1708085280.687399][1905:1905] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085280.687451][1905:1905] CHIP:DL: NVS set: chip-factory/unique-id = "68CF3DAAA5E5AB8F" [1708085280.687584][1905:1905] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-nZcUA6) [1708085280.688331][1905:1905] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085280.688385][1905:1905] CHIP:DL: NVS set: chip-factory/vendor-id = 65521 (0xFFF1) [1708085280.688510][1905:1905] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-iLpJFw) [1708085280.689128][1905:1905] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085280.689174][1905:1905] CHIP:DL: NVS set: chip-factory/product-id = 32769 (0x8001) [1708085280.689289][1905:1905] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-tXYjhT) [1708085280.689604][1905:1905] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085280.689646][1905:1905] CHIP:DL: NVS set: chip-counters/reboot-count = 1 (0x1) [1708085280.689790][1905:1905] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-zuKp8Y) [1708085280.690840][1905:1905] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085280.690889][1905:1905] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1708085280.691017][1905:1905] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-jZ8E1y) [1708085280.691701][1905:1905] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085280.691750][1905:1905] CHIP:DL: NVS set: chip-counters/boot-reason = 0 (0x0) [1708085280.691866][1905:1905] CHIP:DL: writing settings to file (/tmp/chip_config.ini-fHcE6c) [1708085280.692179][1905:1905] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085280.692220][1905:1905] CHIP:DL: NVS set: chip-config/regulatory-location = 0 (0x0) [1708085280.692324][1905:1905] CHIP:DL: writing settings to file (/tmp/chip_config.ini-fjmxaq) [1708085280.693806][1905:1905] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085280.693854][1905:1905] CHIP:DL: NVS set: chip-config/location-capability = 2 (0x2) [1708085280.694491][1905:1905] CHIP:DL: Got Ethernet interface: eth0 [1708085280.694996][1905:1905] CHIP:DL: Found the primary Ethernet interface:eth0 [1708085280.695478][1905:1905] CHIP:DL: Got WiFi interface: wlan0 [1708085280.695538][1905:1905] CHIP:DL: Failed to reset WiFi statistic counts [1708085280.695590][1905:1905] CHIP:IN: UDP::Init bind&listen port=0 [1708085280.695698][1905:1905] CHIP:IN: UDP::Init bound to port=37757 [1708085280.695720][1905:1905] CHIP:IN: BLEBase::Init - setting/overriding transport [1708085280.695735][1905:1905] CHIP:IN: TransportMgr initialized [1708085280.695782][1905:1905] CHIP:FP: Initializing FabricTable from persistent storage [1708085280.695824][1905:1905] CHIP:TS: Last Known Good Time: [unknown] [1708085280.695850][1905:1905] CHIP:TS: Setting Last Known Good Time to firmware build time 2023-10-14T01:16:48 [1708085280.699338][1905:1905] CHIP:ZCL: Using ZAP configuration... [1708085280.709283][1905:1905] CHIP:DL: Avahi client registered [1708085280.709525][1905:1905] CHIP:CTL: System State Initialized... [1708085280.709980][1905:1905] CHIP:CTL: Setting attestation nonce to random value [1708085280.710199][1905:1905] CHIP:CTL: Setting CSR nonce to random value [1708085280.710441][1905:1905] CHIP:IN: UDP::Init bind&listen port=5550 [1708085280.710790][1905:1905] CHIP:IN: UDP::Init bound to port=5550 [1708085280.710853][1905:1905] CHIP:IN: TransportMgr initialized [1708085280.713202][1905:1907] CHIP:DL: CHIP task running [1708085280.713623][1905:1907] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1708085280.714681][1905:1907] CHIP:CTL: Setting attestation nonce to random value [1708085280.715135][1905:1907] CHIP:CTL: Setting CSR nonce to random value [1708085280.715460][1905:1907] CHIP:CTL: Couldn't get ExampleOpCredsCAKey from storage: src/controller/ExamplePersistentStorage.cpp:106: CHIP Error 0x000000A0: Value not found in the persisted storage [1708085280.717642][1905:1907] CHIP:CTL: Couldn't get ExampleOpCredsICAKey from storage: src/controller/ExamplePersistentStorage.cpp:106: CHIP Error 0x000000A0: Value not found in the persisted storage [1708085280.720311][1905:1907] CHIP:CTL: Generating RCAC [1708085280.723869][1905:1907] CHIP:CTL: Generating ICAC [1708085280.726053][1905:1907] CHIP:CTL: Generating NOC [1708085280.727739][1905:1907] CHIP:FP: Validating NOC chain [1708085280.733843][1905:1907] CHIP:FP: NOC chain validation successful [1708085280.734296][1905:1907] CHIP:FP: Added new fabric at index: 0x1 [1708085280.734385][1905:1907] CHIP:FP: Assigned compressed fabric ID: 0x55DBEBD945F88713, node ID: 0x000000000001B669 [1708085280.734455][1905:1907] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48 [1708085280.734509][1905:1907] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1708085280.734558][1905:1907] CHIP:TS: Retaining current Last Known Good Time [1708085280.738112][1905:1907] CHIP:FP: Metadata for Fabric 0x1 persisted to storage. [1708085280.743183][1905:1907] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-14T01:16:48 [1708085280.750574][1905:1907] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 55DBEBD945F88713) [1708085280.750689][1905:1907] CHIP:IN: UDP::Init bind&listen port=5550 [1708085280.750943][1905:1907] CHIP:IN: UDP::Init bound to port=5550 [1708085280.751003][1905:1907] CHIP:IN: TransportMgr initialized [1708085280.818120][1905:1907] CHIP:CTL: Setting wifi credentials from parameters [1708085280.818214][1905:1907] CHIP:CTL: Setting attestation nonce to random value [1708085280.818311][1905:1907] CHIP:CTL: Setting CSR nonce to random value [1708085280.818398][1905:1907] CHIP:CTL: Checking ICD registration parameters [1708085280.818496][1905:1907] CHIP:CTL: Commission called for node ID 0x0000000000000001 [1708085280.818568][1905:1907] CHIP:DL: Long dispatch time: 105 ms, for event type 2 [1708085280.851075][1905:1907] CHIP:DL: BlueZ integration init success [1708085280.867710][1905:1906] CHIP:BLE: BLE removing known devices. [1708085280.871503][1905:1906] CHIP:BLE: BLE initiating scan. [1708085280.876392][1905:1907] CHIP:BLE: ChipDeviceScanner has started scanning! [1708085280.887071][1905:1906] CHIP:BLE: Device 22:B0:2A:35:1C:4A does not look like a CHIP device. [1708085280.896870][1905:1906] CHIP:BLE: Device D1:B6:D0:42:7A:C7 does not look like a CHIP device. [1708085280.900356][1905:1906] CHIP:BLE: Device 09:48:FC:E5:0F:00 does not look like a CHIP device. [1708085280.903436][1905:1906] CHIP:BLE: Device 00:9B:FF:A3:EC:10 does not look like a CHIP device. [1708085280.906526][1905:1906] CHIP:BLE: Device 3F:E8:37:74:B0:11 does not look like a CHIP device. [1708085280.909315][1905:1906] CHIP:BLE: Device 14:13:09:CB:2E:C5 does not look like a CHIP device. [1708085280.916227][1905:1906] CHIP:BLE: Device 32:5E:41:FE:97:E1 does not look like a CHIP device. [1708085280.919510][1905:1906] CHIP:BLE: Device 3A:6A:E7:A7:A9:14 does not look like a CHIP device. [1708085280.922560][1905:1906] CHIP:BLE: Device 07:A6:F0:78:C9:41 does not look like a CHIP device. [1708085280.934165][1905:1906] CHIP:BLE: Device 0D:4A:37:0D:C9:8F does not look like a CHIP device. [1708085280.939970][1905:1906] CHIP:BLE: Device 37:82:12:92:B2:98 does not look like a CHIP device. [1708085280.944374][1905:1906] CHIP:BLE: Device 13:0D:19:C4:3A:07 does not look like a CHIP device. [1708085280.949206][1905:1906] CHIP:BLE: Device 30:46:32:3C:3E:A6 does not look like a CHIP device. [1708085280.953525][1905:1906] CHIP:BLE: Device 15:66:56:ED:9B:44 does not look like a CHIP device. [1708085281.000064][1905:1906] CHIP:BLE: Device 3E:DE:74:31:A5:18 does not look like a CHIP device. [1708085281.003006][1905:1906] CHIP:BLE: Device 02:02:4C:FC:DB:50 does not look like a CHIP device. [1708085281.007580][1905:1906] CHIP:BLE: Device 5A:DF:F1:15:F2:FF does not look like a CHIP device. [1708085281.031139][1905:1906] CHIP:BLE: Device 3F:AA:F5:DE:B5:A4 does not look like a CHIP device. [1708085281.041647][1905:1906] CHIP:BLE: Device 04:69:72:B6:FD:43 does not look like a CHIP device. [1708085281.044931][1905:1906] CHIP:BLE: Device 27:4C:13:C5:21:D3 does not look like a CHIP device. [1708085281.060697][1905:1906] CHIP:BLE: Device 15:E1:37:08:60:2D does not look like a CHIP device. [1708085281.063726][1905:1906] CHIP:BLE: Device 15:3F:39:F3:69:DA does not look like a CHIP device. [1708085281.070399][1905:1906] CHIP:BLE: Device 17:C0:80:27:2E:B8 does not look like a CHIP device. [1708085281.074492][1905:1906] CHIP:BLE: Device 19:D7:04:92:AC:7A does not look like a CHIP device. [1708085281.080473][1905:1906] CHIP:BLE: New device scanned: C4:5B:6D:16:AC:90 [1708085281.080563][1905:1906] CHIP:BLE: Device discriminator match. Attempting to connect. [1708085281.085651][1905:1906] CHIP:BLE: ChipDeviceScanner has stopped scanning! [1708085281.264459][1905:1906] CHIP:DL: ConnectDevice complete [1708085281.264569][1905:1906] CHIP:BLE: New device connected: C4:5B:6D:16:AC:90 [1708085301.106798][1905:1907] CHIP:DL: HandlePlatformSpecificBLEEvent 16386 [1708085301.106903][1905:1907] CHIP:DIS: Closing all BLE connections [1708085301.107009][1905:1907] CHIP:TOO: Pairing Failure: src/platform/Linux/BLEManagerImpl.cpp:83: CHIP Error 0x00000032: Timeout [1708085301.107703][1905:1905] CHIP:CTL: Shutting down the commissioner [1708085301.108067][1905:1905] CHIP:CTL: Shutting down the controller [1708085301.108186][1905:1905] CHIP:IN: Expiring all sessions for fabric 0x1!! [1708085301.108244][1905:1905] CHIP:FP: Forgetting fabric 0x1 [1708085301.108386][1905:1905] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48 [1708085301.108795][1905:1905] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48 [1708085301.108955][1905:1905] CHIP:TS: Reverted Last Known Good Time to previous value [1708085301.109051][1905:1905] CHIP:CTL: Shutting down the commissioner [1708085301.109222][1905:1905] CHIP:CTL: Shutting down the controller [1708085301.109279][1905:1905] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1708085301.109831][1905:1905] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1708085301.110052][1905:1905] CHIP:FP: Shutting down FabricTable [1708085301.110135][1905:1905] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48 [1708085301.110423][1905:1905] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48 [1708085301.110486][1905:1905] CHIP:TS: Reverted Last Known Good Time to previous value [1708085301.111032][1905:1905] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-ZCqtmY) [1708085301.112708][1905:1905] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085301.112862][1905:1905] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1708085301.112922][1905:1905] CHIP:DL: Inet Layer shutdown [1708085301.112973][1905:1905] CHIP:DL: BLE shutdown [1708085301.116277][1905:1905] CHIP:DL: System Layer shutdown [1708085301.117907][1905:1905] CHIP:TOO: Run command failure: src/platform/Linux/BLEManagerImpl.cpp:83: CHIP Error 0x00000032: Timeout ubuntu@ubuntu:~/master_cntrl/connectedhomeip/out/chip-tool$ sudo rm -rf /tmp/chip_* ubuntu@ubuntu:~/master_cntrl/connectedhomeip/out/chip-tool$ ./chip-tool pairing ble-wifi 1 GRLPrivate grlprivatewifi092010 20202021 3840 [1708085312.727950][1915:1915] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs [1708085312.728399][1915:1915] CHIP:DL: writing settings to file (/tmp/chip_tool_kvs-ElB2UF) [1708085312.728784][1915:1915] CHIP:DL: renamed tmp file to file (/tmp/chip_tool_kvs) [1708085312.730723][1915:1915] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1708085312.730798][1915:1915] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs [1708085312.745593][1915:1915] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1708085312.746192][1915:1915] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-vmnqRy) [1708085312.746836][1915:1915] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085312.747099][1915:1915] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1708085312.747462][1915:1915] CHIP:DL: writing settings to file (/tmp/chip_config.ini-PTEPbX) [1708085312.747855][1915:1915] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085312.748142][1915:1915] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1708085312.748473][1915:1915] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-z3lvOa) [1708085312.748844][1915:1915] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085312.749639][1915:1915] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-qBMpxn) [1708085312.750785][1915:1915] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085312.750915][1915:1915] CHIP:DL: NVS set: chip-factory/unique-id = "ED908AF6FF88ECC1" [1708085312.751218][1915:1915] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-KexBWr) [1708085312.752616][1915:1915] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085312.752740][1915:1915] CHIP:DL: NVS set: chip-factory/vendor-id = 65521 (0xFFF1) [1708085312.753042][1915:1915] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-I8j0TU) [1708085312.754235][1915:1915] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085312.754362][1915:1915] CHIP:DL: NVS set: chip-factory/product-id = 32769 (0x8001) [1708085312.754655][1915:1915] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-YAZ8NI) [1708085312.755650][1915:1915] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085312.755772][1915:1915] CHIP:DL: NVS set: chip-counters/reboot-count = 1 (0x1) [1708085312.756058][1915:1915] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-Vq8K2r) [1708085312.757132][1915:1915] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085312.757252][1915:1915] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1708085312.757541][1915:1915] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-oyLiwK) [1708085312.758818][1915:1915] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085312.758941][1915:1915] CHIP:DL: NVS set: chip-counters/boot-reason = 0 (0x0) [1708085312.759221][1915:1915] CHIP:DL: writing settings to file (/tmp/chip_config.ini-etRvt3) [1708085312.760182][1915:1915] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085312.760300][1915:1915] CHIP:DL: NVS set: chip-config/regulatory-location = 0 (0x0) [1708085312.760578][1915:1915] CHIP:DL: writing settings to file (/tmp/chip_config.ini-ZfM0Hh) [1708085312.761672][1915:1915] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085312.761840][1915:1915] CHIP:DL: NVS set: chip-config/location-capability = 2 (0x2) [1708085312.763564][1915:1915] CHIP:DL: Got Ethernet interface: eth0 [1708085312.764831][1915:1915] CHIP:DL: Found the primary Ethernet interface:eth0 [1708085312.766224][1915:1915] CHIP:DL: Got WiFi interface: wlan0 [1708085312.766391][1915:1915] CHIP:DL: Failed to reset WiFi statistic counts [1708085312.766502][1915:1915] CHIP:IN: UDP::Init bind&listen port=0 [1708085312.766840][1915:1915] CHIP:IN: UDP::Init bound to port=42183 [1708085312.766902][1915:1915] CHIP:IN: BLEBase::Init - setting/overriding transport [1708085312.767009][1915:1915] CHIP:IN: TransportMgr initialized [1708085312.767176][1915:1915] CHIP:FP: Initializing FabricTable from persistent storage [1708085312.767275][1915:1915] CHIP:TS: Last Known Good Time: [unknown] [1708085312.767340][1915:1915] CHIP:TS: Setting Last Known Good Time to firmware build time 2023-10-14T01:16:48 [1708085312.771615][1915:1915] CHIP:ZCL: Using ZAP configuration... [1708085312.781197][1915:1915] CHIP:DL: Avahi client registered [1708085312.781445][1915:1915] CHIP:CTL: System State Initialized... [1708085312.781879][1915:1915] CHIP:CTL: Setting attestation nonce to random value [1708085312.781991][1915:1915] CHIP:CTL: Setting CSR nonce to random value [1708085312.782155][1915:1915] CHIP:IN: UDP::Init bind&listen port=5550 [1708085312.782435][1915:1915] CHIP:IN: UDP::Init bound to port=5550 [1708085312.782494][1915:1915] CHIP:IN: TransportMgr initialized [1708085312.784686][1915:1917] CHIP:DL: CHIP task running [1708085312.785116][1915:1917] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1708085312.786422][1915:1917] CHIP:CTL: Setting attestation nonce to random value [1708085312.786846][1915:1917] CHIP:CTL: Setting CSR nonce to random value [1708085312.787192][1915:1917] CHIP:CTL: Couldn't get ExampleOpCredsCAKey from storage: src/controller/ExamplePersistentStorage.cpp:106: CHIP Error 0x000000A0: Value not found in the persisted storage [1708085312.789484][1915:1917] CHIP:CTL: Couldn't get ExampleOpCredsICAKey from storage: src/controller/ExamplePersistentStorage.cpp:106: CHIP Error 0x000000A0: Value not found in the persisted storage [1708085312.792533][1915:1917] CHIP:CTL: Generating RCAC [1708085312.796410][1915:1917] CHIP:CTL: Generating ICAC [1708085312.798765][1915:1917] CHIP:CTL: Generating NOC [1708085312.800817][1915:1917] CHIP:FP: Validating NOC chain [1708085312.807154][1915:1917] CHIP:FP: NOC chain validation successful [1708085312.807607][1915:1917] CHIP:FP: Added new fabric at index: 0x1 [1708085312.807672][1915:1917] CHIP:FP: Assigned compressed fabric ID: 0xAE92D82EAA891BBF, node ID: 0x000000000001B669 [1708085312.807739][1915:1917] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48 [1708085312.807792][1915:1917] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1708085312.807841][1915:1917] CHIP:TS: Retaining current Last Known Good Time [1708085312.810980][1915:1917] CHIP:FP: Metadata for Fabric 0x1 persisted to storage. [1708085312.815525][1915:1917] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-14T01:16:48 [1708085312.819851][1915:1917] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: AE92D82EAA891BBF) [1708085312.819956][1915:1917] CHIP:IN: UDP::Init bind&listen port=5550 [1708085312.820255][1915:1917] CHIP:IN: UDP::Init bound to port=5550 [1708085312.820313][1915:1917] CHIP:IN: TransportMgr initialized [1708085312.891638][1915:1917] CHIP:CTL: Setting wifi credentials from parameters [1708085312.891729][1915:1917] CHIP:CTL: Setting attestation nonce to random value [1708085312.891817][1915:1917] CHIP:CTL: Setting CSR nonce to random value [1708085312.891902][1915:1917] CHIP:CTL: Checking ICD registration parameters [1708085312.892000][1915:1917] CHIP:CTL: Commission called for node ID 0x0000000000000001 [1708085312.892071][1915:1917] CHIP:DL: Long dispatch time: 107 ms, for event type 2 [1708085312.918938][1915:1917] CHIP:DL: BlueZ integration init success [1708085312.931533][1915:1916] CHIP:BLE: BLE removing known devices. [1708085312.935452][1915:1916] CHIP:BLE: BLE initiating scan. [1708085312.940612][1915:1917] CHIP:BLE: ChipDeviceScanner has started scanning! [1708085312.960776][1915:1916] CHIP:BLE: Device AE:50:DE:4C:31:D6 does not look like a CHIP device. [1708085312.964275][1915:1916] CHIP:BLE: Device B4:9A:95:77:96:1B does not look like a CHIP device. [1708085312.967420][1915:1916] CHIP:BLE: Device 42:5C:9D:B8:E0:16 does not look like a CHIP device. [1708085312.970340][1915:1916] CHIP:BLE: Device 3A:6A:E7:A7:A9:14 does not look like a CHIP device. [1708085312.980282][1915:1916] CHIP:BLE: Device 30:46:32:3C:3E:A6 does not look like a CHIP device. [1708085312.990333][1915:1916] CHIP:BLE: Device 15:3F:39:F3:69:DA does not look like a CHIP device. [1708085312.996778][1915:1916] CHIP:BLE: Device FB:02:E8:67:D0:F5 does not look like a CHIP device. [1708085313.000506][1915:1916] CHIP:BLE: Device 02:02:4C:FC:DB:50 does not look like a CHIP device. [1708085313.003795][1915:1916] CHIP:BLE: Device 19:93:DA:38:4F:03 does not look like a CHIP device. [1708085313.006596][1915:1916] CHIP:BLE: Device 07:A6:F0:78:C9:41 does not look like a CHIP device. [1708085313.009474][1915:1916] CHIP:BLE: Device 53:A8:00:B8:4A:E3 does not look like a CHIP device. [1708085313.012206][1915:1916] CHIP:BLE: Device 28:E1:46:B5:31:AF does not look like a CHIP device. [1708085313.020503][1915:1916] CHIP:BLE: Device 38:04:C1:18:55:15 does not look like a CHIP device. [1708085313.034237][1915:1916] CHIP:BLE: Device 1A:AF:42:26:D8:75 does not look like a CHIP device. [1708085313.042911][1915:1916] CHIP:BLE: Device 2D:1D:2F:94:7E:BF does not look like a CHIP device. [1708085313.056896][1915:1916] CHIP:BLE: Device AE:50:DE:4C:31:D6 does not look like a CHIP device. [1708085313.065692][1915:1916] CHIP:BLE: Device 15:66:56:ED:9B:44 does not look like a CHIP device. [1708085313.068579][1915:1916] CHIP:BLE: Device CF:F7:23:9E:7E:29 does not look like a CHIP device. [1708085313.076802][1915:1916] CHIP:BLE: Device 5A:DF:F1:15:F2:FF does not look like a CHIP device. [1708085313.107079][1915:1916] CHIP:BLE: Device F0:EE:C1:BC:49:0D does not look like a CHIP device. [1708085313.120506][1915:1916] CHIP:BLE: Device 00:9B:FF:A3:EC:10 does not look like a CHIP device. [1708085313.132561][1915:1916] CHIP:BLE: Device 0D:4A:37:0D:C9:8F does not look like a CHIP device. [1708085313.144479][1915:1916] CHIP:BLE: Device 04:69:72:B6:FD:43 does not look like a CHIP device. [1708085313.154181][1915:1916] CHIP:BLE: Device 15:E1:37:08:60:2D does not look like a CHIP device. [1708085313.162592][1915:1916] CHIP:BLE: Device 37:82:12:92:B2:98 does not look like a CHIP device. [1708085313.176796][1915:1916] CHIP:BLE: Device 1B:B1:6A:1E:48:29 does not look like a CHIP device. [1708085313.185279][1915:1916] CHIP:BLE: Device 4B:20:3E:66:F4:79 does not look like a CHIP device. [1708085313.248993][1915:1916] CHIP:BLE: Device 3F:AA:F5:DE:B5:A4 does not look like a CHIP device. [1708085313.271454][1915:1916] CHIP:BLE: Device 14:13:09:CB:2E:C5 does not look like a CHIP device. [1708085313.282398][1915:1916] CHIP:BLE: Device 13:0D:19:C4:3A:07 does not look like a CHIP device. [1708085313.293599][1915:1916] CHIP:BLE: Device 1B:C2:72:A2:F0:8C does not look like a CHIP device. [1708085313.300461][1915:1916] CHIP:BLE: Device 09:48:FC:E5:0F:00 does not look like a CHIP device. [1708085313.339201][1915:1916] CHIP:BLE: Device 17:C0:80:27:2E:B8 does not look like a CHIP device. [1708085313.376089][1915:1916] CHIP:BLE: Device 22:B0:2A:35:1C:4A does not look like a CHIP device. [1708085313.394791][1915:1916] CHIP:BLE: Device 32:5E:41:FE:97:E1 does not look like a CHIP device. [1708085313.429007][1915:1916] CHIP:BLE: Device 27:4C:13:C5:21:D3 does not look like a CHIP device. [1708085313.433292][1915:1916] CHIP:BLE: Device AE:50:DE:4C:31:D6 does not look like a CHIP device. [1708085313.440955][1915:1916] CHIP:BLE: Device 1F:9E:40:21:CB:7E does not look like a CHIP device. [1708085313.444872][1915:1916] CHIP:BLE: Device 78:CC:30:DE:11:6D does not look like a CHIP device. [1708085313.447758][1915:1916] CHIP:BLE: Device 2D:22:DB:8F:23:0D does not look like a CHIP device. [1708085313.495396][1915:1916] CHIP:BLE: Device 69:A5:8D:1A:11:BF does not look like a CHIP device. [1708085313.498116][1915:1916] CHIP:BLE: Device B4:9A:95:77:96:1B does not look like a CHIP device. [1708085313.498549][1915:1916] CHIP:BLE: Device 3A:6A:E7:A7:A9:14 does not look like a CHIP device. [1708085313.520249][1915:1916] CHIP:BLE: Device FA:ED:AD:52:21:B2 does not look like a CHIP device. [1708085313.520693][1915:1916] CHIP:BLE: Device 07:A6:F0:78:C9:41 does not look like a CHIP device. [1708085313.557444][1915:1916] CHIP:BLE: Device 64:C6:54:6D:DD:79 does not look like a CHIP device. [1708085313.594308][1915:1916] CHIP:BLE: Device 3E:DE:74:31:A5:18 does not look like a CHIP device. [1708085313.604123][1915:1916] CHIP:BLE: Device 7C:32:4B:AE:19:A1 does not look like a CHIP device. [1708085313.617235][1915:1916] CHIP:BLE: Device 02:02:4C:FC:DB:50 does not look like a CHIP device. [1708085313.632417][1915:1916] CHIP:BLE: Device 3D:77:D9:57:6B:6D does not look like a CHIP device. [1708085313.632864][1915:1916] CHIP:BLE: Device 28:E1:46:B5:31:AF does not look like a CHIP device. [1708085313.653584][1915:1916] CHIP:BLE: Device 1A:AF:42:26:D8:75 does not look like a CHIP device. [1708085313.655833][1915:1916] CHIP:BLE: Device 38:04:C1:18:55:15 does not look like a CHIP device. [1708085313.675735][1915:1916] CHIP:BLE: Device 21:4C:59:92:B2:54 does not look like a CHIP device. [1708085313.699245][1915:1916] CHIP:BLE: Device 31:32:65:BB:42:A8 does not look like a CHIP device. [1708085313.707520][1915:1916] CHIP:BLE: Device 42:08:1F:CE:42:8D does not look like a CHIP device. [1708085313.707963][1915:1916] CHIP:BLE: Device 30:46:32:3C:3E:A6 does not look like a CHIP device. [1708085313.710829][1915:1916] CHIP:BLE: Device 5F:CD:E9:A6:D9:65 does not look like a CHIP device. [1708085313.743708][1915:1916] CHIP:BLE: Device 12:38:E8:FE:B2:5D does not look like a CHIP device. [1708085313.746654][1915:1916] CHIP:BLE: Device 19:D7:04:92:AC:7A does not look like a CHIP device. [1708085313.763891][1915:1916] CHIP:BLE: Device 7F:AF:97:2A:3E:90 does not look like a CHIP device. [1708085313.764378][1915:1916] CHIP:BLE: Device B4:9A:95:77:96:1B does not look like a CHIP device. [1708085313.765157][1915:1916] CHIP:BLE: Device 37:82:12:92:B2:98 does not look like a CHIP device. [1708085313.769535][1915:1916] CHIP:BLE: Device 53:A8:00:B8:4A:E3 does not look like a CHIP device. [1708085313.776464][1915:1916] CHIP:BLE: Device 2D:1D:2F:94:7E:BF does not look like a CHIP device. [1708085313.781468][1915:1916] CHIP:BLE: Device 15:E1:37:08:60:2D does not look like a CHIP device. [1708085313.785361][1915:1916] CHIP:BLE: Device 68:27:37:08:85:43 does not look like a CHIP device. [1708085313.789701][1915:1916] CHIP:BLE: Device 1B:B1:6A:1E:48:29 does not look like a CHIP device. [1708085313.815729][1915:1916] CHIP:BLE: Device 5A:DF:F1:15:F2:FF does not look like a CHIP device. [1708085313.846548][1915:1916] CHIP:BLE: Device 27:4C:13:C5:21:D3 does not look like a CHIP device. [1708085313.851430][1915:1916] CHIP:BLE: Device 4B:D3:B3:9A:06:33 does not look like a CHIP device. [1708085313.851884][1915:1916] CHIP:BLE: Device 00:9B:FF:A3:EC:10 does not look like a CHIP device. [1708085313.863355][1915:1916] CHIP:BLE: Device 17:C0:80:27:2E:B8 does not look like a CHIP device. [1708085313.892564][1915:1916] CHIP:BLE: Device 15:66:56:ED:9B:44 does not look like a CHIP device. [1708085313.897651][1915:1916] CHIP:BLE: Device 22:B0:2A:35:1C:4A does not look like a CHIP device. [1708085313.911893][1915:1916] CHIP:BLE: Device 13:0D:19:C4:3A:07 does not look like a CHIP device. [1708085313.913290][1915:1916] CHIP:BLE: Device 3A:6A:E7:A7:A9:14 does not look like a CHIP device. [1708085313.957963][1915:1916] CHIP:BLE: Device B4:9A:95:77:96:1B does not look like a CHIP device. [1708085313.980028][1915:1916] CHIP:BLE: Device 42:08:1F:CE:42:8D does not look like a CHIP device. [1708085313.984420][1915:1916] CHIP:BLE: Device 0D:4A:37:0D:C9:8F does not look like a CHIP device. [1708085314.002599][1915:1916] CHIP:BLE: Device 6D:A2:1E:F6:F2:20 does not look like a CHIP device. [1708085314.044993][1915:1916] CHIP:BLE: Device 07:A6:F0:78:C9:41 does not look like a CHIP device. [1708085314.049212][1915:1916] CHIP:BLE: Device 69:A5:8D:1A:11:BF does not look like a CHIP device. [1708085314.053535][1915:1916] CHIP:BLE: Device 9C:0C:35:62:13:B8 does not look like a CHIP device. [1708085314.070514][1915:1916] CHIP:BLE: Device 2D:22:DB:8F:23:0D does not look like a CHIP device. [1708085314.088425][1915:1916] CHIP:BLE: Device 04:69:72:B6:FD:43 does not look like a CHIP device. [1708085314.092947][1915:1916] CHIP:BLE: Device 3E:DE:74:31:A5:18 does not look like a CHIP device. [1708085314.148023][1915:1916] CHIP:BLE: Device 75:AE:F7:0B:02:DD does not look like a CHIP device. [1708085314.148479][1915:1916] CHIP:BLE: Device 28:E1:46:B5:31:AF does not look like a CHIP device. [1708085314.153042][1915:1916] CHIP:BLE: Device 2E:E3:A6:C4:9C:02 does not look like a CHIP device. [1708085314.155818][1915:1916] CHIP:BLE: Device 3D:77:D9:57:6B:6D does not look like a CHIP device. [1708085314.175021][1915:1916] CHIP:BLE: Device 38:04:C1:18:55:15 does not look like a CHIP device. [1708085314.178887][1915:1916] CHIP:BLE: Device 4B:20:3E:66:F4:79 does not look like a CHIP device. [1708085314.184480][1915:1916] CHIP:BLE: Device 3F:AA:F5:DE:B5:A4 does not look like a CHIP device. [1708085314.213609][1915:1916] CHIP:BLE: Device 31:32:65:BB:42:A8 does not look like a CHIP device. [1708085314.227378][1915:1916] CHIP:BLE: Device 09:48:FC:E5:0F:00 does not look like a CHIP device. [1708085314.234462][1915:1916] CHIP:BLE: Device 32:5E:41:FE:97:E1 does not look like a CHIP device. [1708085314.247318][1915:1916] CHIP:BLE: Device 19:93:DA:38:4F:03 does not look like a CHIP device. [1708085314.252762][1915:1916] CHIP:BLE: Device 3F:E8:37:74:B0:11 does not look like a CHIP device. [1708085314.253203][1915:1916] CHIP:BLE: Device 02:02:4C:FC:DB:50 does not look like a CHIP device. [1708085314.253506][1915:1916] CHIP:BLE: Device 42:08:1F:CE:42:8D does not look like a CHIP device. [1708085314.268628][1915:1916] CHIP:BLE: Device 37:82:12:92:B2:98 does not look like a CHIP device. [1708085314.270977][1915:1916] CHIP:BLE: Device 19:D7:04:92:AC:7A does not look like a CHIP device. [1708085314.284094][1915:1916] CHIP:BLE: Device D0:88:05:DA:12:6A does not look like a CHIP device. [1708085314.284533][1915:1916] CHIP:BLE: Device 1A:AF:42:26:D8:75 does not look like a CHIP device. [1708085314.303468][1915:1916] CHIP:BLE: Device 1B:B1:6A:1E:48:29 does not look like a CHIP device. [1708085314.306193][1915:1916] CHIP:BLE: Device 2D:1D:2F:94:7E:BF does not look like a CHIP device. [1708085314.308546][1915:1916] CHIP:BLE: Device 15:E1:37:08:60:2D does not look like a CHIP device. [1708085314.314525][1915:1916] CHIP:BLE: Device 5F:CD:E9:A6:D9:65 does not look like a CHIP device. [1708085314.321497][1915:1916] CHIP:BLE: Device 22:B0:2A:35:1C:4A does not look like a CHIP device. [1708085314.328476][1915:1916] CHIP:BLE: Device 3A:6A:E7:A7:A9:14 does not look like a CHIP device. [1708085314.333451][1915:1916] CHIP:BLE: Device F8:00:6A:88:44:48 does not look like a CHIP device. [1708085314.344448][1915:1916] CHIP:BLE: Device 1B:C2:72:A2:F0:8C does not look like a CHIP device. [1708085314.361193][1915:1916] CHIP:BLE: Device 15:3F:39:F3:69:DA does not look like a CHIP device. [1708085314.364465][1915:1916] CHIP:BLE: Device 07:A6:F0:78:C9:41 does not look like a CHIP device. [1708085314.378612][1915:1916] CHIP:BLE: Device 1F:9E:40:21:CB:7E does not look like a CHIP device. [1708085314.379007][1915:1916] CHIP:BLE: Device 00:9B:FF:A3:EC:10 does not look like a CHIP device. [1708085314.388645][1915:1916] CHIP:BLE: Device 64:C6:54:6D:DD:79 does not look like a CHIP device. [1708085314.404328][1915:1916] CHIP:BLE: Device 53:A8:00:B8:4A:E3 does not look like a CHIP device. [1708085314.423705][1915:1916] CHIP:BLE: Device AE:50:DE:4C:31:D6 does not look like a CHIP device. [1708085314.424139][1915:1916] CHIP:BLE: Device 7C:32:4B:AE:19:A1 does not look like a CHIP device. [1708085314.431832][1915:1916] CHIP:BLE: Device 13:0D:19:C4:3A:07 does not look like a CHIP device. [1708085314.449879][1915:1916] CHIP:BLE: Device 30:46:32:3C:3E:A6 does not look like a CHIP device. [1708085314.453685][1915:1916] CHIP:BLE: Device 28:E1:46:B5:31:AF does not look like a CHIP device. [1708085314.472570][1915:1916] CHIP:BLE: Device 27:4C:13:C5:21:D3 does not look like a CHIP device. [1708085314.480694][1915:1916] CHIP:BLE: Device 12:17:5C:95:3C:57 does not look like a CHIP device. [1708085314.486935][1915:1916] CHIP:BLE: Device 7F:AF:97:2A:3E:90 does not look like a CHIP device. [1708085314.487379][1915:1916] CHIP:BLE: Device 12:38:E8:FE:B2:5D does not look like a CHIP device. [1708085314.490962][1915:1916] CHIP:BLE: Device B4:9A:95:77:96:1B does not look like a CHIP device. [1708085314.502441][1915:1916] CHIP:BLE: Device 3E:DE:74:31:A5:18 does not look like a CHIP device. [1708085314.507229][1915:1916] CHIP:BLE: Device 4B:20:3E:66:F4:79 does not look like a CHIP device. [1708085314.521651][1915:1916] CHIP:BLE: Device FA:ED:AD:52:21:B2 does not look like a CHIP device. [1708085314.538901][1915:1916] CHIP:BLE: Device 78:CC:30:DE:11:6D does not look like a CHIP device. [1708085314.552168][1915:1916] CHIP:BLE: Device 5A:DF:F1:15:F2:FF does not look like a CHIP device. [1708085314.574249][1915:1916] CHIP:BLE: Device 3D:77:D9:57:6B:6D does not look like a CHIP device. [1708085314.588573][1915:1916] CHIP:BLE: Device 28:DE:65:62:6A:56 does not look like a CHIP device. [1708085314.612367][1915:1916] CHIP:BLE: Device 0D:4A:37:0D:C9:8F does not look like a CHIP device. [1708085314.615247][1915:1916] CHIP:BLE: Device 04:69:72:B6:FD:43 does not look like a CHIP device. [1708085314.631407][1915:1916] CHIP:BLE: Device 15:66:56:ED:9B:44 does not look like a CHIP device. [1708085314.649406][1915:1916] CHIP:BLE: Device 7C:A0:1A:80:9C:EE does not look like a CHIP device. [1708085314.657120][1915:1916] CHIP:BLE: Device 3F:E8:37:74:B0:11 does not look like a CHIP device. [1708085314.689863][1915:1916] CHIP:BLE: Device DA:51:B8:8B:6B:D7 does not look like a CHIP device. [1708085314.690308][1915:1916] CHIP:BLE: Device 19:D7:04:92:AC:7A does not look like a CHIP device. [1708085314.703905][1915:1916] CHIP:BLE: Device 38:04:C1:18:55:15 does not look like a CHIP device. [1708085314.723996][1915:1916] CHIP:BLE: Device 6D:A2:1E:F6:F2:20 does not look like a CHIP device. [1708085314.746066][1915:1916] CHIP:BLE: Device 3A:6A:E7:A7:A9:14 does not look like a CHIP device. [1708085314.773583][1915:1916] CHIP:BLE: Device C7:81:35:3C:3C:53 does not look like a CHIP device. [1708085314.774116][1915:1916] CHIP:BLE: Device 19:93:DA:38:4F:03 does not look like a CHIP device. [1708085314.780137][1915:1916] CHIP:BLE: Device 09:48:FC:E5:0F:00 does not look like a CHIP device. [1708085314.786001][1915:1916] CHIP:BLE: Device 15:3F:39:F3:69:DA does not look like a CHIP device. [1708085314.822313][1915:1916] CHIP:BLE: Device 1B:B1:6A:1E:48:29 does not look like a CHIP device. [1708085314.823899][1915:1916] CHIP:BLE: Device 2D:1D:2F:94:7E:BF does not look like a CHIP device. [1708085314.827438][1915:1916] CHIP:BLE: Device 21:4C:59:92:B2:54 does not look like a CHIP device. [1708085314.844994][1915:1916] CHIP:BLE: Device 22:B0:2A:35:1C:4A does not look like a CHIP device. [1708085314.861831][1915:1916] CHIP:BLE: Device D4:2F:1D:53:46:26 does not look like a CHIP device. [1708085314.862324][1915:1916] CHIP:BLE: Device 32:5E:41:FE:97:E1 does not look like a CHIP device. [1708085314.862642][1915:1916] CHIP:BLE: Device 28:E1:46:B5:31:AF does not look like a CHIP device. [1708085314.865500][1915:1916] CHIP:BLE: Device 30:46:32:3C:3E:A6 does not look like a CHIP device. [1708085314.881241][1915:1916] CHIP:BLE: Device 37:82:12:92:B2:98 does not look like a CHIP device. [1708085314.889961][1915:1916] CHIP:BLE: Device 27:4C:13:C5:21:D3 does not look like a CHIP device. [1708085314.891887][1915:1916] CHIP:BLE: Device 07:A6:F0:78:C9:41 does not look like a CHIP device. [1708085314.917622][1915:1916] CHIP:BLE: Device 1A:AF:42:26:D8:75 does not look like a CHIP device. [1708085314.920978][1915:1916] CHIP:BLE: Device 2D:22:DB:8F:23:0D does not look like a CHIP device. [1708085314.933539][1915:1916] CHIP:BLE: Device 64:C6:54:6D:DD:79 does not look like a CHIP device. [1708085314.955308][1915:1916] CHIP:BLE: Device 13:0D:19:C4:3A:07 does not look like a CHIP device. [1708085315.005292][1915:1916] CHIP:BLE: Device 42:5C:9D:B8:E0:16 does not look like a CHIP device. [1708085315.016720][1915:1916] CHIP:BLE: Device B4:9A:95:77:96:1B does not look like a CHIP device. [1708085315.023625][1915:1916] CHIP:BLE: Device 53:A8:00:B8:4A:E3 does not look like a CHIP device. [1708085315.024025][1915:1916] CHIP:BLE: Device 3F:AA:F5:DE:B5:A4 does not look like a CHIP device. [1708085315.028582][1915:1916] CHIP:BLE: Device 68:27:37:08:85:43 does not look like a CHIP device. [1708085315.029379][1915:1916] CHIP:BLE: Device 0D:4A:37:0D:C9:8F does not look like a CHIP device. [1708085315.040984][1915:1916] CHIP:BLE: Device 04:69:72:B6:FD:43 does not look like a CHIP device. [1708085315.050492][1915:1916] CHIP:BLE: Device 7F:AF:97:2A:3E:90 does not look like a CHIP device. [1708085315.050906][1915:1916] CHIP:BLE: Device 12:38:E8:FE:B2:5D does not look like a CHIP device. [1708085315.061203][1915:1916] CHIP:BLE: New device scanned: 88:B1:11:E3:F8:E5 [1708085315.061304][1915:1916] CHIP:BLE: Device discriminator match. Attempting to connect. [1708085315.066265][1915:1916] CHIP:BLE: ChipDeviceScanner has stopped scanning! [1708085315.139661][1915:1916] CHIP:DL: FAIL: ConnectDevice: GDBus.Error:org.freedesktop.DBus.Error.UnknownObject: Method "Connect" with signature "" on interface "org.bluez.Device1" doesn't exist (41) [1708085315.139883][1915:1916] CHIP:BLE: Device connection failed: src/platform/Linux/bluez/BluezEndpoint.cpp:749: CHIP Error 0x000000AC: Internal error [1708085315.140002][1915:1917] CHIP:DL: HandlePlatformSpecificBLEEvent 16386 [1708085315.140075][1915:1917] CHIP:DIS: Closing all BLE connections [1708085315.140185][1915:1917] CHIP:TOO: Pairing Failure: src/platform/Linux/bluez/BluezEndpoint.cpp:748: CHIP Error 0x000000AC: Internal error [1708085315.140791][1915:1915] CHIP:CTL: Shutting down the commissioner [1708085315.141217][1915:1915] CHIP:CTL: Shutting down the controller [1708085315.141469][1915:1915] CHIP:IN: Expiring all sessions for fabric 0x1!! [1708085315.141526][1915:1915] CHIP:FP: Forgetting fabric 0x1 [1708085315.141608][1915:1915] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48 [1708085315.142111][1915:1915] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48 [1708085315.142183][1915:1915] CHIP:TS: Reverted Last Known Good Time to previous value [1708085315.142282][1915:1915] CHIP:CTL: Shutting down the commissioner [1708085315.142551][1915:1915] CHIP:CTL: Shutting down the controller [1708085315.142617][1915:1915] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1708085315.143000][1915:1915] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1708085315.143217][1915:1915] CHIP:FP: Shutting down FabricTable [1708085315.143461][1915:1915] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48 [1708085315.143751][1915:1915] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48 [1708085315.143827][1915:1915] CHIP:TS: Reverted Last Known Good Time to previous value [1708085315.144410][1915:1915] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-2JHDEI) [1708085315.145998][1915:1915] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085315.146165][1915:1915] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1708085315.146226][1915:1915] CHIP:DL: Inet Layer shutdown [1708085315.146278][1915:1915] CHIP:DL: BLE shutdown [1708085315.171089][1915:1915] CHIP:DL: System Layer shutdown [1708085315.175122][1915:1915] CHIP:TOO: Run command failure: src/platform/Linux/bluez/BluezEndpoint.cpp:748: CHIP Error 0x000000AC: Internal error ubuntu@ubuntu:~/master_cntrl/connectedhomeip/out/chip-tool$ sudo rm -rf /tmp/chip_* ubuntu@ubuntu:~/master_cntrl/connectedhomeip/out/chip-tool$ ./chip-tool pairing ble-wifi 1 GRLPrivate grlprivatewifi092010 20202021 3840 [1708085324.299239][1925:1925] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs [1708085324.299682][1925:1925] CHIP:DL: writing settings to file (/tmp/chip_tool_kvs-JKf6ZJ) [1708085324.300100][1925:1925] CHIP:DL: renamed tmp file to file (/tmp/chip_tool_kvs) [1708085324.301837][1925:1925] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1708085324.301912][1925:1925] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs [1708085324.316610][1925:1925] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1708085324.317133][1925:1925] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-wfwI91) [1708085324.317569][1925:1925] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085324.317899][1925:1925] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1708085324.318184][1925:1925] CHIP:DL: writing settings to file (/tmp/chip_config.ini-6YuJom) [1708085324.318510][1925:1925] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085324.318736][1925:1925] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1708085324.319006][1925:1925] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-7BBzhO) [1708085324.319324][1925:1925] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085324.319994][1925:1925] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-MRtdxZ) [1708085324.321050][1925:1925] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085324.321171][1925:1925] CHIP:DL: NVS set: chip-factory/unique-id = "9B7CA736101B96C8" [1708085324.321469][1925:1925] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-PIgaIv) [1708085324.322703][1925:1925] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085324.322828][1925:1925] CHIP:DL: NVS set: chip-factory/vendor-id = 65521 (0xFFF1) [1708085324.323313][1925:1925] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-NjRYEO) [1708085324.324340][1925:1925] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085324.324459][1925:1925] CHIP:DL: NVS set: chip-factory/product-id = 32769 (0x8001) [1708085324.324936][1925:1925] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-FgSGlR) [1708085324.325826][1925:1925] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085324.325942][1925:1925] CHIP:DL: NVS set: chip-counters/reboot-count = 1 (0x1) [1708085324.326224][1925:1925] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-IftKvK) [1708085324.327374][1925:1925] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085324.327491][1925:1925] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1708085324.327794][1925:1925] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-ivpgeG) [1708085324.328927][1925:1925] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085324.329045][1925:1925] CHIP:DL: NVS set: chip-counters/boot-reason = 0 (0x0) [1708085324.329334][1925:1925] CHIP:DL: writing settings to file (/tmp/chip_config.ini-x5dV6q) [1708085324.330392][1925:1925] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085324.330513][1925:1925] CHIP:DL: NVS set: chip-config/regulatory-location = 0 (0x0) [1708085324.330800][1925:1925] CHIP:DL: writing settings to file (/tmp/chip_config.ini-BcSSv8) [1708085324.331886][1925:1925] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085324.332003][1925:1925] CHIP:DL: NVS set: chip-config/location-capability = 2 (0x2) [1708085324.333861][1925:1925] CHIP:DL: Got Ethernet interface: eth0 [1708085324.335106][1925:1925] CHIP:DL: Found the primary Ethernet interface:eth0 [1708085324.336384][1925:1925] CHIP:DL: Got WiFi interface: wlan0 [1708085324.336541][1925:1925] CHIP:DL: Failed to reset WiFi statistic counts [1708085324.336651][1925:1925] CHIP:IN: UDP::Init bind&listen port=0 [1708085324.336911][1925:1925] CHIP:IN: UDP::Init bound to port=51342 [1708085324.336968][1925:1925] CHIP:IN: BLEBase::Init - setting/overriding transport [1708085324.337017][1925:1925] CHIP:IN: TransportMgr initialized [1708085324.337127][1925:1925] CHIP:FP: Initializing FabricTable from persistent storage [1708085324.337220][1925:1925] CHIP:TS: Last Known Good Time: [unknown] [1708085324.337286][1925:1925] CHIP:TS: Setting Last Known Good Time to firmware build time 2023-10-14T01:16:48 [1708085324.341366][1925:1925] CHIP:ZCL: Using ZAP configuration... [1708085324.351106][1925:1925] CHIP:DL: Avahi client registered [1708085324.351352][1925:1925] CHIP:CTL: System State Initialized... [1708085324.351726][1925:1925] CHIP:CTL: Setting attestation nonce to random value [1708085324.351828][1925:1925] CHIP:CTL: Setting CSR nonce to random value [1708085324.351994][1925:1925] CHIP:IN: UDP::Init bind&listen port=5550 [1708085324.352433][1925:1925] CHIP:IN: UDP::Init bound to port=5550 [1708085324.352495][1925:1925] CHIP:IN: TransportMgr initialized [1708085324.354943][1925:1927] CHIP:DL: CHIP task running [1708085324.355366][1925:1927] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1708085324.356425][1925:1927] CHIP:CTL: Setting attestation nonce to random value [1708085324.356866][1925:1927] CHIP:CTL: Setting CSR nonce to random value [1708085324.357208][1925:1927] CHIP:CTL: Couldn't get ExampleOpCredsCAKey from storage: src/controller/ExamplePersistentStorage.cpp:106: CHIP Error 0x000000A0: Value not found in the persisted storage [1708085324.359781][1925:1927] CHIP:CTL: Couldn't get ExampleOpCredsICAKey from storage: src/controller/ExamplePersistentStorage.cpp:106: CHIP Error 0x000000A0: Value not found in the persisted storage [1708085324.362634][1925:1927] CHIP:CTL: Generating RCAC [1708085324.366236][1925:1927] CHIP:CTL: Generating ICAC [1708085324.368554][1925:1927] CHIP:CTL: Generating NOC [1708085324.370318][1925:1927] CHIP:FP: Validating NOC chain [1708085324.376522][1925:1927] CHIP:FP: NOC chain validation successful [1708085324.376964][1925:1927] CHIP:FP: Added new fabric at index: 0x1 [1708085324.377059][1925:1927] CHIP:FP: Assigned compressed fabric ID: 0x632A45CBA4C7AA44, node ID: 0x000000000001B669 [1708085324.377126][1925:1927] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48 [1708085324.377179][1925:1927] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1708085324.377228][1925:1927] CHIP:TS: Retaining current Last Known Good Time [1708085324.380903][1925:1927] CHIP:FP: Metadata for Fabric 0x1 persisted to storage. [1708085324.386090][1925:1927] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-14T01:16:48 [1708085324.393396][1925:1927] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 632A45CBA4C7AA44) [1708085324.393505][1925:1927] CHIP:IN: UDP::Init bind&listen port=5550 [1708085324.393865][1925:1927] CHIP:IN: UDP::Init bound to port=5550 [1708085324.393927][1925:1927] CHIP:IN: TransportMgr initialized [1708085324.462230][1925:1927] CHIP:CTL: Setting wifi credentials from parameters [1708085324.462322][1925:1927] CHIP:CTL: Setting attestation nonce to random value [1708085324.462421][1925:1927] CHIP:CTL: Setting CSR nonce to random value [1708085324.462508][1925:1927] CHIP:CTL: Checking ICD registration parameters [1708085324.462606][1925:1927] CHIP:CTL: Commission called for node ID 0x0000000000000001 [1708085324.462679][1925:1927] CHIP:DL: Long dispatch time: 107 ms, for event type 2 [1708085324.523018][1925:1927] CHIP:DL: BlueZ integration init success [1708085324.566094][1925:1926] CHIP:BLE: BLE removing known devices. [1708085324.570283][1925:1926] CHIP:BLE: BLE initiating scan. [1708085324.575484][1925:1927] CHIP:BLE: ChipDeviceScanner has started scanning! [1708085324.575586][1925:1927] CHIP:DL: Long dispatch time: 112 ms, for event type 3 [1708085324.588367][1925:1926] CHIP:BLE: Device 3A:6A:E7:A7:A9:14 does not look like a CHIP device. [1708085324.591661][1925:1926] CHIP:BLE: Device 37:82:12:92:B2:98 does not look like a CHIP device. [1708085324.605296][1925:1926] CHIP:BLE: Device 13:0D:19:C4:3A:07 does not look like a CHIP device. [1708085324.614891][1925:1926] CHIP:BLE: Device 04:69:72:B6:FD:43 does not look like a CHIP device. [1708085324.620290][1925:1926] CHIP:BLE: Device 2D:22:DB:8F:23:0D does not look like a CHIP device. [1708085324.626618][1925:1926] CHIP:BLE: Device 0D:4A:37:0D:C9:8F does not look like a CHIP device. [1708085324.639780][1925:1926] CHIP:BLE: Device 69:A5:8D:1A:11:BF does not look like a CHIP device. [1708085324.640248][1925:1926] CHIP:BLE: Device 09:48:FC:E5:0F:00 does not look like a CHIP device. [1708085324.644205][1925:1926] CHIP:BLE: Device 07:A6:F0:78:C9:41 does not look like a CHIP device. [1708085324.647261][1925:1926] CHIP:BLE: Device 22:B0:2A:35:1C:4A does not look like a CHIP device. [1708085324.658072][1925:1926] CHIP:BLE: Device 15:E1:37:08:60:2D does not look like a CHIP device. [1708085324.661574][1925:1926] CHIP:BLE: Device 38:04:C1:18:55:15 does not look like a CHIP device. [1708085324.676019][1925:1926] CHIP:BLE: Device 15:29:80:16:1F:61 does not look like a CHIP device. [1708085324.680803][1925:1926] CHIP:BLE: Device 1B:B1:6A:1E:48:29 does not look like a CHIP device. [1708085324.700248][1925:1926] CHIP:BLE: Device 19:93:DA:38:4F:03 does not look like a CHIP device. [1708085324.715645][1925:1926] CHIP:BLE: Device 42:5C:9D:B8:E0:16 does not look like a CHIP device. [1708085324.718739][1925:1926] CHIP:BLE: Device 3E:DE:74:31:A5:18 does not look like a CHIP device. [1708085324.728622][1925:1926] CHIP:BLE: Device 7F:AF:97:2A:3E:90 does not look like a CHIP device. [1708085324.729103][1925:1926] CHIP:BLE: Device AE:50:DE:4C:31:D6 does not look like a CHIP device. [1708085324.733987][1925:1926] CHIP:BLE: Device 7C:32:4B:AE:19:A1 does not look like a CHIP device. [1708085324.740649][1925:1926] CHIP:BLE: Device 6D:A2:1E:F6:F2:20 does not look like a CHIP device. [1708085324.746694][1925:1926] CHIP:BLE: Device 3F:E8:37:74:B0:11 does not look like a CHIP device. [1708085324.759387][1925:1926] CHIP:BLE: Device 3F:AA:F5:DE:B5:A4 does not look like a CHIP device. [1708085324.763438][1925:1926] CHIP:BLE: Device 28:E1:46:B5:31:AF does not look like a CHIP device. [1708085324.763967][1925:1926] CHIP:BLE: Device 53:A8:00:B8:4A:E3 does not look like a CHIP device. [1708085324.775503][1925:1926] CHIP:BLE: Device 19:D7:04:92:AC:7A does not look like a CHIP device. [1708085324.840292][1925:1926] CHIP:BLE: Device 5A:DF:F1:15:F2:FF does not look like a CHIP device. [1708085324.844849][1925:1926] CHIP:BLE: Device 32:5E:41:FE:97:E1 does not look like a CHIP device. [1708085324.858106][1925:1926] CHIP:BLE: Device 15:3F:39:F3:69:DA does not look like a CHIP device. [1708085324.863470][1925:1926] CHIP:BLE: Device 27:4C:13:C5:21:D3 does not look like a CHIP device. [1708085324.872570][1925:1926] CHIP:BLE: Device 21:4C:59:92:B2:54 does not look like a CHIP device. [1708085324.877500][1925:1926] CHIP:BLE: Device 17:C0:80:27:2E:B8 does not look like a CHIP device. [1708085324.889838][1925:1926] CHIP:BLE: Device 2D:1D:2F:94:7E:BF does not look like a CHIP device. [1708085324.907369][1925:1926] CHIP:BLE: Device 4B:20:3E:66:F4:79 does not look like a CHIP device. [1708085324.938832][1925:1926] CHIP:BLE: Device 00:9B:FF:A3:EC:10 does not look like a CHIP device. [1708085324.947789][1925:1926] CHIP:BLE: Device 15:66:56:ED:9B:44 does not look like a CHIP device. [1708085324.966196][1925:1926] CHIP:BLE: Device 78:CF:2A:53:F6:61 does not look like a CHIP device. [1708085324.969085][1925:1926] CHIP:BLE: Device 68:27:37:08:85:43 does not look like a CHIP device. [1708085324.979545][1925:1926] CHIP:BLE: Device 1A:AF:42:26:D8:75 does not look like a CHIP device. [1708085324.984301][1925:1926] CHIP:BLE: Device 42:5C:9D:B8:E0:16 does not look like a CHIP device. [1708085325.006154][1925:1926] CHIP:BLE: Device 1F:9E:40:21:CB:7E does not look like a CHIP device. [1708085325.006599][1925:1926] CHIP:BLE: Device B4:9A:95:77:96:1B does not look like a CHIP device. [1708085325.035913][1925:1926] CHIP:BLE: Device 1B:C2:72:A2:F0:8C does not look like a CHIP device. [1708085325.036366][1925:1926] CHIP:BLE: Device 04:69:72:B6:FD:43 does not look like a CHIP device. [1708085325.045874][1925:1926] CHIP:BLE: Device 30:46:32:3C:3E:A6 does not look like a CHIP device. [1708085325.062802][1925:1926] CHIP:BLE: Device 07:A6:F0:78:C9:41 does not look like a CHIP device. [1708085325.091854][1925:1926] CHIP:BLE: Device 15:29:80:16:1F:61 does not look like a CHIP device. [1708085325.095198][1925:1926] CHIP:BLE: Device 12:38:E8:FE:B2:5D does not look like a CHIP device. [1708085325.099133][1925:1926] CHIP:BLE: Device 1B:B1:6A:1E:48:29 does not look like a CHIP device. [1708085325.135468][1925:1926] CHIP:BLE: Device 4F:FF:39:EB:DD:5F does not look like a CHIP device. [1708085325.143763][1925:1926] CHIP:BLE: Device F0:EE:C1:BC:49:0D does not look like a CHIP device. [1708085325.171337][1925:1926] CHIP:BLE: Device 15:E1:37:08:60:2D does not look like a CHIP device. [1708085325.187557][1925:1926] CHIP:BLE: Device 38:04:C1:18:55:15 does not look like a CHIP device. [1708085325.195363][1925:1926] CHIP:BLE: Device 3D:77:D9:57:6B:6D does not look like a CHIP device. [1708085325.213471][1925:1926] CHIP:BLE: Device 1F:9E:40:21:CB:7E does not look like a CHIP device. [1708085325.215752][1925:1926] CHIP:BLE: Device 19:93:DA:38:4F:03 does not look like a CHIP device. [1708085325.232196][1925:1926] CHIP:BLE: Device 6D:61:0E:21:86:B2 does not look like a CHIP device. [1708085325.232646][1925:1926] CHIP:BLE: Device 3E:DE:74:31:A5:18 does not look like a CHIP device. [1708085325.243705][1925:1926] CHIP:BLE: New device scanned: E9:6E:8D:D5:DA:39 [1708085325.243799][1925:1926] CHIP:BLE: Device discriminator match. Attempting to connect. [1708085325.248929][1925:1926] CHIP:BLE: ChipDeviceScanner has stopped scanning! [1708085325.366439][1925:1926] CHIP:DL: ConnectDevice complete [1708085325.366544][1925:1926] CHIP:BLE: New device connected: E9:6E:8D:D5:DA:39 [1708085326.358709][1925:1926] CHIP:DL: Char /org/bluez/hci0/dev_E9_6E_8D_D5_DA_39/service000c on service /org/bluez/hci0/dev_E9_6E_8D_D5_DA_39/service000c [1708085326.358850][1925:1926] CHIP:DL: Char /org/bluez/hci0/dev_E9_6E_8D_D5_DA_39/service000c on service /org/bluez/hci0/dev_E9_6E_8D_D5_DA_39/service000c [1708085326.358917][1925:1926] CHIP:DL: Char /org/bluez/hci0/dev_E9_6E_8D_D5_DA_39/service000c on service /org/bluez/hci0/dev_E9_6E_8D_D5_DA_39/service000c [1708085326.359033][1925:1926] CHIP:DL: New BLE connection: conn 0xffff8c08ff30, device E9:6E:8D:D5:DA:39, path /org/bluez/hci0/dev_E9_6E_8D_D5_DA_39 [1708085326.359291][1925:1927] CHIP:DL: HandlePlatformSpecificBLEEvent 16385 [1708085326.359416][1925:1927] CHIP:DIS: Closing all BLE connections [1708085326.359534][1925:1927] CHIP:IN: BleConnectionComplete: endPoint 0xaaaab2446358 [1708085326.360513][1925:1927] CHIP:IN: SecureSession[0xffff94037cf0]: Allocated Type:1 LSID:23872 [1708085326.360606][1925:1927] CHIP:SC: Assigned local session key ID 23872 [1708085326.360863][1925:1927] CHIP:EM: <<< [E:15383i S:0 M:162745544] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:20 (SecureChannel:PBKDFParamRequest) [1708085326.360965][1925:1927] CHIP:IN: Message appended to BLE send queue [1708085326.361069][1925:1927] CHIP:SC: Sent PBKDF param request [1708085326.761137][1925:1927] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1708085326.852019][1925:1927] CHIP:DL: HandlePlatformSpecificBLEEvent 16388 [1708085326.852156][1925:1927] CHIP:BLE: subscribe complete, ep = 0xaaaab2446358 [1708085326.852440][1925:1926] CHIP:DL: Indication received, conn = 0xffff8c08ff30 [1708085326.852642][1925:1927] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1708085326.852702][1925:1927] CHIP:BLE: peripheral chose BTP version 4; central expected between 4 and 4 [1708085326.852749][1925:1927] CHIP:BLE: using BTP fragment sizes rx 244 / tx 244. [1708085326.852797][1925:1927] CHIP:BLE: local and remote recv window size = 5 [1708085326.853513][1925:1927] CHIP:IN: BLE EndPoint 0xaaaab2446358 Connection Complete [1708085326.940913][1925:1927] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1708085326.988258][1925:1926] CHIP:DL: Indication received, conn = 0xffff8c08ff30 [1708085326.988544][1925:1927] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1708085326.988791][1925:1927] CHIP:EM: >>> [E:15383i S:0 M:166818096] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:21 (SecureChannel:PBKDFParamResponse) [1708085326.988908][1925:1927] CHIP:EM: Found matching exchange: 15383i, Delegate: 0xffff94036d60 [1708085326.989009][1925:1927] CHIP:SC: Received PBKDF param response [1708085326.989133][1925:1927] CHIP:SC: Peer assigned session ID 38035 [1708085326.989210][1925:1927] CHIP:SC: Found MRP parameters in the message [1708085327.006077][1925:1927] CHIP:EM: <<< [E:15383i S:0 M:162745545] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:22 (SecureChannel:PASE_Pake1) [1708085327.006923][1925:1927] CHIP:SC: Sent spake2p msg1 [1708085327.077215][1925:1927] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1708085328.833120][1925:1926] CHIP:DL: Indication received, conn = 0xffff8c08ff30 [1708085328.833400][1925:1927] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1708085328.833630][1925:1927] CHIP:EM: >>> [E:15383i S:0 M:166818097] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:23 (SecureChannel:PASE_Pake2) [1708085328.833710][1925:1927] CHIP:EM: Found matching exchange: 15383i, Delegate: 0xffff94036d60 [1708085328.833873][1925:1927] CHIP:SC: Received spake2p msg2 [1708085328.837245][1925:1927] CHIP:EM: <<< [E:15383i S:0 M:162745546] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:24 (SecureChannel:PASE_Pake3) [1708085328.838102][1925:1927] CHIP:SC: Sent spake2p msg3 [1708085329.236174][1925:1927] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1708085334.818191][1925:1926] CHIP:DL: Bluez disconnected [1708085334.818288][1925:1926] CHIP:DL: Bluez notify CHIPoBluez connection disconnected [1708085334.818536][1925:1927] CHIP:IN: Clearing BLE pending packets. ^C ubuntu@ubuntu:~/master_cntrl/connectedhomeip/out/chip-tool$ sudo rm -rf /tmp/chip_* ubuntu@ubuntu:~/master_cntrl/connectedhomeip/out/chip-tool$ ./chip-tool pairing ble-wifi 1 GRLPrivate grlprivatewifi092010 20202021 3840 [1708085368.134167][1937:1937] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs [1708085368.134655][1937:1937] CHIP:DL: writing settings to file (/tmp/chip_tool_kvs-KKHu2T) [1708085368.135032][1937:1937] CHIP:DL: renamed tmp file to file (/tmp/chip_tool_kvs) [1708085368.136683][1937:1937] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1708085368.136762][1937:1937] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs [1708085368.151400][1937:1937] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1708085368.151924][1937:1937] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-bA7Zlf) [1708085368.152352][1937:1937] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085368.152610][1937:1937] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1708085368.152882][1937:1937] CHIP:DL: writing settings to file (/tmp/chip_config.ini-MkRvBm) [1708085368.153198][1937:1937] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085368.153413][1937:1937] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1708085368.153678][1937:1937] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-G14meS) [1708085368.154106][1937:1937] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085368.154803][1937:1937] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-cqRA8M) [1708085368.155876][1937:1937] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085368.156001][1937:1937] CHIP:DL: NVS set: chip-factory/unique-id = "AB8CFC92B4ECC7A4" [1708085368.156320][1937:1937] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-5fSs7s) [1708085368.157507][1937:1937] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085368.157632][1937:1937] CHIP:DL: NVS set: chip-factory/vendor-id = 65521 (0xFFF1) [1708085368.157989][1937:1937] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-l6vkh8) [1708085368.159159][1937:1937] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085368.159279][1937:1937] CHIP:DL: NVS set: chip-factory/product-id = 32769 (0x8001) [1708085368.159569][1937:1937] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-oF9kzz) [1708085368.160564][1937:1937] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085368.160682][1937:1937] CHIP:DL: NVS set: chip-counters/reboot-count = 1 (0x1) [1708085368.160965][1937:1937] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-QSGzPJ) [1708085368.162014][1937:1937] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085368.162135][1937:1937] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1708085368.162420][1937:1937] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-olsfmg) [1708085368.163540][1937:1937] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085368.163658][1937:1937] CHIP:DL: NVS set: chip-counters/boot-reason = 0 (0x0) [1708085368.163964][1937:1937] CHIP:DL: writing settings to file (/tmp/chip_config.ini-r0qUCo) [1708085368.164924][1937:1937] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085368.165042][1937:1937] CHIP:DL: NVS set: chip-config/regulatory-location = 0 (0x0) [1708085368.165337][1937:1937] CHIP:DL: writing settings to file (/tmp/chip_config.ini-JZrtbd) [1708085368.166446][1937:1937] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085368.166570][1937:1937] CHIP:DL: NVS set: chip-config/location-capability = 2 (0x2) [1708085368.168333][1937:1937] CHIP:DL: Got Ethernet interface: eth0 [1708085368.169551][1937:1937] CHIP:DL: Found the primary Ethernet interface:eth0 [1708085368.170916][1937:1937] CHIP:DL: Got WiFi interface: wlan0 [1708085368.171077][1937:1937] CHIP:DL: Failed to reset WiFi statistic counts [1708085368.171189][1937:1937] CHIP:IN: UDP::Init bind&listen port=0 [1708085368.171455][1937:1937] CHIP:IN: UDP::Init bound to port=39353 [1708085368.171511][1937:1937] CHIP:IN: BLEBase::Init - setting/overriding transport [1708085368.171562][1937:1937] CHIP:IN: TransportMgr initialized [1708085368.171675][1937:1937] CHIP:FP: Initializing FabricTable from persistent storage [1708085368.171768][1937:1937] CHIP:TS: Last Known Good Time: [unknown] [1708085368.171833][1937:1937] CHIP:TS: Setting Last Known Good Time to firmware build time 2023-10-14T01:16:48 [1708085368.175977][1937:1937] CHIP:ZCL: Using ZAP configuration... [1708085368.185689][1937:1937] CHIP:DL: Avahi client registered [1708085368.185974][1937:1937] CHIP:CTL: System State Initialized... [1708085368.186389][1937:1937] CHIP:CTL: Setting attestation nonce to random value [1708085368.186511][1937:1937] CHIP:CTL: Setting CSR nonce to random value [1708085368.186680][1937:1937] CHIP:IN: UDP::Init bind&listen port=5550 [1708085368.187005][1937:1937] CHIP:IN: UDP::Init bound to port=5550 [1708085368.187064][1937:1937] CHIP:IN: TransportMgr initialized [1708085368.189342][1937:1939] CHIP:DL: CHIP task running [1708085368.189848][1937:1939] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1708085368.191087][1937:1939] CHIP:CTL: Setting attestation nonce to random value [1708085368.191495][1937:1939] CHIP:CTL: Setting CSR nonce to random value [1708085368.191809][1937:1939] CHIP:CTL: Couldn't get ExampleOpCredsCAKey from storage: src/controller/ExamplePersistentStorage.cpp:106: CHIP Error 0x000000A0: Value not found in the persisted storage [1708085368.194432][1937:1939] CHIP:CTL: Couldn't get ExampleOpCredsICAKey from storage: src/controller/ExamplePersistentStorage.cpp:106: CHIP Error 0x000000A0: Value not found in the persisted storage [1708085368.197242][1937:1939] CHIP:CTL: Generating RCAC [1708085368.201141][1937:1939] CHIP:CTL: Generating ICAC [1708085368.203562][1937:1939] CHIP:CTL: Generating NOC [1708085368.205478][1937:1939] CHIP:FP: Validating NOC chain [1708085368.211698][1937:1939] CHIP:FP: NOC chain validation successful [1708085368.212145][1937:1939] CHIP:FP: Added new fabric at index: 0x1 [1708085368.212332][1937:1939] CHIP:FP: Assigned compressed fabric ID: 0x86A05090F92BF351, node ID: 0x000000000001B669 [1708085368.212401][1937:1939] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48 [1708085368.212455][1937:1939] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1708085368.212505][1937:1939] CHIP:TS: Retaining current Last Known Good Time [1708085368.216236][1937:1939] CHIP:FP: Metadata for Fabric 0x1 persisted to storage. [1708085368.223578][1937:1939] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-14T01:16:48 [1708085368.227970][1937:1939] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 86A05090F92BF351) [1708085368.228075][1937:1939] CHIP:IN: UDP::Init bind&listen port=5550 [1708085368.228331][1937:1939] CHIP:IN: UDP::Init bound to port=5550 [1708085368.228388][1937:1939] CHIP:IN: TransportMgr initialized [1708085368.303311][1937:1939] CHIP:CTL: Setting wifi credentials from parameters [1708085368.303399][1937:1939] CHIP:CTL: Setting attestation nonce to random value [1708085368.303492][1937:1939] CHIP:CTL: Setting CSR nonce to random value [1708085368.303575][1937:1939] CHIP:CTL: Checking ICD registration parameters [1708085368.303671][1937:1939] CHIP:CTL: Commission called for node ID 0x0000000000000001 [1708085368.303740][1937:1939] CHIP:DL: Long dispatch time: 114 ms, for event type 2 [1708085368.325994][1937:1939] CHIP:DL: BlueZ integration init success [1708085368.338617][1937:1938] CHIP:BLE: BLE removing known devices. [1708085368.342411][1937:1938] CHIP:BLE: BLE initiating scan. [1708085368.347251][1937:1939] CHIP:BLE: ChipDeviceScanner has started scanning! [1708085368.356635][1937:1938] CHIP:BLE: Device CF:F7:23:9E:7E:29 does not look like a CHIP device. [1708085368.359601][1937:1938] CHIP:BLE: Device 11:5F:5B:E8:E0:33 does not look like a CHIP device. [1708085368.370148][1937:1938] CHIP:BLE: Device 07:A6:F0:78:C9:41 does not look like a CHIP device. [1708085368.373562][1937:1938] CHIP:BLE: Device 19:93:DA:38:4F:03 does not look like a CHIP device. [1708085368.376579][1937:1938] CHIP:BLE: Device 1B:B1:6A:1E:48:29 does not look like a CHIP device. [1708085368.379453][1937:1938] CHIP:BLE: Device 14:13:09:CB:2E:C5 does not look like a CHIP device. [1708085368.399077][1937:1938] CHIP:BLE: Device 39:07:09:38:A4:54 does not look like a CHIP device. [1708085368.401955][1937:1938] CHIP:BLE: Device 22:B0:2A:35:1C:4A does not look like a CHIP device. [1708085368.407577][1937:1938] CHIP:BLE: Device 1A:74:8F:36:29:13 does not look like a CHIP device. [1708085368.413238][1937:1938] CHIP:BLE: Device 53:A8:00:B8:4A:E3 does not look like a CHIP device. [1708085368.416155][1937:1938] CHIP:BLE: Device D0:88:05:DA:12:6A does not look like a CHIP device. [1708085368.420318][1937:1938] CHIP:BLE: Device 3A:6A:E7:A7:A9:14 does not look like a CHIP device. [1708085368.435454][1937:1938] CHIP:BLE: Device 5A:DF:F1:15:F2:FF does not look like a CHIP device. [1708085368.444846][1937:1938] CHIP:BLE: Device 02:3D:69:33:ED:C4 does not look like a CHIP device. [1708085368.447899][1937:1938] CHIP:BLE: Device 2D:22:DB:8F:23:0D does not look like a CHIP device. [1708085368.450705][1937:1938] CHIP:BLE: Device 38:88:E3:A2:49:FD does not look like a CHIP device. [1708085368.462098][1937:1938] CHIP:BLE: Device 15:3F:39:F3:69:DA does not look like a CHIP device. [1708085368.473856][1937:1938] CHIP:BLE: Device F8:00:6A:88:44:48 does not look like a CHIP device. [1708085368.476671][1937:1938] CHIP:BLE: Device 27:4C:13:C5:21:D3 does not look like a CHIP device. [1708085368.492947][1937:1938] CHIP:BLE: Device 2D:1D:2F:94:7E:BF does not look like a CHIP device. [1708085368.498137][1937:1938] CHIP:BLE: Device 78:CC:30:DE:11:6D does not look like a CHIP device. [1708085368.513118][1937:1938] CHIP:BLE: Device 37:82:12:92:B2:98 does not look like a CHIP device. [1708085368.520892][1937:1938] CHIP:BLE: Device 4B:20:3E:66:F4:79 does not look like a CHIP device. [1708085368.523745][1937:1938] CHIP:BLE: Device 02:22:9A:53:3F:00 does not look like a CHIP device. [1708085368.526494][1937:1938] CHIP:BLE: Device 19:D7:04:92:AC:7A does not look like a CHIP device. [1708085368.542349][1937:1938] CHIP:BLE: Device 25:C7:9B:A9:09:EA does not look like a CHIP device. [1708085368.576402][1937:1938] CHIP:BLE: Device 12:38:E8:FE:B2:5D does not look like a CHIP device. [1708085368.593952][1937:1938] CHIP:BLE: Device 15:E1:37:08:60:2D does not look like a CHIP device. [1708085368.599752][1937:1938] CHIP:BLE: Device 19:A6:57:3F:36:40 does not look like a CHIP device. [1708085368.603430][1937:1938] CHIP:BLE: Device 04:69:72:B6:FD:43 does not look like a CHIP device. [1708085368.606407][1937:1938] CHIP:BLE: Device 5F:CD:E9:A6:D9:65 does not look like a CHIP device. [1708085368.609135][1937:1938] CHIP:BLE: Device B4:9A:95:77:96:1B does not look like a CHIP device. [1708085368.621284][1937:1938] CHIP:BLE: Device 2E:E3:A6:C4:9C:02 does not look like a CHIP device. [1708085368.636442][1937:1938] CHIP:BLE: Device 09:48:FC:E5:0F:00 does not look like a CHIP device. [1708085368.639268][1937:1938] CHIP:BLE: Device 3F:E8:37:74:B0:11 does not look like a CHIP device. [1708085368.647878][1937:1938] CHIP:BLE: Device 7F:AF:97:2A:3E:90 does not look like a CHIP device. [1708085368.650756][1937:1938] CHIP:BLE: Device 00:9B:FF:A3:EC:10 does not look like a CHIP device. [1708085368.653404][1937:1938] CHIP:BLE: Device 6D:A2:1E:F6:F2:20 does not look like a CHIP device. [1708085368.657064][1937:1938] CHIP:BLE: Device 11:5F:5B:E8:E0:33 does not look like a CHIP device. [1708085368.675227][1937:1938] CHIP:BLE: Device 07:A6:F0:78:C9:41 does not look like a CHIP device. [1708085368.679059][1937:1938] CHIP:BLE: Device 1B:B1:6A:1E:48:29 does not look like a CHIP device. [1708085368.683566][1937:1938] CHIP:BLE: Device 4B:20:3E:66:F4:79 does not look like a CHIP device. [1708085368.686935][1937:1938] CHIP:BLE: Device 19:93:DA:38:4F:03 does not look like a CHIP device. [1708085368.704121][1937:1938] CHIP:BLE: Device 1C:10:D5:EC:62:82 does not look like a CHIP device. [1708085368.712314][1937:1938] CHIP:BLE: Device 39:07:09:38:A4:54 does not look like a CHIP device. [1708085368.715268][1937:1938] CHIP:BLE: Device 1A:74:8F:36:29:13 does not look like a CHIP device. [1708085368.731237][1937:1938] CHIP:BLE: Device 53:A8:00:B8:4A:E3 does not look like a CHIP device. [1708085368.731583][1937:1938] CHIP:BLE: Device 3A:6A:E7:A7:A9:14 does not look like a CHIP device. [1708085368.745896][1937:1938] CHIP:BLE: Device CF:91:CC:65:1B:F4 does not look like a CHIP device. [1708085368.746371][1937:1938] CHIP:BLE: Device 5A:DF:F1:15:F2:FF does not look like a CHIP device. [1708085368.798309][1937:1938] CHIP:BLE: Device FA:ED:AD:52:21:B2 does not look like a CHIP device. [1708085368.804250][1937:1938] CHIP:BLE: Device 3D:77:D9:57:6B:6D does not look like a CHIP device. [1708085368.827588][1937:1938] CHIP:BLE: Device 1A:AF:42:26:D8:75 does not look like a CHIP device. [1708085368.859761][1937:1938] CHIP:BLE: Device AE:50:DE:4C:31:D6 does not look like a CHIP device. [1708085368.862573][1937:1938] CHIP:BLE: Device 0D:4A:37:0D:C9:8F does not look like a CHIP device. [1708085368.874764][1937:1938] CHIP:BLE: Device 15:3F:39:F3:69:DA does not look like a CHIP device. [1708085368.882333][1937:1938] CHIP:BLE: Device 15:29:80:16:1F:61 does not look like a CHIP device. [1708085368.882772][1937:1938] CHIP:BLE: Device 38:88:E3:A2:49:FD does not look like a CHIP device. [1708085368.905122][1937:1938] CHIP:BLE: Device 2D:1D:2F:94:7E:BF does not look like a CHIP device. [1708085368.929015][1937:1938] CHIP:BLE: Device 69:A5:8D:1A:11:BF does not look like a CHIP device. [1708085368.931968][1937:1938] CHIP:BLE: Device 30:46:32:3C:3E:A6 does not look like a CHIP device. [1708085368.936865][1937:1938] CHIP:BLE: Device 72:1C:78:D6:C2:EF does not look like a CHIP device. [1708085368.944172][1937:1938] CHIP:BLE: Device 05:1D:36:3D:69:06 does not look like a CHIP device. [1708085368.947553][1937:1938] CHIP:BLE: Device 12:38:E8:FE:B2:5D does not look like a CHIP device. [1708085368.977147][1937:1938] CHIP:BLE: Device 2F:90:2D:42:BC:30 does not look like a CHIP device. [1708085369.005696][1937:1938] CHIP:BLE: Device B4:9A:95:77:96:1B does not look like a CHIP device. [1708085369.007124][1937:1938] CHIP:BLE: Device 5F:CD:E9:A6:D9:65 does not look like a CHIP device. [1708085369.017038][1937:1938] CHIP:BLE: Device 19:A6:57:3F:36:40 does not look like a CHIP device. [1708085369.028608][1937:1938] CHIP:BLE: Device 53:A8:00:B8:4A:E3 does not look like a CHIP device. [1708085369.042257][1937:1938] CHIP:BLE: Device 19:D7:04:92:AC:7A does not look like a CHIP device. [1708085369.117669][1937:1938] CHIP:BLE: Device 42:5C:9D:B8:E0:16 does not look like a CHIP device. [1708085369.118211][1937:1938] CHIP:BLE: Device 37:82:12:92:B2:98 does not look like a CHIP device. [1708085369.121069][1937:1938] CHIP:BLE: Device D1:B6:D0:42:7A:C7 does not look like a CHIP device. [1708085369.132353][1937:1938] CHIP:BLE: Device 22:B0:2A:35:1C:4A does not look like a CHIP device. [1708085369.138926][1937:1938] CHIP:BLE: Device 15:66:56:ED:9B:44 does not look like a CHIP device. [1708085369.150259][1937:1938] CHIP:BLE: Device 2E:E3:A6:C4:9C:02 does not look like a CHIP device. [1708085369.173924][1937:1938] CHIP:BLE: Device 4B:20:3E:66:F4:79 does not look like a CHIP device. [1708085369.195907][1937:1938] CHIP:BLE: Device 1B:B1:6A:1E:48:29 does not look like a CHIP device. [1708085369.204896][1937:1938] CHIP:BLE: Device 07:A6:F0:78:C9:41 does not look like a CHIP device. [1708085369.223820][1937:1938] CHIP:BLE: Device 7C:32:4B:AE:19:A1 does not look like a CHIP device. [1708085369.224193][1937:1938] CHIP:BLE: Device 04:69:72:B6:FD:43 does not look like a CHIP device. [1708085369.225856][1937:1938] CHIP:BLE: Device 1A:74:8F:36:29:13 does not look like a CHIP device. [1708085369.227658][1937:1938] CHIP:BLE: Device 39:07:09:38:A4:54 does not look like a CHIP device. [1708085369.261147][1937:1938] CHIP:BLE: Device 11:5F:5B:E8:E0:33 does not look like a CHIP device. [1708085369.265009][1937:1938] CHIP:BLE: Device 00:9B:FF:A3:EC:10 does not look like a CHIP device. [1708085369.274671][1937:1938] CHIP:BLE: Device 5A:DF:F1:15:F2:FF does not look like a CHIP device. [1708085369.283369][1937:1938] CHIP:BLE: Device 6D:A2:1E:F6:F2:20 does not look like a CHIP device. [1708085369.285681][1937:1938] CHIP:BLE: Device 2D:22:DB:8F:23:0D does not look like a CHIP device. [1708085369.300667][1937:1938] CHIP:BLE: Device 3C:1B:58:DE:4D:94 does not look like a CHIP device. [1708085369.311549][1937:1938] CHIP:BLE: Device 14:0F:41:1D:6E:B9 does not look like a CHIP device. [1708085369.313105][1937:1938] CHIP:BLE: Device 19:93:DA:38:4F:03 does not look like a CHIP device. [1708085369.326316][1937:1938] CHIP:BLE: Device 14:2B:20:79:35:12 does not look like a CHIP device. [1708085369.332185][1937:1938] CHIP:BLE: Device 2D:1D:2F:94:7E:BF does not look like a CHIP device. [1708085369.335766][1937:1938] CHIP:BLE: Device 53:A8:00:B8:4A:E3 does not look like a CHIP device. [1708085369.339541][1937:1938] CHIP:BLE: Device 30:46:32:3C:3E:A6 does not look like a CHIP device. [1708085369.346029][1937:1938] CHIP:BLE: Device 1A:AF:42:26:D8:75 does not look like a CHIP device. [1708085369.360355][1937:1938] CHIP:BLE: Device 3A:6A:E7:A7:A9:14 does not look like a CHIP device. [1708085369.406385][1937:1938] CHIP:BLE: Device 7F:AF:97:2A:3E:90 does not look like a CHIP device. [1708085369.406807][1937:1938] CHIP:BLE: Device 38:88:E3:A2:49:FD does not look like a CHIP device. [1708085369.431705][1937:1938] CHIP:BLE: Device 40:18:25:98:27:E3 does not look like a CHIP device. [1708085369.437936][1937:1938] CHIP:BLE: Device 15:E1:37:08:60:2D does not look like a CHIP device. [1708085369.489223][1937:1938] CHIP:BLE: Device 69:A5:8D:1A:11:BF does not look like a CHIP device. [1708085369.499170][1937:1938] CHIP:BLE: Device 68:27:37:08:85:43 does not look like a CHIP device. [1708085369.504233][1937:1938] CHIP:BLE: Device 15:3F:39:F3:69:DA does not look like a CHIP device. [1708085369.520553][1937:1938] CHIP:BLE: Device 5F:CD:E9:A6:D9:65 does not look like a CHIP device. [1708085369.522397][1937:1938] CHIP:BLE: Device 14:13:09:CB:2E:C5 does not look like a CHIP device. [1708085369.536705][1937:1938] CHIP:BLE: Device 37:82:12:92:B2:98 does not look like a CHIP device. [1708085369.545887][1937:1938] CHIP:BLE: Device 3D:77:D9:57:6B:6D does not look like a CHIP device. [1708085369.589200][1937:1938] CHIP:BLE: Device 42:08:1F:CE:42:8D does not look like a CHIP device. [1708085369.592353][1937:1938] CHIP:BLE: Device 28:DE:65:62:6A:56 does not look like a CHIP device. [1708085369.592828][1937:1938] CHIP:BLE: Device 78:CC:30:DE:11:6D does not look like a CHIP device. [1708085369.604751][1937:1938] CHIP:BLE: Device 0D:4A:37:0D:C9:8F does not look like a CHIP device. [1708085369.609308][1937:1938] CHIP:BLE: Device B4:9A:95:77:96:1B does not look like a CHIP device. [1708085369.610777][1937:1938] CHIP:BLE: Device 15:29:80:16:1F:61 does not look like a CHIP device. [1708085369.618127][1937:1938] CHIP:BLE: Device 07:A6:F0:78:C9:41 does not look like a CHIP device. [1708085369.628167][1937:1938] CHIP:BLE: Device 42:5C:9D:B8:E0:16 does not look like a CHIP device. [1708085369.651712][1937:1938] CHIP:BLE: Device 04:69:72:B6:FD:43 does not look like a CHIP device. [1708085369.659758][1937:1938] CHIP:BLE: Device 22:B0:2A:35:1C:4A does not look like a CHIP device. [1708085369.664270][1937:1938] CHIP:BLE: Device 15:66:56:ED:9B:44 does not look like a CHIP device. [1708085369.666698][1937:1938] CHIP:BLE: Device 19:D7:04:92:AC:7A does not look like a CHIP device. [1708085369.668327][1937:1938] CHIP:BLE: Device 11:5F:5B:E8:E0:33 does not look like a CHIP device. [1708085369.678419][1937:1938] CHIP:BLE: Device 3F:E8:37:74:B0:11 does not look like a CHIP device. [1708085369.688178][1937:1938] CHIP:BLE: Device 25:C7:9B:A9:09:EA does not look like a CHIP device. [1708085369.694988][1937:1938] CHIP:BLE: Device 12:38:E8:FE:B2:5D does not look like a CHIP device. [1708085369.714607][1937:1938] CHIP:BLE: Device 2D:22:DB:8F:23:0D does not look like a CHIP device. [1708085369.723368][1937:1938] CHIP:BLE: Device 1B:B1:6A:1E:48:29 does not look like a CHIP device. [1708085369.732319][1937:1938] CHIP:BLE: Device 19:93:DA:38:4F:03 does not look like a CHIP device. [1708085369.747085][1937:1938] CHIP:BLE: Device 09:48:FC:E5:0F:00 does not look like a CHIP device. [1708085369.751720][1937:1938] CHIP:BLE: Device 7C:32:4B:AE:19:A1 does not look like a CHIP device. [1708085369.775476][1937:1938] CHIP:BLE: Device 3A:6A:E7:A7:A9:14 does not look like a CHIP device. [1708085369.789668][1937:1938] CHIP:BLE: Device 00:9B:FF:A3:EC:10 does not look like a CHIP device. [1708085369.795944][1937:1938] CHIP:BLE: Device FA:ED:AD:52:21:B2 does not look like a CHIP device. [1708085369.855390][1937:1938] CHIP:BLE: Device 19:A6:57:3F:36:40 does not look like a CHIP device. [1708085369.862634][1937:1938] CHIP:BLE: Device 1A:74:8F:36:29:13 does not look like a CHIP device. [1708085369.867442][1937:1938] CHIP:BLE: Device 30:46:32:3C:3E:A6 does not look like a CHIP device. [1708085369.918927][1937:1938] CHIP:BLE: Device AE:50:DE:4C:31:D6 does not look like a CHIP device. [1708085369.919317][1937:1938] CHIP:BLE: Device 6D:A2:1E:F6:F2:20 does not look like a CHIP device. [1708085369.931069][1937:1938] CHIP:BLE: Device 5F:CD:E9:A6:D9:65 does not look like a CHIP device. [1708085369.945065][1937:1938] CHIP:BLE: Device 9C:0C:35:62:13:B8 does not look like a CHIP device. [1708085369.961292][1937:1938] CHIP:BLE: Device 15:E1:37:08:60:2D does not look like a CHIP device. [1708085369.973044][1937:1938] CHIP:BLE: Device 53:A8:00:B8:4A:E3 does not look like a CHIP device. [1708085369.973390][1937:1938] CHIP:BLE: Device 1A:AF:42:26:D8:75 does not look like a CHIP device. [1708085370.025138][1937:1938] CHIP:BLE: Device 40:18:25:98:27:E3 does not look like a CHIP device. [1708085370.027834][1937:1938] CHIP:BLE: Device 4B:D3:B3:9A:06:33 does not look like a CHIP device. [1708085370.028262][1937:1938] CHIP:BLE: Device 38:88:E3:A2:49:FD does not look like a CHIP device. [1708085370.028647][1937:1938] CHIP:BLE: Device 27:4C:13:C5:21:D3 does not look like a CHIP device. [1708085370.042550][1937:1938] CHIP:BLE: Device 37:82:12:92:B2:98 does not look like a CHIP device. [1708085370.066576][1937:1938] CHIP:BLE: Device 54:2E:70:D6:60:0B does not look like a CHIP device. [1708085370.067016][1937:1938] CHIP:BLE: Device 1C:10:D5:EC:62:82 does not look like a CHIP device. [1708085370.072678][1937:1938] CHIP:BLE: Device 69:A5:8D:1A:11:BF does not look like a CHIP device. [1708085370.073181][1937:1938] CHIP:BLE: Device 2D:1D:2F:94:7E:BF does not look like a CHIP device. [1708085370.095909][1937:1938] CHIP:BLE: Device 05:1D:36:3D:69:06 does not look like a CHIP device. [1708085370.116364][1937:1938] CHIP:BLE: Device 5A:DF:F1:15:F2:FF does not look like a CHIP device. [1708085370.125446][1937:1938] CHIP:BLE: Device 02:3D:69:33:ED:C4 does not look like a CHIP device. [1708085370.133832][1937:1938] CHIP:BLE: Device 0D:4A:37:0D:C9:8F does not look like a CHIP device. [1708085370.137922][1937:1938] CHIP:BLE: Device 15:3F:39:F3:69:DA does not look like a CHIP device. [1708085370.158135][1937:1938] CHIP:BLE: Device 4B:20:3E:66:F4:79 does not look like a CHIP device. [1708085370.172896][1937:1938] CHIP:BLE: Device 39:07:09:38:A4:54 does not look like a CHIP device. [1708085370.179693][1937:1938] CHIP:BLE: Device 22:B0:2A:35:1C:4A does not look like a CHIP device. [1708085370.187279][1937:1938] CHIP:BLE: Device 15:66:56:ED:9B:44 does not look like a CHIP device. [1708085370.194610][1937:1938] CHIP:BLE: Device 19:D7:04:92:AC:7A does not look like a CHIP device. [1708085370.195988][1937:1938] CHIP:BLE: Device 3F:E8:37:74:B0:11 does not look like a CHIP device. [1708085370.202129][1937:1938] CHIP:BLE: Device B4:9A:95:77:96:1B does not look like a CHIP device. [1708085370.208098][1937:1938] CHIP:BLE: Device 00:9B:FF:A3:EC:10 does not look like a CHIP device. [1708085370.210399][1937:1938] CHIP:BLE: Device 3A:6A:E7:A7:A9:14 does not look like a CHIP device. [1708085370.217334][1937:1938] CHIP:BLE: Device 25:C7:9B:A9:09:EA does not look like a CHIP device. [1708085370.228378][1937:1938] CHIP:BLE: New device scanned: 88:B1:11:E3:F8:E5 [1708085370.228469][1937:1938] CHIP:BLE: Device discriminator match. Attempting to connect. [1708085370.233363][1937:1938] CHIP:BLE: ChipDeviceScanner has stopped scanning! [1708085370.375914][1937:1938] CHIP:DL: FAIL: ConnectDevice: GDBus.Error:org.freedesktop.DBus.Error.UnknownObject: Method "Connect" with signature "" on interface "org.bluez.Device1" doesn't exist (41) [1708085370.376128][1937:1938] CHIP:BLE: Device connection failed: src/platform/Linux/bluez/BluezEndpoint.cpp:749: CHIP Error 0x000000AC: Internal error [1708085370.376245][1937:1939] CHIP:DL: HandlePlatformSpecificBLEEvent 16386 [1708085370.376316][1937:1939] CHIP:DIS: Closing all BLE connections [1708085370.376425][1937:1939] CHIP:TOO: Pairing Failure: src/platform/Linux/bluez/BluezEndpoint.cpp:748: CHIP Error 0x000000AC: Internal error [1708085370.377280][1937:1937] CHIP:CTL: Shutting down the commissioner [1708085370.377499][1937:1937] CHIP:CTL: Shutting down the controller [1708085370.377608][1937:1937] CHIP:IN: Expiring all sessions for fabric 0x1!! [1708085370.377664][1937:1937] CHIP:FP: Forgetting fabric 0x1 [1708085370.377820][1937:1937] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48 [1708085370.378144][1937:1937] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48 [1708085370.378303][1937:1937] CHIP:TS: Reverted Last Known Good Time to previous value [1708085370.378463][1937:1937] CHIP:CTL: Shutting down the commissioner [1708085370.378658][1937:1937] CHIP:CTL: Shutting down the controller [1708085370.378716][1937:1937] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1708085370.379028][1937:1937] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1708085370.379481][1937:1937] CHIP:FP: Shutting down FabricTable [1708085370.379686][1937:1937] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48 [1708085370.380120][1937:1937] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48 [1708085370.380274][1937:1937] CHIP:TS: Reverted Last Known Good Time to previous value [1708085370.381366][1937:1937] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-i4qBwW) [1708085370.382752][1937:1937] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085370.382909][1937:1937] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1708085370.383055][1937:1937] CHIP:DL: Inet Layer shutdown [1708085370.383110][1937:1937] CHIP:DL: BLE shutdown [1708085370.408014][1937:1937] CHIP:DL: System Layer shutdown [1708085370.410239][1937:1937] CHIP:TOO: Run command failure: src/platform/Linux/bluez/BluezEndpoint.cpp:748: CHIP Error 0x000000AC: Internal error ubuntu@ubuntu:~/master_cntrl/connectedhomeip/out/chip-tool$ sudo rm -rf /tmp/chip_* ubuntu@ubuntu:~/master_cntrl/connectedhomeip/out/chip-tool$ ./chip-tool pairing ble-wifi 1 GRLPrivate grlprivatewifi092010 20202021 3840 [1708085378.812271][1945:1945] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs [1708085378.812712][1945:1945] CHIP:DL: writing settings to file (/tmp/chip_tool_kvs-Gcord3) [1708085378.813081][1945:1945] CHIP:DL: renamed tmp file to file (/tmp/chip_tool_kvs) [1708085378.815103][1945:1945] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1708085378.815188][1945:1945] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs [1708085378.830181][1945:1945] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1708085378.830695][1945:1945] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-bAygis) [1708085378.831246][1945:1945] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085378.831615][1945:1945] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1708085378.831984][1945:1945] CHIP:DL: writing settings to file (/tmp/chip_config.ini-Cm5FGl) [1708085378.832380][1945:1945] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085378.832671][1945:1945] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1708085378.833065][1945:1945] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-4RjUE5) [1708085378.833451][1945:1945] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085378.834289][1945:1945] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-gmwtmR) [1708085378.835402][1945:1945] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085378.835527][1945:1945] CHIP:DL: NVS set: chip-factory/unique-id = "4C8595302CB7374B" [1708085378.835826][1945:1945] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-OTJb9c) [1708085378.837221][1945:1945] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085378.837347][1945:1945] CHIP:DL: NVS set: chip-factory/vendor-id = 65521 (0xFFF1) [1708085378.837646][1945:1945] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-HyVA6A) [1708085378.838846][1945:1945] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085378.838973][1945:1945] CHIP:DL: NVS set: chip-factory/product-id = 32769 (0x8001) [1708085378.839260][1945:1945] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-BPjuqu) [1708085378.840262][1945:1945] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085378.840388][1945:1945] CHIP:DL: NVS set: chip-counters/reboot-count = 1 (0x1) [1708085378.840698][1945:1945] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-1IoxSI) [1708085378.841865][1945:1945] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085378.841989][1945:1945] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1708085378.842289][1945:1945] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-xD2FD0) [1708085378.843386][1945:1945] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085378.843507][1945:1945] CHIP:DL: NVS set: chip-counters/boot-reason = 0 (0x0) [1708085378.843783][1945:1945] CHIP:DL: writing settings to file (/tmp/chip_config.ini-6iJKad) [1708085378.844763][1945:1945] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085378.844882][1945:1945] CHIP:DL: NVS set: chip-config/regulatory-location = 0 (0x0) [1708085378.845172][1945:1945] CHIP:DL: writing settings to file (/tmp/chip_config.ini-L7T19W) [1708085378.846302][1945:1945] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085378.846423][1945:1945] CHIP:DL: NVS set: chip-config/location-capability = 2 (0x2) [1708085378.848117][1945:1945] CHIP:DL: Got Ethernet interface: eth0 [1708085378.849410][1945:1945] CHIP:DL: Found the primary Ethernet interface:eth0 [1708085378.850808][1945:1945] CHIP:DL: Got WiFi interface: wlan0 [1708085378.850991][1945:1945] CHIP:DL: Failed to reset WiFi statistic counts [1708085378.851105][1945:1945] CHIP:IN: UDP::Init bind&listen port=0 [1708085378.851365][1945:1945] CHIP:IN: UDP::Init bound to port=55541 [1708085378.851423][1945:1945] CHIP:IN: BLEBase::Init - setting/overriding transport [1708085378.851549][1945:1945] CHIP:IN: TransportMgr initialized [1708085378.851725][1945:1945] CHIP:FP: Initializing FabricTable from persistent storage [1708085378.851869][1945:1945] CHIP:TS: Last Known Good Time: [unknown] [1708085378.851937][1945:1945] CHIP:TS: Setting Last Known Good Time to firmware build time 2023-10-14T01:16:48 [1708085378.856227][1945:1945] CHIP:ZCL: Using ZAP configuration... [1708085378.866149][1945:1945] CHIP:DL: Avahi client registered [1708085378.866396][1945:1945] CHIP:CTL: System State Initialized... [1708085378.866804][1945:1945] CHIP:CTL: Setting attestation nonce to random value [1708085378.866906][1945:1945] CHIP:CTL: Setting CSR nonce to random value [1708085378.867101][1945:1945] CHIP:IN: UDP::Init bind&listen port=5550 [1708085378.867404][1945:1945] CHIP:IN: UDP::Init bound to port=5550 [1708085378.867483][1945:1945] CHIP:IN: TransportMgr initialized [1708085378.869653][1945:1947] CHIP:DL: CHIP task running [1708085378.870116][1945:1947] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1708085378.871309][1945:1947] CHIP:CTL: Setting attestation nonce to random value [1708085378.871713][1945:1947] CHIP:CTL: Setting CSR nonce to random value [1708085378.872027][1945:1947] CHIP:CTL: Couldn't get ExampleOpCredsCAKey from storage: src/controller/ExamplePersistentStorage.cpp:106: CHIP Error 0x000000A0: Value not found in the persisted storage [1708085378.874388][1945:1947] CHIP:CTL: Couldn't get ExampleOpCredsICAKey from storage: src/controller/ExamplePersistentStorage.cpp:106: CHIP Error 0x000000A0: Value not found in the persisted storage [1708085378.877075][1945:1947] CHIP:CTL: Generating RCAC [1708085378.880803][1945:1947] CHIP:CTL: Generating ICAC [1708085378.883251][1945:1947] CHIP:CTL: Generating NOC [1708085378.885045][1945:1947] CHIP:FP: Validating NOC chain [1708085378.891242][1945:1947] CHIP:FP: NOC chain validation successful [1708085378.891687][1945:1947] CHIP:FP: Added new fabric at index: 0x1 [1708085378.891750][1945:1947] CHIP:FP: Assigned compressed fabric ID: 0x71888C16AF5A0550, node ID: 0x000000000001B669 [1708085378.891816][1945:1947] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48 [1708085378.891870][1945:1947] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1708085378.891920][1945:1947] CHIP:TS: Retaining current Last Known Good Time [1708085378.895589][1945:1947] CHIP:FP: Metadata for Fabric 0x1 persisted to storage. [1708085378.900629][1945:1947] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-14T01:16:48 [1708085378.905865][1945:1947] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 71888C16AF5A0550) [1708085378.905974][1945:1947] CHIP:IN: UDP::Init bind&listen port=5550 [1708085378.906226][1945:1947] CHIP:IN: UDP::Init bound to port=5550 [1708085378.906284][1945:1947] CHIP:IN: TransportMgr initialized [1708085378.976266][1945:1947] CHIP:CTL: Setting wifi credentials from parameters [1708085378.976358][1945:1947] CHIP:CTL: Setting attestation nonce to random value [1708085378.976451][1945:1947] CHIP:CTL: Setting CSR nonce to random value [1708085378.976540][1945:1947] CHIP:CTL: Checking ICD registration parameters [1708085378.976639][1945:1947] CHIP:CTL: Commission called for node ID 0x0000000000000001 [1708085378.976710][1945:1947] CHIP:DL: Long dispatch time: 106 ms, for event type 2 [1708085379.028882][1945:1947] CHIP:DL: BlueZ integration init success [1708085379.063941][1945:1946] CHIP:BLE: BLE removing known devices. [1708085379.068080][1945:1946] CHIP:BLE: BLE initiating scan. [1708085379.073175][1945:1947] CHIP:BLE: ChipDeviceScanner has started scanning! [1708085379.080401][1945:1946] CHIP:BLE: Device 04:69:72:B6:FD:43 does not look like a CHIP device. [1708085379.083036][1945:1946] CHIP:BLE: Device 40:18:25:98:27:E3 does not look like a CHIP device. [1708085379.086278][1945:1946] CHIP:BLE: Device 25:C7:9B:A9:09:EA does not look like a CHIP device. [1708085379.090011][1945:1946] CHIP:BLE: Device B4:9A:95:77:96:1B does not look like a CHIP device. [1708085379.090436][1945:1946] CHIP:BLE: Device 09:48:FC:E5:0F:00 does not look like a CHIP device. [1708085379.097799][1945:1946] CHIP:BLE: Device 05:1D:36:3D:69:06 does not look like a CHIP device. [1708085379.100675][1945:1946] CHIP:BLE: Device 14:2B:20:79:35:12 does not look like a CHIP device. [1708085379.103537][1945:1946] CHIP:BLE: Device 22:B0:2A:35:1C:4A does not look like a CHIP device. [1708085379.113397][1945:1946] CHIP:BLE: New device scanned: F5:4A:0A:FE:E9:32 [1708085379.113493][1945:1946] CHIP:BLE: Device discriminator match. Attempting to connect. [1708085379.118462][1945:1946] CHIP:BLE: ChipDeviceScanner has stopped scanning! [1708085379.235918][1945:1946] CHIP:DL: ConnectDevice complete [1708085379.236032][1945:1946] CHIP:BLE: New device connected: F5:4A:0A:FE:E9:32 [1708085380.297853][1945:1946] CHIP:DL: Char /org/bluez/hci0/dev_F5_4A_0A_FE_E9_32/service0001 on service /org/bluez/hci0/dev_F5_4A_0A_FE_E9_32/service000c [1708085380.297959][1945:1946] CHIP:DL: Char /org/bluez/hci0/dev_F5_4A_0A_FE_E9_32/service0001 on service /org/bluez/hci0/dev_F5_4A_0A_FE_E9_32/service000c [1708085380.298031][1945:1946] CHIP:DL: Char /org/bluez/hci0/dev_F5_4A_0A_FE_E9_32/service000c on service /org/bluez/hci0/dev_F5_4A_0A_FE_E9_32/service000c [1708085380.298099][1945:1946] CHIP:DL: Char /org/bluez/hci0/dev_F5_4A_0A_FE_E9_32/service000c on service /org/bluez/hci0/dev_F5_4A_0A_FE_E9_32/service000c [1708085380.298191][1945:1946] CHIP:DL: Char /org/bluez/hci0/dev_F5_4A_0A_FE_E9_32/service000c on service /org/bluez/hci0/dev_F5_4A_0A_FE_E9_32/service000c [1708085380.298303][1945:1946] CHIP:DL: New BLE connection: conn 0xffffb006ac60, device F5:4A:0A:FE:E9:32, path /org/bluez/hci0/dev_F5_4A_0A_FE_E9_32 [1708085380.298559][1945:1947] CHIP:DL: HandlePlatformSpecificBLEEvent 16385 [1708085380.298640][1945:1947] CHIP:DIS: Closing all BLE connections [1708085380.298757][1945:1947] CHIP:IN: BleConnectionComplete: endPoint 0xaaaac4ab6358 [1708085380.299789][1945:1947] CHIP:IN: SecureSession[0xffffa8037cf0]: Allocated Type:1 LSID:24902 [1708085380.299896][1945:1947] CHIP:SC: Assigned local session key ID 24902 [1708085380.300171][1945:1947] CHIP:EM: <<< [E:16303i S:0 M:143506692] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:20 (SecureChannel:PBKDFParamRequest) [1708085380.300287][1945:1947] CHIP:IN: Message appended to BLE send queue [1708085380.300352][1945:1947] CHIP:SC: Sent PBKDF param request [1708085380.650859][1945:1947] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1708085380.741490][1945:1947] CHIP:DL: HandlePlatformSpecificBLEEvent 16388 [1708085380.741587][1945:1947] CHIP:BLE: subscribe complete, ep = 0xaaaac4ab6358 [1708085380.742040][1945:1946] CHIP:DL: Indication received, conn = 0xffffb006ac60 [1708085380.742270][1945:1947] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1708085380.742345][1945:1947] CHIP:BLE: peripheral chose BTP version 4; central expected between 4 and 4 [1708085380.742480][1945:1947] CHIP:BLE: using BTP fragment sizes rx 244 / tx 244. [1708085380.742542][1945:1947] CHIP:BLE: local and remote recv window size = 5 [1708085380.743369][1945:1947] CHIP:IN: BLE EndPoint 0xaaaac4ab6358 Connection Complete [1708085380.830578][1945:1947] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1708085380.877892][1945:1946] CHIP:DL: Indication received, conn = 0xffffb006ac60 [1708085380.878155][1945:1947] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1708085380.878394][1945:1947] CHIP:EM: >>> [E:16303i S:0 M:128729460] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:21 (SecureChannel:PBKDFParamResponse) [1708085380.878476][1945:1947] CHIP:EM: Found matching exchange: 16303i, Delegate: 0xffffa8036d60 [1708085380.878574][1945:1947] CHIP:SC: Received PBKDF param response [1708085380.878674][1945:1947] CHIP:SC: Peer assigned session ID 56913 [1708085380.878749][1945:1947] CHIP:SC: Found MRP parameters in the message [1708085380.895449][1945:1947] CHIP:EM: <<< [E:16303i S:0 M:143506693] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:22 (SecureChannel:PASE_Pake1) [1708085380.896457][1945:1947] CHIP:SC: Sent spake2p msg1 [1708085380.965702][1945:1947] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1708085382.722555][1945:1946] CHIP:DL: Indication received, conn = 0xffffb006ac60 [1708085382.722837][1945:1947] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1708085382.723070][1945:1947] CHIP:EM: >>> [E:16303i S:0 M:128729461] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:23 (SecureChannel:PASE_Pake2) [1708085382.723151][1945:1947] CHIP:EM: Found matching exchange: 16303i, Delegate: 0xffffa8036d60 [1708085382.723246][1945:1947] CHIP:SC: Received spake2p msg2 [1708085382.726878][1945:1947] CHIP:EM: <<< [E:16303i S:0 M:143506694] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:24 (SecureChannel:PASE_Pake3) [1708085382.727710][1945:1947] CHIP:SC: Sent spake2p msg3 [1708085383.125904][1945:1947] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1708085388.707012][1945:1946] CHIP:DL: Bluez disconnected [1708085388.707103][1945:1946] CHIP:DL: Bluez notify CHIPoBluez connection disconnected [1708085388.707344][1945:1947] CHIP:IN: Clearing BLE pending packets. ^C ubuntu@ubuntu:~/master_cntrl/connectedhomeip/out/chip-tool$ sudo rm -rf /tmp/chip_* ubuntu@ubuntu:~/master_cntrl/connectedhomeip/out/chip-tool$ ./chip-tool pairing ble-wifi 1 GRLPrivate grlprivatewifi092010 20202021 3840 [1708085410.931570][1961:1961] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs [1708085410.932062][1961:1961] CHIP:DL: writing settings to file (/tmp/chip_tool_kvs-9jQhKr) [1708085410.932446][1961:1961] CHIP:DL: renamed tmp file to file (/tmp/chip_tool_kvs) [1708085410.934428][1961:1961] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1708085410.934503][1961:1961] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs [1708085410.949252][1961:1961] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1708085410.949787][1961:1961] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-IaAyYc) [1708085410.950318][1961:1961] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085410.950660][1961:1961] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1708085410.951008][1961:1961] CHIP:DL: writing settings to file (/tmp/chip_config.ini-wscQbr) [1708085410.951427][1961:1961] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085410.951719][1961:1961] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1708085410.952034][1961:1961] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-4Qi6Yq) [1708085410.952463][1961:1961] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085410.953256][1961:1961] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-0IjeIt) [1708085410.954429][1961:1961] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085410.954557][1961:1961] CHIP:DL: NVS set: chip-factory/unique-id = "60A2632439126E5A" [1708085410.954855][1961:1961] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-BAoKbs) [1708085410.955981][1961:1961] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085410.956138][1961:1961] CHIP:DL: NVS set: chip-factory/vendor-id = 65521 (0xFFF1) [1708085410.956433][1961:1961] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-9q3za1) [1708085410.957547][1961:1961] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085410.957669][1961:1961] CHIP:DL: NVS set: chip-factory/product-id = 32769 (0x8001) [1708085410.958109][1961:1961] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-m2GV4y) [1708085410.959146][1961:1961] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085410.959270][1961:1961] CHIP:DL: NVS set: chip-counters/reboot-count = 1 (0x1) [1708085410.959564][1961:1961] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-czLTE9) [1708085410.960656][1961:1961] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085410.960778][1961:1961] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1708085410.961106][1961:1961] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-GEXgQe) [1708085410.962221][1961:1961] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085410.962343][1961:1961] CHIP:DL: NVS set: chip-counters/boot-reason = 0 (0x0) [1708085410.962621][1961:1961] CHIP:DL: writing settings to file (/tmp/chip_config.ini-ZHeSuF) [1708085410.963585][1961:1961] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085410.963705][1961:1961] CHIP:DL: NVS set: chip-config/regulatory-location = 0 (0x0) [1708085410.963992][1961:1961] CHIP:DL: writing settings to file (/tmp/chip_config.ini-Gq4CFn) [1708085410.965018][1961:1961] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085410.965136][1961:1961] CHIP:DL: NVS set: chip-config/location-capability = 2 (0x2) [1708085410.966899][1961:1961] CHIP:DL: Got Ethernet interface: eth0 [1708085410.968224][1961:1961] CHIP:DL: Found the primary Ethernet interface:eth0 [1708085410.969571][1961:1961] CHIP:DL: Got WiFi interface: wlan0 [1708085410.969778][1961:1961] CHIP:DL: Failed to reset WiFi statistic counts [1708085410.969894][1961:1961] CHIP:IN: UDP::Init bind&listen port=0 [1708085410.970165][1961:1961] CHIP:IN: UDP::Init bound to port=58854 [1708085410.970225][1961:1961] CHIP:IN: BLEBase::Init - setting/overriding transport [1708085410.970275][1961:1961] CHIP:IN: TransportMgr initialized [1708085410.970493][1961:1961] CHIP:FP: Initializing FabricTable from persistent storage [1708085410.970646][1961:1961] CHIP:TS: Last Known Good Time: [unknown] [1708085410.970716][1961:1961] CHIP:TS: Setting Last Known Good Time to firmware build time 2023-10-14T01:16:48 [1708085410.975062][1961:1961] CHIP:ZCL: Using ZAP configuration... [1708085410.984983][1961:1961] CHIP:DL: Avahi client registered [1708085410.985229][1961:1961] CHIP:CTL: System State Initialized... [1708085410.985642][1961:1961] CHIP:CTL: Setting attestation nonce to random value [1708085410.985798][1961:1961] CHIP:CTL: Setting CSR nonce to random value [1708085410.985975][1961:1961] CHIP:IN: UDP::Init bind&listen port=5550 [1708085410.986256][1961:1961] CHIP:IN: UDP::Init bound to port=5550 [1708085410.986317][1961:1961] CHIP:IN: TransportMgr initialized [1708085410.988529][1961:1963] CHIP:DL: CHIP task running [1708085410.988955][1961:1963] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1708085410.990107][1961:1963] CHIP:CTL: Setting attestation nonce to random value [1708085410.990529][1961:1963] CHIP:CTL: Setting CSR nonce to random value [1708085410.990883][1961:1963] CHIP:CTL: Couldn't get ExampleOpCredsCAKey from storage: src/controller/ExamplePersistentStorage.cpp:106: CHIP Error 0x000000A0: Value not found in the persisted storage [1708085410.993189][1961:1963] CHIP:CTL: Couldn't get ExampleOpCredsICAKey from storage: src/controller/ExamplePersistentStorage.cpp:106: CHIP Error 0x000000A0: Value not found in the persisted storage [1708085410.996065][1961:1963] CHIP:CTL: Generating RCAC [1708085410.999672][1961:1963] CHIP:CTL: Generating ICAC [1708085411.001881][1961:1963] CHIP:CTL: Generating NOC [1708085411.003588][1961:1963] CHIP:FP: Validating NOC chain [1708085411.009597][1961:1963] CHIP:FP: NOC chain validation successful [1708085411.010113][1961:1963] CHIP:FP: Added new fabric at index: 0x1 [1708085411.010211][1961:1963] CHIP:FP: Assigned compressed fabric ID: 0xC296A6854E0C5914, node ID: 0x000000000001B669 [1708085411.010281][1961:1963] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48 [1708085411.010336][1961:1963] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1708085411.010385][1961:1963] CHIP:TS: Retaining current Last Known Good Time [1708085411.014007][1961:1963] CHIP:FP: Metadata for Fabric 0x1 persisted to storage. [1708085411.018978][1961:1963] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-14T01:16:48 [1708085411.025826][1961:1963] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: C296A6854E0C5914) [1708085411.025936][1961:1963] CHIP:IN: UDP::Init bind&listen port=5550 [1708085411.026189][1961:1963] CHIP:IN: UDP::Init bound to port=5550 [1708085411.026250][1961:1963] CHIP:IN: TransportMgr initialized [1708085411.093876][1961:1963] CHIP:CTL: Setting wifi credentials from parameters [1708085411.093971][1961:1963] CHIP:CTL: Setting attestation nonce to random value [1708085411.094070][1961:1963] CHIP:CTL: Setting CSR nonce to random value [1708085411.094159][1961:1963] CHIP:CTL: Checking ICD registration parameters [1708085411.094259][1961:1963] CHIP:CTL: Commission called for node ID 0x0000000000000001 [1708085411.094330][1961:1963] CHIP:DL: Long dispatch time: 105 ms, for event type 2 [1708085411.133815][1961:1963] CHIP:DL: BlueZ integration init success [1708085411.157253][1961:1962] CHIP:BLE: BLE removing known devices. [1708085411.215882][1961:1962] CHIP:BLE: BLE initiating scan. [1708085411.221078][1961:1963] CHIP:BLE: ChipDeviceScanner has started scanning! [1708085411.221192][1961:1963] CHIP:DL: Long dispatch time: 127 ms, for event type 3 [1708085411.231722][1961:1962] CHIP:BLE: Device 1E:35:2D:85:9D:C1 does not look like a CHIP device. [1708085411.234959][1961:1962] CHIP:BLE: Device 15:3F:39:F3:69:DA does not look like a CHIP device. [1708085411.238968][1961:1962] CHIP:BLE: Device 30:46:32:3C:3E:A6 does not look like a CHIP device. [1708085411.242189][1961:1962] CHIP:BLE: Device 0F:B4:3E:D7:08:0C does not look like a CHIP device. [1708085411.244993][1961:1962] CHIP:BLE: Device 2D:22:DB:8F:23:0D does not look like a CHIP device. [1708085411.251437][1961:1962] CHIP:BLE: Device 09:48:FC:E5:0F:00 does not look like a CHIP device. [1708085411.254254][1961:1962] CHIP:BLE: Device 3F:E8:37:74:B0:11 does not look like a CHIP device. [1708085411.262667][1961:1962] CHIP:BLE: Device 43:39:EF:17:15:3D does not look like a CHIP device. [1708085411.270955][1961:1962] CHIP:BLE: Device 27:4C:13:C5:21:D3 does not look like a CHIP device. [1708085411.275496][1961:1962] CHIP:BLE: Device 00:9B:FF:A3:EC:10 does not look like a CHIP device. [1708085411.287822][1961:1962] CHIP:BLE: Device AE:50:DE:4C:31:D6 does not look like a CHIP device. [1708085411.290918][1961:1962] CHIP:BLE: Device 0B:61:01:A2:09:16 does not look like a CHIP device. [1708085411.294856][1961:1962] CHIP:BLE: Device 1A:AF:42:26:D8:75 does not look like a CHIP device. [1708085411.297855][1961:1962] CHIP:BLE: Device 19:93:DA:38:4F:03 does not look like a CHIP device. [1708085411.300738][1961:1962] CHIP:BLE: Device 1B:B1:6A:1E:48:29 does not look like a CHIP device. [1708085411.307120][1961:1962] CHIP:BLE: Device 37:82:12:92:B2:98 does not look like a CHIP device. [1708085411.318257][1961:1962] CHIP:BLE: Device 3D:77:D9:57:6B:6D does not look like a CHIP device. [1708085411.321026][1961:1962] CHIP:BLE: Device 2D:1D:2F:94:7E:BF does not look like a CHIP device. [1708085411.326863][1961:1962] CHIP:BLE: Device 25:C7:9B:A9:09:EA does not look like a CHIP device. [1708085411.333028][1961:1962] CHIP:BLE: Device 19:D7:04:92:AC:7A does not look like a CHIP device. [1708085411.341434][1961:1962] CHIP:BLE: Device 07:A6:F0:78:C9:41 does not look like a CHIP device. [1708085411.351704][1961:1962] CHIP:BLE: Device 19:A6:57:3F:36:40 does not look like a CHIP device. [1708085411.364789][1961:1962] CHIP:BLE: Device 11:5F:5B:E8:E0:33 does not look like a CHIP device. [1708085411.368141][1961:1962] CHIP:BLE: Device B4:9A:95:77:96:1B does not look like a CHIP device. [1708085411.375980][1961:1962] CHIP:BLE: Device 7C:75:58:04:9E:60 does not look like a CHIP device. [1708085411.378827][1961:1962] CHIP:BLE: Device 12:38:E8:FE:B2:5D does not look like a CHIP device. [1708085411.385876][1961:1962] CHIP:BLE: Device 23:B1:C0:0F:56:67 does not look like a CHIP device. [1708085411.398665][1961:1962] CHIP:BLE: Device 3A:6A:E7:A7:A9:14 does not look like a CHIP device. [1708085411.409234][1961:1962] CHIP:BLE: Device 5F:CD:E9:A6:D9:65 does not look like a CHIP device. [1708085411.414822][1961:1962] CHIP:BLE: Device 5A:DF:F1:15:F2:FF does not look like a CHIP device. [1708085411.424928][1961:1962] CHIP:BLE: Device 68:27:37:08:85:43 does not look like a CHIP device. [1708085411.477051][1961:1962] CHIP:BLE: Device FB:02:E8:67:D0:F5 does not look like a CHIP device. [1708085411.480394][1961:1962] CHIP:BLE: Device 2B:96:63:A5:A4:0F does not look like a CHIP device. [1708085411.483341][1961:1962] CHIP:BLE: Device 15:66:56:ED:9B:44 does not look like a CHIP device. [1708085411.492130][1961:1962] CHIP:BLE: Device 14:2B:20:79:35:12 does not look like a CHIP device. [1708085411.506333][1961:1962] CHIP:BLE: Device 53:A8:00:B8:4A:E3 does not look like a CHIP device. [1708085411.537404][1961:1962] CHIP:BLE: Device 22:B0:2A:35:1C:4A does not look like a CHIP device. [1708085411.541253][1961:1962] CHIP:BLE: Device 0D:4A:37:0D:C9:8F does not look like a CHIP device. [1708085411.549078][1961:1962] CHIP:BLE: Device 38:88:E3:A2:49:FD does not look like a CHIP device. [1708085411.555387][1961:1962] CHIP:BLE: Device 02:02:4C:FC:DB:50 does not look like a CHIP device. [1708085411.555826][1961:1962] CHIP:BLE: Device 30:46:32:3C:3E:A6 does not look like a CHIP device. [1708085411.560488][1961:1962] CHIP:BLE: Device 3F:E8:37:74:B0:11 does not look like a CHIP device. [1708085411.591947][1961:1962] CHIP:BLE: Device 27:4C:13:C5:21:D3 does not look like a CHIP device. [1708085411.597187][1961:1962] CHIP:BLE: Device 2E:E3:A6:C4:9C:02 does not look like a CHIP device. [1708085411.619352][1961:1962] CHIP:BLE: Device 09:48:FC:E5:0F:00 does not look like a CHIP device. [1708085411.657496][1961:1962] CHIP:BLE: Device 69:A5:8D:1A:11:BF does not look like a CHIP device. [1708085411.657931][1961:1962] CHIP:BLE: Device 0F:B4:3E:D7:08:0C does not look like a CHIP device. [1708085411.658262][1961:1962] CHIP:BLE: Device 2D:22:DB:8F:23:0D does not look like a CHIP device. [1708085411.666174][1961:1962] CHIP:BLE: Device 15:E1:37:08:60:2D does not look like a CHIP device. [1708085411.688786][1961:1962] CHIP:BLE: Device 90:F1:57:25:11:BA does not look like a CHIP device. [1708085411.692028][1961:1962] CHIP:BLE: Device 42:08:1F:CE:42:8D does not look like a CHIP device. [1708085411.694950][1961:1962] CHIP:BLE: Device 78:CC:30:DE:11:6D does not look like a CHIP device. [1708085411.695575][1961:1962] CHIP:BLE: Device AE:50:DE:4C:31:D6 does not look like a CHIP device. [1708085411.710456][1961:1962] CHIP:BLE: Device 37:82:12:92:B2:98 does not look like a CHIP device. [1708085411.715472][1961:1962] CHIP:BLE: Device 1A:AF:42:26:D8:75 does not look like a CHIP device. [1708085411.720022][1961:1962] CHIP:BLE: Device 19:93:DA:38:4F:03 does not look like a CHIP device. [1708085411.722386][1961:1962] CHIP:BLE: Device 1B:B1:6A:1E:48:29 does not look like a CHIP device. [1708085411.737911][1961:1962] CHIP:BLE: Device 2D:1D:2F:94:7E:BF does not look like a CHIP device. [1708085411.743393][1961:1962] CHIP:BLE: Device 14:0F:41:1D:6E:B9 does not look like a CHIP device. [1708085411.746955][1961:1962] CHIP:BLE: Device 19:D7:04:92:AC:7A does not look like a CHIP device. [1708085411.759957][1961:1962] CHIP:BLE: Device 11:5F:5B:E8:E0:33 does not look like a CHIP device. [1708085411.768606][1961:1962] CHIP:BLE: Device B4:9A:95:77:96:1B does not look like a CHIP device. [1708085411.798907][1961:1962] CHIP:BLE: Device 00:9B:FF:A3:EC:10 does not look like a CHIP device. [1708085411.801480][1961:1962] CHIP:BLE: Device 0B:61:01:A2:09:16 does not look like a CHIP device. [1708085411.813049][1961:1962] CHIP:BLE: Device 3A:6A:E7:A7:A9:14 does not look like a CHIP device. [1708085411.819508][1961:1962] CHIP:BLE: Device 5F:CD:E9:A6:D9:65 does not look like a CHIP device. [1708085411.830334][1961:1962] CHIP:BLE: New device scanned: 88:B1:11:E3:F8:E5 [1708085411.830429][1961:1962] CHIP:BLE: Device discriminator match. Attempting to connect. [1708085411.836696][1961:1962] CHIP:BLE: ChipDeviceScanner has stopped scanning! [1708085411.882353][1961:1962] CHIP:DL: FAIL: ConnectDevice: GDBus.Error:org.freedesktop.DBus.Error.UnknownObject: Method "Connect" with signature "" on interface "org.bluez.Device1" doesn't exist (41) [1708085411.882568][1961:1962] CHIP:BLE: Device connection failed: src/platform/Linux/bluez/BluezEndpoint.cpp:749: CHIP Error 0x000000AC: Internal error [1708085411.882689][1961:1963] CHIP:DL: HandlePlatformSpecificBLEEvent 16386 [1708085411.882760][1961:1963] CHIP:DIS: Closing all BLE connections [1708085411.882860][1961:1963] CHIP:TOO: Pairing Failure: src/platform/Linux/bluez/BluezEndpoint.cpp:748: CHIP Error 0x000000AC: Internal error [1708085411.883618][1961:1961] CHIP:CTL: Shutting down the commissioner [1708085411.883847][1961:1961] CHIP:CTL: Shutting down the controller [1708085411.883957][1961:1961] CHIP:IN: Expiring all sessions for fabric 0x1!! [1708085411.884015][1961:1961] CHIP:FP: Forgetting fabric 0x1 [1708085411.884094][1961:1961] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48 [1708085411.884412][1961:1961] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48 [1708085411.884478][1961:1961] CHIP:TS: Reverted Last Known Good Time to previous value [1708085411.884569][1961:1961] CHIP:CTL: Shutting down the commissioner [1708085411.884745][1961:1961] CHIP:CTL: Shutting down the controller [1708085411.884802][1961:1961] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1708085411.885114][1961:1961] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1708085411.885335][1961:1961] CHIP:FP: Shutting down FabricTable [1708085411.885426][1961:1961] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48 [1708085411.885695][1961:1961] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48 [1708085411.885837][1961:1961] CHIP:TS: Reverted Last Known Good Time to previous value [1708085411.886439][1961:1961] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-O9jJc4) [1708085411.887892][1961:1961] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085411.888144][1961:1961] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1708085411.888213][1961:1961] CHIP:DL: Inet Layer shutdown [1708085411.888268][1961:1961] CHIP:DL: BLE shutdown [1708085411.906557][1961:1961] CHIP:DL: System Layer shutdown [1708085411.908385][1961:1961] CHIP:TOO: Run command failure: src/platform/Linux/bluez/BluezEndpoint.cpp:748: CHIP Error 0x000000AC: Internal error ubuntu@ubuntu:~/master_cntrl/connectedhomeip/out/chip-tool$ sudo rm -rf /tmp/chip_* ubuntu@ubuntu:~/master_cntrl/connectedhomeip/out/chip-tool$ ./chip-tool pairing ble-wifi 1 GRLPrivate grlprivatewifi092010 20202021 3840 [1708085423.620799][1969:1969] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs [1708085423.621244][1969:1969] CHIP:DL: writing settings to file (/tmp/chip_tool_kvs-Rp69FC) [1708085423.621616][1969:1969] CHIP:DL: renamed tmp file to file (/tmp/chip_tool_kvs) [1708085423.623597][1969:1969] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1708085423.623672][1969:1969] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs [1708085423.638551][1969:1969] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1708085423.639054][1969:1969] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-XZa7Pe) [1708085423.639723][1969:1969] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085423.639984][1969:1969] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1708085423.640265][1969:1969] CHIP:DL: writing settings to file (/tmp/chip_config.ini-Iwsz7m) [1708085423.640714][1969:1969] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085423.640995][1969:1969] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1708085423.641327][1969:1969] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-NgScIZ) [1708085423.641710][1969:1969] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085423.642609][1969:1969] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-0Cn29f) [1708085423.643724][1969:1969] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085423.643850][1969:1969] CHIP:DL: NVS set: chip-factory/unique-id = "0822C4622EB4C258" [1708085423.644147][1969:1969] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-p8JMMK) [1708085423.645349][1969:1969] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085423.645478][1969:1969] CHIP:DL: NVS set: chip-factory/vendor-id = 65521 (0xFFF1) [1708085423.645826][1969:1969] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-FdXTHy) [1708085423.646955][1969:1969] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085423.647076][1969:1969] CHIP:DL: NVS set: chip-factory/product-id = 32769 (0x8001) [1708085423.647364][1969:1969] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-T09l6w) [1708085423.648290][1969:1969] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085423.648409][1969:1969] CHIP:DL: NVS set: chip-counters/reboot-count = 1 (0x1) [1708085423.648704][1969:1969] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-IGkmL3) [1708085423.649865][1969:1969] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085423.649987][1969:1969] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1708085423.650276][1969:1969] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-SRAV7X) [1708085423.651351][1969:1969] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085423.651471][1969:1969] CHIP:DL: NVS set: chip-counters/boot-reason = 0 (0x0) [1708085423.651750][1969:1969] CHIP:DL: writing settings to file (/tmp/chip_config.ini-0MvGbk) [1708085423.652690][1969:1969] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085423.652806][1969:1969] CHIP:DL: NVS set: chip-config/regulatory-location = 0 (0x0) [1708085423.653082][1969:1969] CHIP:DL: writing settings to file (/tmp/chip_config.ini-jMJt4x) [1708085423.654169][1969:1969] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085423.654405][1969:1969] CHIP:DL: NVS set: chip-config/location-capability = 2 (0x2) [1708085423.656136][1969:1969] CHIP:DL: Got Ethernet interface: eth0 [1708085423.657428][1969:1969] CHIP:DL: Found the primary Ethernet interface:eth0 [1708085423.658819][1969:1969] CHIP:DL: Got WiFi interface: wlan0 [1708085423.658981][1969:1969] CHIP:DL: Failed to reset WiFi statistic counts [1708085423.659092][1969:1969] CHIP:IN: UDP::Init bind&listen port=0 [1708085423.659385][1969:1969] CHIP:IN: UDP::Init bound to port=37344 [1708085423.659509][1969:1969] CHIP:IN: BLEBase::Init - setting/overriding transport [1708085423.659607][1969:1969] CHIP:IN: TransportMgr initialized [1708085423.659718][1969:1969] CHIP:FP: Initializing FabricTable from persistent storage [1708085423.659876][1969:1969] CHIP:TS: Last Known Good Time: [unknown] [1708085423.659947][1969:1969] CHIP:TS: Setting Last Known Good Time to firmware build time 2023-10-14T01:16:48 [1708085423.664999][1969:1969] CHIP:ZCL: Using ZAP configuration... [1708085423.674902][1969:1969] CHIP:DL: Avahi client registered [1708085423.675148][1969:1969] CHIP:CTL: System State Initialized... [1708085423.675560][1969:1969] CHIP:CTL: Setting attestation nonce to random value [1708085423.675693][1969:1969] CHIP:CTL: Setting CSR nonce to random value [1708085423.675862][1969:1969] CHIP:IN: UDP::Init bind&listen port=5550 [1708085423.676167][1969:1969] CHIP:IN: UDP::Init bound to port=5550 [1708085423.676247][1969:1969] CHIP:IN: TransportMgr initialized [1708085423.678557][1969:1971] CHIP:DL: CHIP task running [1708085423.679010][1969:1971] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1708085423.680015][1969:1971] CHIP:CTL: Setting attestation nonce to random value [1708085423.680424][1969:1971] CHIP:CTL: Setting CSR nonce to random value [1708085423.680739][1969:1971] CHIP:CTL: Couldn't get ExampleOpCredsCAKey from storage: src/controller/ExamplePersistentStorage.cpp:106: CHIP Error 0x000000A0: Value not found in the persisted storage [1708085423.683083][1969:1971] CHIP:CTL: Couldn't get ExampleOpCredsICAKey from storage: src/controller/ExamplePersistentStorage.cpp:106: CHIP Error 0x000000A0: Value not found in the persisted storage [1708085423.685866][1969:1971] CHIP:CTL: Generating RCAC [1708085423.689347][1969:1971] CHIP:CTL: Generating ICAC [1708085423.693979][1969:1971] CHIP:CTL: Generating NOC [1708085423.695688][1969:1971] CHIP:FP: Validating NOC chain [1708085423.701951][1969:1971] CHIP:FP: NOC chain validation successful [1708085423.702400][1969:1971] CHIP:FP: Added new fabric at index: 0x1 [1708085423.702463][1969:1971] CHIP:FP: Assigned compressed fabric ID: 0xF6C4AAF60E4610F4, node ID: 0x000000000001B669 [1708085423.702531][1969:1971] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48 [1708085423.702585][1969:1971] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1708085423.702634][1969:1971] CHIP:TS: Retaining current Last Known Good Time [1708085423.705620][1969:1971] CHIP:FP: Metadata for Fabric 0x1 persisted to storage. [1708085423.709704][1969:1971] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-14T01:16:48 [1708085423.713468][1969:1971] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: F6C4AAF60E4610F4) [1708085423.713573][1969:1971] CHIP:IN: UDP::Init bind&listen port=5550 [1708085423.713856][1969:1971] CHIP:IN: UDP::Init bound to port=5550 [1708085423.713917][1969:1971] CHIP:IN: TransportMgr initialized [1708085423.781935][1969:1971] CHIP:CTL: Setting wifi credentials from parameters [1708085423.782025][1969:1971] CHIP:CTL: Setting attestation nonce to random value [1708085423.782122][1969:1971] CHIP:CTL: Setting CSR nonce to random value [1708085423.782209][1969:1971] CHIP:CTL: Checking ICD registration parameters [1708085423.782306][1969:1971] CHIP:CTL: Commission called for node ID 0x0000000000000001 [1708085423.782377][1969:1971] CHIP:DL: Long dispatch time: 103 ms, for event type 2 [1708085423.831270][1969:1971] CHIP:DL: BlueZ integration init success [1708085423.863564][1969:1970] CHIP:BLE: BLE removing known devices. [1708085423.867528][1969:1970] CHIP:BLE: BLE initiating scan. [1708085423.872594][1969:1971] CHIP:BLE: ChipDeviceScanner has started scanning! [1708085423.892422][1969:1970] CHIP:BLE: Device B4:9A:95:77:96:1B does not look like a CHIP device. [1708085423.895636][1969:1970] CHIP:BLE: Device 15:3F:39:F3:69:DA does not look like a CHIP device. [1708085423.901142][1969:1970] CHIP:BLE: Device 9C:0C:35:62:13:B8 does not look like a CHIP device. [1708085423.904122][1969:1970] CHIP:BLE: Device 0B:61:01:A2:09:16 does not look like a CHIP device. [1708085423.906297][1969:1970] CHIP:BLE: Device 09:48:FC:E5:0F:00 does not look like a CHIP device. [1708085423.917224][1969:1970] CHIP:BLE: Device 5F:CD:E9:A6:D9:65 does not look like a CHIP device. [1708085423.920710][1969:1970] CHIP:BLE: Device 15:E1:37:08:60:2D does not look like a CHIP device. [1708085423.921259][1969:1970] CHIP:BLE: Device 7C:75:58:04:9E:60 does not look like a CHIP device. [1708085423.924931][1969:1970] CHIP:BLE: Device 05:1D:36:3D:69:06 does not look like a CHIP device. [1708085423.930045][1969:1970] CHIP:BLE: New device scanned: 88:B1:11:E3:F8:E5 [1708085423.930142][1969:1970] CHIP:BLE: Device discriminator match. Attempting to connect. [1708085423.935706][1969:1970] CHIP:BLE: ChipDeviceScanner has stopped scanning! [1708085423.993205][1969:1970] CHIP:DL: FAIL: ConnectDevice: GDBus.Error:org.freedesktop.DBus.Error.UnknownObject: Method "Connect" with signature "" on interface "org.bluez.Device1" doesn't exist (41) [1708085423.993422][1969:1970] CHIP:BLE: Device connection failed: src/platform/Linux/bluez/BluezEndpoint.cpp:749: CHIP Error 0x000000AC: Internal error [1708085423.993540][1969:1971] CHIP:DL: HandlePlatformSpecificBLEEvent 16386 [1708085423.993612][1969:1971] CHIP:DIS: Closing all BLE connections [1708085423.993715][1969:1971] CHIP:TOO: Pairing Failure: src/platform/Linux/bluez/BluezEndpoint.cpp:748: CHIP Error 0x000000AC: Internal error [1708085423.994551][1969:1969] CHIP:CTL: Shutting down the commissioner [1708085423.994767][1969:1969] CHIP:CTL: Shutting down the controller [1708085423.994889][1969:1969] CHIP:IN: Expiring all sessions for fabric 0x1!! [1708085423.994946][1969:1969] CHIP:FP: Forgetting fabric 0x1 [1708085423.995024][1969:1969] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48 [1708085423.995454][1969:1969] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48 [1708085423.995524][1969:1969] CHIP:TS: Reverted Last Known Good Time to previous value [1708085423.995746][1969:1969] CHIP:CTL: Shutting down the commissioner [1708085423.995921][1969:1969] CHIP:CTL: Shutting down the controller [1708085423.995978][1969:1969] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1708085423.996428][1969:1969] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1708085423.996805][1969:1969] CHIP:FP: Shutting down FabricTable [1708085423.997051][1969:1969] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48 [1708085423.997558][1969:1969] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48 [1708085423.997639][1969:1969] CHIP:TS: Reverted Last Known Good Time to previous value [1708085423.998571][1969:1969] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-Fcu7NQ) [1708085423.999913][1969:1969] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085424.000070][1969:1969] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1708085424.000132][1969:1969] CHIP:DL: Inet Layer shutdown [1708085424.000181][1969:1969] CHIP:DL: BLE shutdown [1708085424.007207][1969:1969] CHIP:DL: System Layer shutdown [1708085424.010294][1969:1969] CHIP:TOO: Run command failure: src/platform/Linux/bluez/BluezEndpoint.cpp:748: CHIP Error 0x000000AC: Internal error ubuntu@ubuntu:~/master_cntrl/connectedhomeip/out/chip-tool$ sudo rm -rf /tmp/chip_* ubuntu@ubuntu:~/master_cntrl/connectedhomeip/out/chip-tool$ ./chip-tool pairing ble-wifi 1 GRLPrivate grlprivatewifi092010 20202021 3840 [1708085433.315283][1979:1979] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs [1708085433.315725][1979:1979] CHIP:DL: writing settings to file (/tmp/chip_tool_kvs-iuZz0k) [1708085433.316152][1979:1979] CHIP:DL: renamed tmp file to file (/tmp/chip_tool_kvs) [1708085433.317973][1979:1979] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1708085433.318070][1979:1979] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs [1708085433.332739][1979:1979] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1708085433.333307][1979:1979] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-4Nqs3N) [1708085433.333834][1979:1979] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085433.334117][1979:1979] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1708085433.334416][1979:1979] CHIP:DL: writing settings to file (/tmp/chip_config.ini-r4C6Gp) [1708085433.334790][1979:1979] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085433.335017][1979:1979] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1708085433.335307][1979:1979] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-HAxhx1) [1708085433.335675][1979:1979] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085433.336357][1979:1979] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-BwQTuo) [1708085433.337466][1979:1979] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085433.337593][1979:1979] CHIP:DL: NVS set: chip-factory/unique-id = "12B8BE73C90235C6" [1708085433.338050][1979:1979] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-aQ19pG) [1708085433.339111][1979:1979] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085433.339239][1979:1979] CHIP:DL: NVS set: chip-factory/vendor-id = 65521 (0xFFF1) [1708085433.339575][1979:1979] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-ehBdCq) [1708085433.340592][1979:1979] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1708085433.340713][1979:1979] CHIP:DL: NVS set: chip-factory/product-id = 32769 (0x8001) [1708085433.341018][1979:1979] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-5MOjLx) [1708085433.341917][1979:1979] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085433.342038][1979:1979] CHIP:DL: NVS set: chip-counters/reboot-count = 1 (0x1) [1708085433.342353][1979:1979] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-U559ej) [1708085433.343361][1979:1979] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085433.343482][1979:1979] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1708085433.343804][1979:1979] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-aVagTv) [1708085433.344776][1979:1979] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085433.344895][1979:1979] CHIP:DL: NVS set: chip-counters/boot-reason = 0 (0x0) [1708085433.345189][1979:1979] CHIP:DL: writing settings to file (/tmp/chip_config.ini-XmY9gb) [1708085433.346127][1979:1979] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085433.346248][1979:1979] CHIP:DL: NVS set: chip-config/regulatory-location = 0 (0x0) [1708085433.346569][1979:1979] CHIP:DL: writing settings to file (/tmp/chip_config.ini-bahDK5) [1708085433.347769][1979:1979] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1708085433.347889][1979:1979] CHIP:DL: NVS set: chip-config/location-capability = 2 (0x2) [1708085433.349522][1979:1979] CHIP:DL: Got Ethernet interface: eth0 [1708085433.350876][1979:1979] CHIP:DL: Found the primary Ethernet interface:eth0 [1708085433.352180][1979:1979] CHIP:DL: Got WiFi interface: wlan0 [1708085433.352337][1979:1979] CHIP:DL: Failed to reset WiFi statistic counts [1708085433.352452][1979:1979] CHIP:IN: UDP::Init bind&listen port=0 [1708085433.352758][1979:1979] CHIP:IN: UDP::Init bound to port=43941 [1708085433.352816][1979:1979] CHIP:IN: BLEBase::Init - setting/overriding transport [1708085433.352866][1979:1979] CHIP:IN: TransportMgr initialized [1708085433.353044][1979:1979] CHIP:FP: Initializing FabricTable from persistent storage [1708085433.353138][1979:1979] CHIP:TS: Last Known Good Time: [unknown] [1708085433.353226][1979:1979] CHIP:TS: Setting Last Known Good Time to firmware build time 2023-10-14T01:16:48 [1708085433.358293][1979:1979] CHIP:ZCL: Using ZAP configuration... [1708085433.368339][1979:1979] CHIP:DL: Avahi client registered [1708085433.368585][1979:1979] CHIP:CTL: System State Initialized... [1708085433.369001][1979:1979] CHIP:CTL: Setting attestation nonce to random value [1708085433.369126][1979:1979] CHIP:CTL: Setting CSR nonce to random value [1708085433.369297][1979:1979] CHIP:IN: UDP::Init bind&listen port=5550 [1708085433.369622][1979:1979] CHIP:IN: UDP::Init bound to port=5550 [1708085433.369681][1979:1979] CHIP:IN: TransportMgr initialized [1708085433.371983][1979:1981] CHIP:DL: CHIP task running [1708085433.372412][1979:1981] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1708085433.373578][1979:1981] CHIP:CTL: Setting attestation nonce to random value [1708085433.374059][1979:1981] CHIP:CTL: Setting CSR nonce to random value [1708085433.374426][1979:1981] CHIP:CTL: Couldn't get ExampleOpCredsCAKey from storage: src/controller/ExamplePersistentStorage.cpp:106: CHIP Error 0x000000A0: Value not found in the persisted storage [1708085433.376902][1979:1981] CHIP:CTL: Couldn't get ExampleOpCredsICAKey from storage: src/controller/ExamplePersistentStorage.cpp:106: CHIP Error 0x000000A0: Value not found in the persisted storage [1708085433.380053][1979:1981] CHIP:CTL: Generating RCAC [1708085433.383776][1979:1981] CHIP:CTL: Generating ICAC [1708085433.386159][1979:1981] CHIP:CTL: Generating NOC [1708085433.387907][1979:1981] CHIP:FP: Validating NOC chain [1708085433.394168][1979:1981] CHIP:FP: NOC chain validation successful [1708085433.394623][1979:1981] CHIP:FP: Added new fabric at index: 0x1 [1708085433.394686][1979:1981] CHIP:FP: Assigned compressed fabric ID: 0x9E2F45AB03EFB411, node ID: 0x000000000001B669 [1708085433.394753][1979:1981] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48 [1708085433.394807][1979:1981] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1708085433.394856][1979:1981] CHIP:TS: Retaining current Last Known Good Time [1708085433.397989][1979:1981] CHIP:FP: Metadata for Fabric 0x1 persisted to storage. [1708085433.401869][1979:1981] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-14T01:16:48 [1708085433.405894][1979:1981] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 9E2F45AB03EFB411) [1708085433.406005][1979:1981] CHIP:IN: UDP::Init bind&listen port=5550 [1708085433.406266][1979:1981] CHIP:IN: UDP::Init bound to port=5550 [1708085433.406324][1979:1981] CHIP:IN: TransportMgr initialized [1708085433.479621][1979:1981] CHIP:CTL: Setting wifi credentials from parameters [1708085433.479712][1979:1981] CHIP:CTL: Setting attestation nonce to random value [1708085433.479812][1979:1981] CHIP:CTL: Setting CSR nonce to random value [1708085433.479897][1979:1981] CHIP:CTL: Checking ICD registration parameters [1708085433.479996][1979:1981] CHIP:CTL: Commission called for node ID 0x0000000000000001 [1708085433.480067][1979:1981] CHIP:DL: Long dispatch time: 108 ms, for event type 2 [1708085433.531577][1979:1981] CHIP:DL: BlueZ integration init success [1708085433.567814][1979:1980] CHIP:BLE: BLE removing known devices. [1708085433.571980][1979:1980] CHIP:BLE: BLE initiating scan. [1708085433.577157][1979:1981] CHIP:BLE: ChipDeviceScanner has started scanning! [1708085433.588047][1979:1980] CHIP:BLE: New device scanned: EB:A7:63:5A:39:E8 [1708085433.588145][1979:1980] CHIP:BLE: Device discriminator match. Attempting to connect. [1708085433.593273][1979:1980] CHIP:BLE: ChipDeviceScanner has stopped scanning! [1708085433.720531][1979:1980] CHIP:DL: ConnectDevice complete [1708085433.720637][1979:1980] CHIP:BLE: New device connected: EB:A7:63:5A:39:E8 [1708085434.750999][1979:1980] CHIP:DL: Char /org/bluez/hci0/dev_EB_A7_63_5A_39_E8/service000c on service /org/bluez/hci0/dev_EB_A7_63_5A_39_E8/service000c [1708085434.751118][1979:1980] CHIP:DL: Char /org/bluez/hci0/dev_EB_A7_63_5A_39_E8/service0001 on service /org/bluez/hci0/dev_EB_A7_63_5A_39_E8/service000c [1708085434.751179][1979:1980] CHIP:DL: Char /org/bluez/hci0/dev_EB_A7_63_5A_39_E8/service0001 on service /org/bluez/hci0/dev_EB_A7_63_5A_39_E8/service000c [1708085434.751253][1979:1980] CHIP:DL: Char /org/bluez/hci0/dev_EB_A7_63_5A_39_E8/service000c on service /org/bluez/hci0/dev_EB_A7_63_5A_39_E8/service000c [1708085434.751314][1979:1980] CHIP:DL: Char /org/bluez/hci0/dev_EB_A7_63_5A_39_E8/service000c on service /org/bluez/hci0/dev_EB_A7_63_5A_39_E8/service000c [1708085434.751427][1979:1980] CHIP:DL: New BLE connection: conn 0xaaaafe1c3260, device EB:A7:63:5A:39:E8, path /org/bluez/hci0/dev_EB_A7_63_5A_39_E8 [1708085434.751697][1979:1981] CHIP:DL: HandlePlatformSpecificBLEEvent 16385 [1708085434.751778][1979:1981] CHIP:DIS: Closing all BLE connections [1708085434.751897][1979:1981] CHIP:IN: BleConnectionComplete: endPoint 0xaaaae5b76358 [1708085434.752921][1979:1981] CHIP:IN: SecureSession[0xffff84037cf0]: Allocated Type:1 LSID:18197 [1708085434.753015][1979:1981] CHIP:SC: Assigned local session key ID 18197 [1708085434.753280][1979:1981] CHIP:EM: <<< [E:2816i S:0 M:258262950] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:20 (SecureChannel:PBKDFParamRequest) [1708085434.753382][1979:1981] CHIP:IN: Message appended to BLE send queue [1708085434.753442][1979:1981] CHIP:SC: Sent PBKDF param request [1708085435.266876][1979:1981] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1708085435.537691][1979:1981] CHIP:DL: HandlePlatformSpecificBLEEvent 16388 [1708085435.537840][1979:1981] CHIP:BLE: subscribe complete, ep = 0xaaaae5b76358 [1708085441.117986][1979:1980] CHIP:DL: Bluez disconnected [1708085441.118061][1979:1980] CHIP:DL: Bluez notify CHIPoBluez connection disconnected [1708085441.118282][1979:1981] CHIP:IN: Failed to establish BLE connection: src/platform/Linux/BLEManagerImpl.cpp:536: Ble Error 0x0000040C: Remote device closed BLE connection [1708085441.118333][1979:1981] CHIP:IN: Clearing BLE pending packets. [1708085451.764241][1979:1981] CHIP:SC: PASESession timed out while waiting for a response from the peer. Expected message type was 33 [1708085451.764334][1979:1981] CHIP:IN: SecureSession[0xffff84037cf0]: Released - Type:1 LSID:18197 [1708085451.764387][1979:1981] CHIP:TOO: Secure Pairing Failed [1708085451.764459][1979:1981] CHIP:DIS: Closing all BLE connections [1708085451.764530][1979:1981] CHIP:TOO: Pairing Failure: src/protocols/secure_channel/PASESession.cpp:258: CHIP Error 0x00000032: Timeout [1708085451.764872][1979:1979] CHIP:CTL: Shutting down the commissioner [1708085451.765031][1979:1979] CHIP:CTL: Shutting down the controller [1708085451.765118][1979:1979] CHIP:IN: Expiring all sessions for fabric 0x1!! [1708085451.765160][1979:1979] CHIP:FP: Forgetting fabric 0x1 [1708085451.765215][1979:1979] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48 [1708085451.765697][1979:1979] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48 [1708085451.765805][1979:1979] CHIP:TS: Reverted Last Known Good Time to previous value [1708085451.765880][1979:1979] CHIP:CTL: Shutting down the commissioner [1708085451.766008][1979:1979] CHIP:CTL: Shutting down the controller [1708085451.766050][1979:1979] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1708085451.766283][1979:1979] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1708085451.766561][1979:1979] CHIP:FP: Shutting down FabricTable [1708085451.766674][1979:1979] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48 [1708085451.766938][1979:1979] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48 [1708085451.766994][1979:1979] CHIP:TS: Reverted Last Known Good Time to previous value [1708085451.767509][1979:1979] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-QcB55p) [1708085451.774212][1979:1979] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708085451.774360][1979:1979] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1708085451.774421][1979:1979] CHIP:DL: Inet Layer shutdown [1708085451.774471][1979:1979] CHIP:DL: BLE shutdown [1708085451.779088][1979:1979] CHIP:DL: System Layer shutdown [1708085451.780700][1979:1979] CHIP:TOO: Run command failure: src/protocols/secure_channel/PASESession.cpp:258: CHIP Error 0x00000032: Timeout ubuntu@ubuntu:~/master_cntrl/connectedhomeip/out/chip-tool$