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

[BUG] [chip-tool] remove-keyset cann't remove keyset #27600

Closed
resghst opened this issue Jul 3, 2023 · 0 comments · Fixed by #27676
Closed

[BUG] [chip-tool] remove-keyset cann't remove keyset #27600

resghst opened this issue Jul 3, 2023 · 0 comments · Fixed by #27676
Labels
bug Something isn't working needs triage

Comments

@resghst
Copy link

resghst commented Jul 3, 2023

Reproduction steps

When I want to remove a key-set from the chip-tool keyset table, I get an error in the remove-keyset command. Mabe some mistakes in my step.
The platform is Ubuntu 22.04.
Following is reproduce step:

  1. chip-tool groupsettings show-keysets
  2. chip-tool groupsettings add-keysets 1 0 2220000 hex:fd9f86b931f8f08772b2a36174e32d01
  3. chip-tool groupsettings show-keysets
  4. chip-tool groupsettings remove-keyset 1 (Get error)
    Run command failure: examples/chip-tool/commands/common/CHIPCommand.cpp:537: CHIP Error 0x00000032: Timeout
  5. chip-tool groupsettings show-keysets

log:

$ chip-tool groupsettings show-keysets
[1688383296.300197][32653:32653] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1688383296.301210][32653:32653] CHIP:DL: writing settings to file (/tmp/chip_kvs-xLz8OG)
[1688383296.301718][32653:32653] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs)
[1688383296.303623][32653:32653] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1688383296.303793][32653:32653] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-AOK0W4)
[1688383296.303927][32653:32653] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini)
[1688383296.303947][32653:32653] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1688383296.316564][32653:32653] CHIP:DL: writing settings to file (/tmp/chip_config.ini-RMYOFs)
[1688383296.316670][32653:32653] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini)
[1688383296.316690][32653:32653] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1688383296.316771][32653:32653] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-VRMQYR)
[1688383296.316799][32653:32653] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1688383296.316863][32653:32653] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-psJ7V1)
[1688383296.317056][32653:32653] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini)
[1688383296.317109][32653:32653] CHIP:DL: NVS set: chip-factory/unique-id = "B82299FB85760898"
[1688383296.317143][32653:32653] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-kIzGmr)
[1688383296.318022][32653:32653] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini)
[1688383296.318081][32653:32653] CHIP:DL: NVS set: chip-factory/vendor-id = 65521 (0xFFF1)
[1688383296.318115][32653:32653] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-xT0bg7)
[1688383296.318268][32653:32653] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini)
[1688383296.318325][32653:32653] CHIP:DL: NVS set: chip-factory/product-id = 32769 (0x8001)
[1688383296.318355][32653:32653] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-eix0QY)
[1688383296.318483][32653:32653] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1688383296.318493][32653:32653] CHIP:DL: NVS set: chip-counters/reboot-count = 1 (0x1)
[1688383296.318521][32653:32653] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-3LruJu)
[1688383296.319359][32653:32653] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1688383296.319381][32653:32653] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1688383296.319557][32653:32653] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-YATMRQ)
[1688383296.319701][32653:32653] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1688383296.319717][32653:32653] CHIP:DL: NVS set: chip-counters/boot-reason = 0 (0x0)
[1688383296.319746][32653:32653] CHIP:DL: writing settings to file (/tmp/chip_config.ini-xT4INY)
[1688383296.319873][32653:32653] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini)
[1688383296.319888][32653:32653] CHIP:DL: NVS set: chip-config/regulatory-location = 0 (0x0)
[1688383296.319917][32653:32653] CHIP:DL: writing settings to file (/tmp/chip_config.ini-MJ7FHh)
[1688383296.320129][32653:32653] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini)
[1688383296.320145][32653:32653] CHIP:DL: NVS set: chip-config/location-capability = 2 (0x2)
[1688383296.320485][32653:32653] CHIP:DL: Got Ethernet interface: enp0s3
[1688383296.320629][32653:32653] CHIP:DL: Found the primary Ethernet interface:enp0s3
[1688383296.321035][32653:32653] CHIP:DL: Failed to get WiFi interface
[1688383296.321047][32653:32653] CHIP:DL: Failed to reset WiFi statistic counts
[1688383296.321067][32653:32653] CHIP:IN: UDP::Init bind&listen port=0
[1688383296.321089][32653:32653] CHIP:IN: UDP::Init bound to port=41466
[1688383296.321095][32653:32653] CHIP:IN: UDP::Init bind&listen port=0
[1688383296.321108][32653:32653] CHIP:IN: UDP::Init bound to port=39297
[1688383296.321113][32653:32653] CHIP:IN: BLEBase::Init - setting/overriding transport
[1688383296.321118][32653:32653] CHIP:IN: TransportMgr initialized
[1688383296.321131][32653:32653] CHIP:FP: Initializing FabricTable from persistent storage
[1688383296.321144][32653:32653] CHIP:TS: Last Known Good Time: [unknown]
[1688383296.321150][32653:32653] CHIP:TS: Setting Last Known Good Time to firmware build time 2023-06-14T14:00:57
[1688383296.322051][32653:32653] CHIP:ZCL: Using ZAP configuration...
[1688383296.322670][32653:32653] CHIP:CTL: System State Initialized...
[1688383296.322707][32653:32653] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688383296.322722][32653:32653] CHIP:CTL: Setting attestation nonce to random value
[1688383296.322733][32653:32653] CHIP:CTL: Setting CSR nonce to random value
[1688383296.322804][32653:32655] CHIP:DL: CHIP task running
[1688383296.322825][32653:32655] CHIP:DL: HandlePlatformSpecificBLEEvent 32784
[1688383296.322910][32653:32655] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688383296.322919][32653:32655] CHIP:CTL: Setting attestation nonce to random value
[1688383296.322951][32653:32655] CHIP:CTL: Setting CSR nonce to random value
[1688383296.322973][32653:32655] CHIP:CTL: Couldn't get ExampleOpCredsCAKey from storage: src/controller/ExamplePersistentStorage.cpp:93: CHIP Error 0x000000A0: Value not found in the persisted storage
[1688383296.323309][32653:32655] CHIP:CTL: Couldn't get ExampleOpCredsICAKey from storage: src/controller/ExamplePersistentStorage.cpp:93: CHIP Error 0x000000A0: Value not found in the persisted storage
[1688383296.323742][32653:32655] CHIP:CTL: Generating RCAC
[1688383296.324433][32653:32655] CHIP:CTL: Generating ICAC
[1688383296.325642][32653:32655] CHIP:CTL: Generating NOC
[1688383296.325815][32653:32655] CHIP:FP: Validating NOC chain
[1688383296.326418][32653:32655] CHIP:FP: NOC chain validation successful
[1688383296.326471][32653:32655] CHIP:FP: Added new fabric at index: 0x1
[1688383296.326478][32653:32655] CHIP:FP: Assigned compressed fabric ID: 0xAA744077F7B48F17, node ID: 0x000000000001B669
[1688383296.326486][32653:32655] CHIP:TS: Last Known Good Time: 2023-06-14T14:00:57
[1688383296.326492][32653:32655] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
[1688383296.326497][32653:32655] CHIP:TS: Retaining current Last Known Good Time
[1688383296.327884][32653:32655] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
[1688383296.328782][32653:32655] CHIP:TS: Committing Last Known Good Time to storage: 2023-06-14T14:00:57
[1688383296.329828][32653:32655] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: AA744077F7B48F17)

  +-------------------------------------------------------------------------------------+
  | Available KeySets :                                                                 |
  +-------------------------------------------------------------------------------------+
  | KeySet Id   |   Key Policy                                                          |
  | 0x0             Trust First                                                         |
  | 0x1a3           Trust First                                                         |
  | 0x1a2           Cache and Sync                                                      |
  | 0x1a1           Cache and Sync                                                      |
  +-------------------------------------------------------------------------------------+
[1688383296.347503][32653:32653] CHIP:CTL: Shutting down the commissioner
[1688383296.347513][32653:32653] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688383296.347520][32653:32653] CHIP:CTL: Shutting down the controller
[1688383296.347529][32653:32653] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1688383296.347535][32653:32653] CHIP:FP: Forgetting fabric 0x1
[1688383296.347546][32653:32653] CHIP:TS: Pending Last Known Good Time: 2023-06-14T14:00:57
[1688383296.347571][32653:32653] CHIP:TS: Previous Last Known Good Time: 2023-06-14T14:00:57
[1688383296.347577][32653:32653] CHIP:TS: Reverted Last Known Good Time to previous value
[1688383296.347587][32653:32653] CHIP:CTL: Shutting down the commissioner
[1688383296.347728][32653:32653] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688383296.347741][32653:32653] CHIP:CTL: Shutting down the controller
[1688383296.347748][32653:32653] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1688383296.347827][32653:32653] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1688383296.347845][32653:32653] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.
[1688383296.347857][32653:32653] CHIP:FP: Shutting down FabricTable
[1688383296.347864][32653:32653] CHIP:TS: Pending Last Known Good Time: 2023-06-14T14:00:57
[1688383296.347886][32653:32653] CHIP:TS: Previous Last Known Good Time: 2023-06-14T14:00:57
[1688383296.347892][32653:32653] CHIP:TS: Reverted Last Known Good Time to previous value
[1688383296.347951][32653:32653] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-Ow4N5v)
[1688383296.348126][32653:32653] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1688383296.348145][32653:32653] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1688383296.348152][32653:32653] CHIP:DL: Inet Layer shutdown
[1688383296.348158][32653:32653] CHIP:DL: BLE shutdown
[1688383296.348164][32653:32653] CHIP:DL: System Layer shutdown



$ chip-tool groupsettings add-keysets 1 0 2220000 hex:fd9f86b931f8f08772b2a36174e32d01
[1688383362.579057][32763:32763] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1688383362.580721][32763:32763] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1688383362.580836][32763:32763] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1688383362.580916][32763:32763] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1688383362.581030][32763:32763] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-A4AsPj)
[1688383362.581308][32763:32763] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1688383362.581324][32763:32763] CHIP:DL: NVS set: chip-counters/reboot-count = 2 (0x2)
[1688383362.581529][32763:32763] CHIP:DL: Got Ethernet interface: enp0s3
[1688383362.581741][32763:32763] CHIP:DL: Found the primary Ethernet interface:enp0s3
[1688383362.582219][32763:32763] CHIP:DL: Failed to get WiFi interface
[1688383362.582232][32763:32763] CHIP:DL: Failed to reset WiFi statistic counts
[1688383362.582251][32763:32763] CHIP:IN: UDP::Init bind&listen port=0
[1688383362.582271][32763:32763] CHIP:IN: UDP::Init bound to port=50999
[1688383362.582278][32763:32763] CHIP:IN: UDP::Init bind&listen port=0
[1688383362.582292][32763:32763] CHIP:IN: UDP::Init bound to port=41836
[1688383362.582298][32763:32763] CHIP:IN: BLEBase::Init - setting/overriding transport
[1688383362.582303][32763:32763] CHIP:IN: TransportMgr initialized
[1688383362.582315][32763:32763] CHIP:FP: Initializing FabricTable from persistent storage
[1688383362.582359][32763:32763] CHIP:TS: Last Known Good Time: 2023-06-14T14:00:57
[1688383362.582744][32763:32763] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0xAA744077F7B48F17, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1688383362.586911][32763:32763] CHIP:ZCL: Using ZAP configuration...
[1688383362.587359][32763:32763] CHIP:CTL: System State Initialized...
[1688383362.587391][32763:32763] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688383362.587411][32763:32763] CHIP:CTL: Setting attestation nonce to random value
[1688383362.587421][32763:32763] CHIP:CTL: Setting CSR nonce to random value
[1688383362.587491][32763:32765] CHIP:DL: CHIP task running
[1688383362.587512][32763:32765] CHIP:DL: HandlePlatformSpecificBLEEvent 32784
[1688383362.587580][32763:32765] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688383362.587590][32763:32765] CHIP:CTL: Setting attestation nonce to random value
[1688383362.587618][32763:32765] CHIP:CTL: Setting CSR nonce to random value
[1688383362.588007][32763:32765] CHIP:CTL: Generating NOC
[1688383362.588228][32763:32765] CHIP:FP: Validating NOC chain
[1688383362.588660][32763:32765] CHIP:FP: NOC chain validation successful
[1688383362.588696][32763:32765] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1688383362.588704][32763:32765] CHIP:TS: Last Known Good Time: 2023-06-14T14:00:57
[1688383362.588709][32763:32765] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
[1688383362.588715][32763:32765] CHIP:TS: Retaining current Last Known Good Time
[1688383362.589429][32763:32765] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
[1688383362.590117][32763:32765] CHIP:TS: Committing Last Known Good Time to storage: 2023-06-14T14:00:57
[1688383362.590844][32763:32765] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: AA744077F7B48F17)
[1688383362.597921][32763:32763] CHIP:CTL: Shutting down the commissioner
[1688383362.598114][32763:32763] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688383362.598128][32763:32763] CHIP:CTL: Shutting down the controller
[1688383362.598139][32763:32763] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1688383362.598146][32763:32763] CHIP:FP: Forgetting fabric 0x1
[1688383362.598156][32763:32763] CHIP:TS: Pending Last Known Good Time: 2023-06-14T14:00:57
[1688383362.598186][32763:32763] CHIP:TS: Previous Last Known Good Time: 2023-06-14T14:00:57
[1688383362.598192][32763:32763] CHIP:TS: Reverted Last Known Good Time to previous value
[1688383362.598205][32763:32763] CHIP:CTL: Shutting down the commissioner
[1688383362.598211][32763:32763] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688383362.598216][32763:32763] CHIP:CTL: Shutting down the controller
[1688383362.598221][32763:32763] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1688383362.598271][32763:32763] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1688383362.598287][32763:32763] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.
[1688383362.598299][32763:32763] CHIP:FP: Shutting down FabricTable
[1688383362.598305][32763:32763] CHIP:TS: Pending Last Known Good Time: 2023-06-14T14:00:57
[1688383362.598323][32763:32763] CHIP:TS: Previous Last Known Good Time: 2023-06-14T14:00:57
[1688383362.598328][32763:32763] CHIP:TS: Reverted Last Known Good Time to previous value
[1688383362.612216][32763:32763] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-U3OnH8)
[1688383362.612497][32763:32763] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1688383362.612520][32763:32763] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1688383362.612529][32763:32763] CHIP:DL: Inet Layer shutdown
[1688383362.612535][32763:32763] CHIP:DL: BLE shutdown
[1688383362.612541][32763:32763] CHIP:DL: System Layer shutdown


$ chip-tool groupsettings show-keysets
[1688383410.382614][32855:32855] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1688383410.386320][32855:32855] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1688383410.386382][32855:32855] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1688383410.386405][32855:32855] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1688383410.386633][32855:32855] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-xuYMPa)
[1688383410.387366][32855:32855] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1688383410.388032][32855:32855] CHIP:DL: NVS set: chip-counters/reboot-count = 3 (0x3)
[1688383410.388409][32855:32855] CHIP:DL: Got Ethernet interface: enp0s3
[1688383410.388629][32855:32855] CHIP:DL: Found the primary Ethernet interface:enp0s3
[1688383410.389512][32855:32855] CHIP:DL: Failed to get WiFi interface
[1688383410.389697][32855:32855] CHIP:DL: Failed to reset WiFi statistic counts
[1688383410.389724][32855:32855] CHIP:IN: UDP::Init bind&listen port=0
[1688383410.389751][32855:32855] CHIP:IN: UDP::Init bound to port=54832
[1688383410.389769][32855:32855] CHIP:IN: UDP::Init bind&listen port=0
[1688383410.389783][32855:32855] CHIP:IN: UDP::Init bound to port=57722
[1688383410.389790][32855:32855] CHIP:IN: BLEBase::Init - setting/overriding transport
[1688383410.389796][32855:32855] CHIP:IN: TransportMgr initialized
[1688383410.389809][32855:32855] CHIP:FP: Initializing FabricTable from persistent storage
[1688383410.389857][32855:32855] CHIP:TS: Last Known Good Time: 2023-06-14T14:00:57
[1688383410.390437][32855:32855] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0xAA744077F7B48F17, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1688383410.392346][32855:32855] CHIP:ZCL: Using ZAP configuration...
[1688383410.393244][32855:32855] CHIP:CTL: System State Initialized...
[1688383410.393290][32855:32855] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688383410.393305][32855:32855] CHIP:CTL: Setting attestation nonce to random value
[1688383410.393329][32855:32855] CHIP:CTL: Setting CSR nonce to random value
[1688383410.393589][32855:32857] CHIP:DL: CHIP task running
[1688383410.393664][32855:32857] CHIP:DL: HandlePlatformSpecificBLEEvent 32784
[1688383410.393758][32855:32857] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688383410.393866][32855:32857] CHIP:CTL: Setting attestation nonce to random value
[1688383410.393901][32855:32857] CHIP:CTL: Setting CSR nonce to random value
[1688383410.394170][32855:32857] CHIP:CTL: Generating NOC
[1688383410.394487][32855:32857] CHIP:FP: Validating NOC chain
[1688383410.394956][32855:32857] CHIP:FP: NOC chain validation successful
[1688383410.395067][32855:32857] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1688383410.395077][32855:32857] CHIP:TS: Last Known Good Time: 2023-06-14T14:00:57
[1688383410.395080][32855:32857] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
[1688383410.395082][32855:32857] CHIP:TS: Retaining current Last Known Good Time
[1688383410.396768][32855:32857] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
[1688383410.398990][32855:32857] CHIP:TS: Committing Last Known Good Time to storage: 2023-06-14T14:00:57
[1688383410.402364][32855:32857] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: AA744077F7B48F17)

  +-------------------------------------------------------------------------------------+
  | Available KeySets :                                                                 |
  +-------------------------------------------------------------------------------------+
  | KeySet Id   |   Key Policy                                                          |
  | 0x1             Trust First                                                         |
  | 0x0             Trust First                                                         |
  | 0x1a3           Trust First                                                         |
  | 0x1a2           Cache and Sync                                                      |
  | 0x1a1           Cache and Sync                                                      |
  +-------------------------------------------------------------------------------------+
[1688383410.424277][32855:32855] CHIP:CTL: Shutting down the commissioner
[1688383410.424289][32855:32855] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688383410.424293][32855:32855] CHIP:CTL: Shutting down the controller
[1688383410.424298][32855:32855] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1688383410.424301][32855:32855] CHIP:FP: Forgetting fabric 0x1
[1688383410.424309][32855:32855] CHIP:TS: Pending Last Known Good Time: 2023-06-14T14:00:57
[1688383410.424340][32855:32855] CHIP:TS: Previous Last Known Good Time: 2023-06-14T14:00:57
[1688383410.424341][32855:32855] CHIP:TS: Reverted Last Known Good Time to previous value
[1688383410.424352][32855:32855] CHIP:CTL: Shutting down the commissioner
[1688383410.424354][32855:32855] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688383410.424356][32855:32855] CHIP:CTL: Shutting down the controller
[1688383410.424358][32855:32855] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1688383410.424410][32855:32855] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1688383410.424421][32855:32855] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.
[1688383410.424430][32855:32855] CHIP:FP: Shutting down FabricTable
[1688383410.424432][32855:32855] CHIP:TS: Pending Last Known Good Time: 2023-06-14T14:00:57
[1688383410.424491][32855:32855] CHIP:TS: Previous Last Known Good Time: 2023-06-14T14:00:57
[1688383410.424494][32855:32855] CHIP:TS: Reverted Last Known Good Time to previous value
[1688383410.424661][32855:32855] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-BdGwiZ)
[1688383410.426537][32855:32855] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1688383410.426554][32855:32855] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1688383410.426558][32855:32855] CHIP:DL: Inet Layer shutdown
[1688383410.426560][32855:32855] CHIP:DL: BLE shutdown
[1688383410.426563][32855:32855] CHIP:DL: System Layer shutdown


$ chip-tool groupsettings remove-keyset 1
[1688383440.595360][32932:32932] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1688383440.597615][32932:32932] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1688383440.597748][32932:32932] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1688383440.597765][32932:32932] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1688383440.597925][32932:32932] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-HG6ePX)
[1688383440.598744][32932:32932] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1688383440.598813][32932:32932] CHIP:DL: NVS set: chip-counters/reboot-count = 4 (0x4)
[1688383440.599901][32932:32932] CHIP:DL: Got Ethernet interface: enp0s3
[1688383440.600121][32932:32932] CHIP:DL: Found the primary Ethernet interface:enp0s3
[1688383440.600667][32932:32932] CHIP:DL: Failed to get WiFi interface
[1688383440.600721][32932:32932] CHIP:DL: Failed to reset WiFi statistic counts
[1688383440.600742][32932:32932] CHIP:IN: UDP::Init bind&listen port=0
[1688383440.600764][32932:32932] CHIP:IN: UDP::Init bound to port=47911
[1688383440.600767][32932:32932] CHIP:IN: UDP::Init bind&listen port=0
[1688383440.600779][32932:32932] CHIP:IN: UDP::Init bound to port=60265
[1688383440.600831][32932:32932] CHIP:IN: BLEBase::Init - setting/overriding transport
[1688383440.600835][32932:32932] CHIP:IN: TransportMgr initialized
[1688383440.600845][32932:32932] CHIP:FP: Initializing FabricTable from persistent storage
[1688383440.600894][32932:32932] CHIP:TS: Last Known Good Time: 2023-06-14T14:00:57
[1688383440.601402][32932:32932] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0xAA744077F7B48F17, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1688383440.604480][32932:32932] CHIP:ZCL: Using ZAP configuration...
[1688383440.605075][32932:32932] CHIP:CTL: System State Initialized...
[1688383440.605181][32932:32932] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688383440.605201][32932:32932] CHIP:CTL: Setting attestation nonce to random value
[1688383440.605214][32932:32932] CHIP:CTL: Setting CSR nonce to random value
[1688383440.605315][32932:32934] CHIP:DL: CHIP task running
[1688383440.605399][32932:32934] CHIP:DL: HandlePlatformSpecificBLEEvent 32784
[1688383440.605497][32932:32934] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688383440.605566][32932:32934] CHIP:CTL: Setting attestation nonce to random value
[1688383440.605626][32932:32934] CHIP:CTL: Setting CSR nonce to random value
[1688383440.606005][32932:32934] CHIP:CTL: Generating NOC
[1688383440.606339][32932:32934] CHIP:FP: Validating NOC chain
[1688383440.609310][32932:32934] CHIP:FP: NOC chain validation successful
[1688383440.609426][32932:32934] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1688383440.609434][32932:32934] CHIP:TS: Last Known Good Time: 2023-06-14T14:00:57
[1688383440.609437][32932:32934] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
[1688383440.609439][32932:32934] CHIP:TS: Retaining current Last Known Good Time
[1688383440.611017][32932:32934] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
[1688383440.612843][32932:32934] CHIP:TS: Committing Last Known Good Time to storage: 2023-06-14T14:00:57
[1688383440.614133][32932:32934] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: AA744077F7B48F17)
[1688383445.605917][32932:32932] CHIP:CTL: Shutting down the commissioner
[1688383445.606005][32932:32932] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688383445.606013][32932:32932] CHIP:CTL: Shutting down the controller
[1688383445.606019][32932:32932] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1688383445.606022][32932:32932] CHIP:FP: Forgetting fabric 0x1
[1688383445.606031][32932:32932] CHIP:TS: Pending Last Known Good Time: 2023-06-14T14:00:57
[1688383445.606072][32932:32932] CHIP:TS: Previous Last Known Good Time: 2023-06-14T14:00:57
[1688383445.606074][32932:32932] CHIP:TS: Reverted Last Known Good Time to previous value
[1688383445.606086][32932:32932] CHIP:CTL: Shutting down the commissioner
[1688383445.606087][32932:32932] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688383445.606089][32932:32932] CHIP:CTL: Shutting down the controller
[1688383445.606091][32932:32932] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1688383445.606143][32932:32932] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1688383445.606155][32932:32932] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.
[1688383445.606163][32932:32932] CHIP:FP: Shutting down FabricTable
[1688383445.606165][32932:32932] CHIP:TS: Pending Last Known Good Time: 2023-06-14T14:00:57
[1688383445.606178][32932:32932] CHIP:TS: Previous Last Known Good Time: 2023-06-14T14:00:57
[1688383445.606222][32932:32932] CHIP:TS: Reverted Last Known Good Time to previous value
[1688383445.606409][32932:32932] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-AzqzGB)
[1688383445.607046][32932:32932] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1688383445.607100][32932:32932] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1688383445.607105][32932:32932] CHIP:DL: Inet Layer shutdown
[1688383445.607107][32932:32932] CHIP:DL: BLE shutdown
[1688383445.607110][32932:32932] CHIP:DL: System Layer shutdown
[1688383445.607935][32932:32932] CHIP:TOO: Run command failure: examples/chip-tool/commands/common/CHIPCommand.cpp:537: CHIP Error 0x00000032: Timeout


$ chip-tool groupsettings show-keysets
[1688383461.365022][32968:32968] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1688383461.366727][32968:32968] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1688383461.366851][32968:32968] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1688383461.366866][32968:32968] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1688383461.368965][32968:32968] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-3i1oPJ)
[1688383461.369314][32968:32968] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1688383461.369433][32968:32968] CHIP:DL: NVS set: chip-counters/reboot-count = 5 (0x5)
[1688383461.369791][32968:32968] CHIP:DL: Got Ethernet interface: enp0s3
[1688383461.369994][32968:32968] CHIP:DL: Found the primary Ethernet interface:enp0s3
[1688383461.370564][32968:32968] CHIP:DL: Failed to get WiFi interface
[1688383461.370611][32968:32968] CHIP:DL: Failed to reset WiFi statistic counts
[1688383461.370640][32968:32968] CHIP:IN: UDP::Init bind&listen port=0
[1688383461.370676][32968:32968] CHIP:IN: UDP::Init bound to port=34867
[1688383461.370681][32968:32968] CHIP:IN: UDP::Init bind&listen port=0
[1688383461.370699][32968:32968] CHIP:IN: UDP::Init bound to port=45319
[1688383461.370702][32968:32968] CHIP:IN: BLEBase::Init - setting/overriding transport
[1688383461.370705][32968:32968] CHIP:IN: TransportMgr initialized
[1688383461.370718][32968:32968] CHIP:FP: Initializing FabricTable from persistent storage
[1688383461.370783][32968:32968] CHIP:TS: Last Known Good Time: 2023-06-14T14:00:57
[1688383461.371252][32968:32968] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0xAA744077F7B48F17, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1688383461.372873][32968:32968] CHIP:ZCL: Using ZAP configuration...
[1688383461.373360][32968:32968] CHIP:CTL: System State Initialized...
[1688383461.373453][32968:32968] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688383461.373468][32968:32968] CHIP:CTL: Setting attestation nonce to random value
[1688383461.373478][32968:32968] CHIP:CTL: Setting CSR nonce to random value
[1688383461.373646][32968:32970] CHIP:DL: CHIP task running
[1688383461.373677][32968:32970] CHIP:DL: HandlePlatformSpecificBLEEvent 32784
[1688383461.373760][32968:32970] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688383461.373767][32968:32970] CHIP:CTL: Setting attestation nonce to random value
[1688383461.373796][32968:32970] CHIP:CTL: Setting CSR nonce to random value
[1688383461.374036][32968:32970] CHIP:CTL: Generating NOC
[1688383461.374259][32968:32970] CHIP:FP: Validating NOC chain
[1688383461.374715][32968:32970] CHIP:FP: NOC chain validation successful
[1688383461.374825][32968:32970] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1688383461.374833][32968:32970] CHIP:TS: Last Known Good Time: 2023-06-14T14:00:57
[1688383461.374836][32968:32970] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
[1688383461.374837][32968:32970] CHIP:TS: Retaining current Last Known Good Time
[1688383461.375969][32968:32970] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
[1688383461.377148][32968:32970] CHIP:TS: Committing Last Known Good Time to storage: 2023-06-14T14:00:57
[1688383461.378538][32968:32970] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: AA744077F7B48F17)

  +-------------------------------------------------------------------------------------+
  | Available KeySets :                                                                 |
  +-------------------------------------------------------------------------------------+
  | KeySet Id   |   Key Policy                                                          |
  | 0x1             Trust First                                                         |
  | 0x0             Trust First                                                         |
  | 0x1a3           Trust First                                                         |
  | 0x1a2           Cache and Sync                                                      |
  | 0x1a1           Cache and Sync                                                      |
  +-------------------------------------------------------------------------------------+
[1688383461.397223][32968:32968] CHIP:CTL: Shutting down the commissioner
[1688383461.397570][32968:32968] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688383461.397946][32968:32968] CHIP:CTL: Shutting down the controller
[1688383461.398346][32968:32968] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1688383461.399091][32968:32968] CHIP:FP: Forgetting fabric 0x1
[1688383461.399541][32968:32968] CHIP:TS: Pending Last Known Good Time: 2023-06-14T14:00:57
[1688383461.403939][32968:32968] CHIP:TS: Previous Last Known Good Time: 2023-06-14T14:00:57
[1688383461.403968][32968:32968] CHIP:TS: Reverted Last Known Good Time to previous value
[1688383461.403999][32968:32968] CHIP:CTL: Shutting down the commissioner
[1688383461.404006][32968:32968] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688383461.404020][32968:32968] CHIP:CTL: Shutting down the controller
[1688383461.404028][32968:32968] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1688383461.404119][32968:32968] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1688383461.404146][32968:32968] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.
[1688383461.404163][32968:32968] CHIP:FP: Shutting down FabricTable
[1688383461.404172][32968:32968] CHIP:TS: Pending Last Known Good Time: 2023-06-14T14:00:57
[1688383461.404197][32968:32968] CHIP:TS: Previous Last Known Good Time: 2023-06-14T14:00:57
[1688383461.404203][32968:32968] CHIP:TS: Reverted Last Known Good Time to previous value
[1688383461.404289][32968:32968] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-VO5wjI)
[1688383461.404536][32968:32968] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1688383461.404559][32968:32968] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1688383461.404566][32968:32968] CHIP:DL: Inet Layer shutdown
[1688383461.404573][32968:32968] CHIP:DL: BLE shutdown
[1688383461.404582][32968:32968] CHIP:DL: System Layer shutdown

Bug prevalence

everytime

GitHub hash of the SDK that was being used

6382144

Platform

other

Platform Version(s)

No response

Anything else?

No response

@resghst resghst added bug Something isn't working needs triage labels Jul 3, 2023
bzbarsky-apple added a commit to bzbarsky-apple/connectedhomeip that referenced this issue Jul 6, 2023
We were returning without calling SetCommandExitStatus if removing group keys
_succeeded_, which is backwards.

Fixes project-chip#27600
@mergify mergify bot closed this as completed in #27676 Jul 7, 2023
mergify bot pushed a commit that referenced this issue Jul 7, 2023
We were returning without calling SetCommandExitStatus if removing group keys
_succeeded_, which is backwards.

Fixes #27600
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working needs triage
Projects
None yet
Development

Successfully merging a pull request may close this issue.

1 participant