Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Document the timeout extension for commissioning Thread device into Thread network #26

Open
MonicaisHer opened this issue Nov 27, 2023 · 2 comments
Labels
bug Something isn't working

Comments

@MonicaisHer
Copy link
Contributor

During the testing of matter-pi-gpio-commander, it was discovered that chip-tool encountered trouble commissioning the commander snap via the Thread feature. This comment also confirms that the Thread commission error might originate from chip-tool, considering that the Python Matter Server in Home Assistant Libs can commission the commander snap. Here is the log from chip-tool:

$ sudo chip-tool pairing ble-thread 110 hex:0e080000000000010000000300000c35060004001fffe00208d2f97acbb3662c9b0708fda12b93c2ba31520510fc408c0ff8d558aa52617ba63a435417030f4f70656e5468726561642d303235380102025804101ef3e9682c1d382dee42aec736a1c23b0c0402a0f7f8 20202021 3840
[1701099866.706623][82231:82231] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /mnt/chip_tool_kvs
[1701099866.706841][82231:82231] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /mnt/chip_kvs
[1701099866.706845][82231:82231] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /mnt/chip_kvs
[1701099866.707927][82231:82231] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /mnt/chip_factory.ini
[1701099866.707952][82231:82231] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /mnt/chip_config.ini
[1701099866.707960][82231:82231] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /mnt/chip_counters.ini
[1701099866.708015][82231:82231] CHIP:DL: writing settings to file (/mnt/chip_counters.ini-p2fLEu)
[1701099866.708102][82231:82231] CHIP:DL: renamed tmp file to file (/mnt/chip_counters.ini)
[1701099866.708107][82231:82231] CHIP:DL: NVS set: chip-counters/reboot-count = 27 (0x1B)
[1701099866.708324][82231:82231] CHIP:DL: Got Ethernet interface: eno1
[1701099866.708471][82231:82231] CHIP:DL: Found the primary Ethernet interface:eno1
[1701099866.708685][82231:82231] CHIP:DL: Failed to get WiFi interface
[1701099866.708687][82231:82231] CHIP:DL: Failed to reset WiFi statistic counts
[1701099866.708695][82231:82231] CHIP:IN: UDP::Init bind&listen port=0
[1701099866.708707][82231:82231] CHIP:IN: UDP::Init bound to port=42743
[1701099866.708708][82231:82231] CHIP:IN: UDP::Init bind&listen port=0
[1701099866.708715][82231:82231] CHIP:IN: UDP::Init bound to port=51228
[1701099866.708717][82231:82231] CHIP:IN: BLEBase::Init - setting/overriding transport
[1701099866.708718][82231:82231] CHIP:IN: TransportMgr initialized
[1701099866.708723][82231:82231] CHIP:FP: Initializing FabricTable from persistent storage
[1701099866.708750][82231:82231] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48
[1701099866.709037][82231:82231] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0xE6CACD9207E74AF0, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1701099866.709241][82231:82231] CHIP:ZCL: Using ZAP configuration...
[1701099866.711916][82231:82231] CHIP:CTL: System State Initialized...
[1701099866.711946][82231:82231] CHIP:CTL: Setting attestation nonce to random value
[1701099866.711951][82231:82231] CHIP:CTL: Setting CSR nonce to random value
[1701099866.711959][82231:82231] CHIP:IN: UDP::Init bind&listen port=5550
[1701099866.711966][82231:82231] CHIP:IN: UDP::Init bound to port=5550
[1701099866.711968][82231:82231] CHIP:IN: UDP::Init bind&listen port=5550
[1701099866.711974][82231:82231] CHIP:IN: UDP::Init bound to port=5550
[1701099866.711976][82231:82231] CHIP:IN: TransportMgr initialized
[1701099866.712045][82231:82259] CHIP:DL: CHIP task running
[1701099866.712060][82231:82259] CHIP:DL: HandlePlatformSpecificBLEEvent 32784
[1701099866.712140][82231:82259] CHIP:CTL: Setting attestation nonce to random value
[1701099866.712159][82231:82259] CHIP:CTL: Setting CSR nonce to random value
[1701099866.712329][82231:82259] CHIP:CTL: Generating NOC
[1701099866.712507][82231:82259] CHIP:FP: Validating NOC chain
[1701099866.712800][82231:82259] CHIP:FP: NOC chain validation successful
[1701099866.712830][82231:82259] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1701099866.712833][82231:82259] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48
[1701099866.712834][82231:82259] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
[1701099866.712835][82231:82259] CHIP:TS: Retaining current Last Known Good Time
[1701099866.713070][82231:82259] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
[1701099866.713226][82231:82259] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-14T01:16:48
[1701099866.713366][82231:82259] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: E6CACD9207E74AF0)
[1701099866.713370][82231:82259] CHIP:IN: UDP::Init bind&listen port=5550
[1701099866.713382][82231:82259] CHIP:IN: UDP::Init bound to port=5550
[1701099866.713383][82231:82259] CHIP:IN: UDP::Init bind&listen port=5550
[1701099866.713390][82231:82259] CHIP:IN: UDP::Init bound to port=5550
[1701099866.713392][82231:82259] CHIP:IN: TransportMgr initialized
[1701099866.714959][82231:82259] CHIP:CTL: Setting thread operational dataset from parameters
[1701099866.714962][82231:82259] CHIP:CTL: Setting attestation nonce to random value
[1701099866.714967][82231:82259] CHIP:CTL: Setting CSR nonce to random value
[1701099866.714970][82231:82259] CHIP:CTL: Commission called for node ID 0x000000000000006E
[1701099866.715954][82231:82258] CHIP:DL: TRACE: Bus acquired for name C-4137
[1701099866.717564][82231:82259] CHIP:DL: PlatformBlueZInit init success
[1701099866.719161][82231:82258] CHIP:BLE: BLE removing known devices.
[1701099866.719617][82231:82258] CHIP:BLE: BLE initiating scan.
[1701099866.867459][82231:82258] CHIP:BLE: Device 5A:C8:D3:99:E0:C4 does not look like a CHIP device.
...
[1701099876.783735][82231:82258] CHIP:BLE: Device E0:58:7C:A2:D7:11 does not look like a CHIP device.
[1701099876.794460][82231:82259] CHIP:DIS: Closing all BLE connections
[1701099876.794516][82231:82259] CHIP:TOO: Pairing Failure: src/platform/Linux/bluez/ChipDeviceScanner.cpp:173: CHIP Error 0x00000032: Timeout
[1701099876.794546][82231:82259] CHIP:BLE: BLE scan error: src/platform/Linux/bluez/ChipDeviceScanner.cpp:173: CHIP Error 0x00000032: Timeout
[1701099876.798313][82231:82259] CHIP:BLE: Scan complete. No matching device found.
[1701099876.798514][82231:82231] CHIP:CTL: Shutting down the commissioner
[1701099876.798595][82231:82231] CHIP:CTL: Shutting down the controller
[1701099876.798636][82231:82231] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1701099876.798651][82231:82231] CHIP:FP: Forgetting fabric 0x1
[1701099876.798676][82231:82231] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48
[1701099876.798817][82231:82231] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48
[1701099876.798828][82231:82231] CHIP:TS: Reverted Last Known Good Time to previous value
[1701099876.798867][82231:82231] CHIP:CTL: Shutting down the commissioner
[1701099876.798910][82231:82231] CHIP:CTL: Shutting down the controller
[1701099876.798922][82231:82231] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1701099876.799119][82231:82231] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1701099876.799177][82231:82231] CHIP:FP: Shutting down FabricTable
[1701099876.799192][82231:82231] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48
[1701099876.799294][82231:82231] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48
[1701099876.799307][82231:82231] CHIP:TS: Reverted Last Known Good Time to previous value
[1701099876.799589][82231:82231] CHIP:DL: writing settings to file (/mnt/chip_counters.ini-35CMQo)
[1701099876.799997][82231:82231] CHIP:DL: renamed tmp file to file (/mnt/chip_counters.ini)
[1701099876.800030][82231:82231] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1701099876.800043][82231:82231] CHIP:DL: Inet Layer shutdown
[1701099876.800051][82231:82231] CHIP:DL: BLE shutdown
[1701099876.802640][82231:82231] CHIP:DL: System Layer shutdown
[1701099876.803121][82231:82231] CHIP:TOO: Run command failure: src/platform/Linux/bluez/ChipDeviceScanner.cpp:173: CHIP Error 0x00000032: Timeout
@MonicaisHer MonicaisHer added the bug Something isn't working label Nov 27, 2023
@MonicaisHer
Copy link
Contributor Author

MonicaisHer commented Nov 27, 2023

The chip tool might be run in interactive mode to allow for an extended period of time to scan the Thread device.

For commands such as event subscriptions that need to run for an extended period
of time, the CHIP Tool can be started in interactive mode first before running
the command.

https://github.com/project-chip/connectedhomeip/blob/master/docs/guides/chip_tool_guide.md#interactive-mode

@MonicaisHer
Copy link
Contributor Author

Using the chip-tool snap in interactive mode to allow for a timeout when scanning Thread devices could be documented in the README.

@MonicaisHer MonicaisHer changed the title Timeout on commission Thread device into Thread network Document the timeout extension for commissioning Thread device into Thread network Mar 20, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

1 participant