[SVE2][TC-SC-5.2] chip-tool crashes sending groupcast identify command

[Carpao79]

Problem

By sending a groupcast identify command chip-tool crashes. On TC-SC-5.2 is asked to issue the command ./chip-tool identify identify 0x0078 0xffffffffffff0001 1

Here the log of that command:

ubuntu@ubuntu:~/apps$ ./chip-tool identify identify 0x0078 0xffffffffffff0001 1 [1661871671.365476][4970:4970] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1661871671.371119][4970:4970] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1661871671.371392][4970:4970] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1661871671.371516][4970:4970] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1661871671.371896][4970:4970] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-91drvc) [1661871671.372583][4970:4970] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1661871671.372647][4970:4970] CHIP:DL: NVS set: chip-counters/reboot-count = 115 (0x73) [1661871671.373501][4970:4970] CHIP:DL: Got Ethernet interface: eth0 [1661871671.374069][4970:4970] CHIP:DL: Found the primary Ethernet interface:eth0 [1661871671.374791][4970:4970] CHIP:DL: Got WiFi interface: wlan0 [1661871671.374866][4970:4970] CHIP:DL: Failed to reset WiFi statistic counts [1661871671.374947][4970:4970] CHIP:IN: UDP::Init bind&listen port=0 [1661871671.375061][4970:4970] CHIP:IN: UDP::Init bound to port=42299 [1661871671.375086][4970:4970] CHIP:IN: BLEBase::Init - setting/overriding transport [1661871671.375106][4970:4970] CHIP:IN: TransportMgr initialized [1661871671.375143][4970:4970] CHIP:FP: Initializing FabricTable from persistent storage [1661871671.375286][4970:4970] CHIP:TS: Last Known Good Time: 2022-08-21T03:20:25 [1661871671.376791][4970:4970] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0x85AC7550DBBFE903, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1 [1661871671.378947][4970:4970] CHIP:ZCL: Using ZAP configuration... [1661871671.382739][4970:4970] CHIP:DL: Avahi client registered [1661871671.383864][4970:4970] CHIP:CTL: System State Initialized... [1661871671.383976][4970:4970] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1661871671.384017][4970:4970] CHIP:CTL: Setting attestation nonce to random value [1661871671.384051][4970:4970] CHIP:CTL: Setting CSR nonce to random value [1661871671.384358][4970:4975] CHIP:DL: CHIP task running [1661871671.384555][4970:4975] CHIP:DL: HandlePlatformSpecificBLEEvent 32784 [1661871671.384624][4970:4975] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1661871671.384659][4970:4975] CHIP:CTL: Setting attestation nonce to random value [1661871671.384818][4970:4975] CHIP:CTL: Setting CSR nonce to random value [1661871671.385730][4970:4975] CHIP:CTL: Generating NOC [1661871671.386662][4970:4975] CHIP:FP: Validating NOC chain [1661871671.388239][4970:4975] CHIP:FP: NOC chain validation successful [1661871671.388418][4970:4975] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669 [1661871671.388450][4970:4975] CHIP:TS: Last Known Good Time: 2022-08-21T03:20:25 [1661871671.388470][4970:4975] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1661871671.388488][4970:4975] CHIP:TS: Retaining current Last Known Good Time [1661871671.398479][4970:4975] CHIP:FP: Metadata for Fabric 0x1 persisted to storage. [1661871671.400529][4970:4975] CHIP:TS: Committing Last Known Good Time to storage: 2022-08-21T03:20:25 [1661871671.402495][4970:4975] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x0000000000000000 [1661871671.413436][4970:4975] CHIP:TOO: Sending command to group 0x1 [1661871671.413482][4970:4975] CHIP:TOO: Sending cluster (0x00000003) command (0x00000000) on Group 1 [1661871671.413531][4970:4975] CHIP:DMG: ICR moving to [AddingComm] [1661871671.413558][4970:4975] CHIP:DMG: ICR moving to [AddedComma] [1661871671.414027][4970:4970] CHIP:CTL: Shutting down the commissioner [1661871671.414059][4970:4970] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1661871671.414080][4970:4970] CHIP:CTL: Shutting down the controller [1661871671.414100][4970:4970] CHIP:IN: Expiring all sessions for fabric 0x1!! [1661871671.414216][4970:4970] CHIP:FP: Forgetting fabric 0x1 [1661871671.414246][4970:4970] CHIP:TS: Pending Last Known Good Time: 2022-08-21T03:20:25 [1661871671.414341][4970:4970] CHIP:TS: Previous Last Known Good Time: 2022-08-21T03:20:25 [1661871671.414365][4970:4970] CHIP:TS: Reverted Last Known Good Time to previous value [1661871671.414403][4970:4970] CHIP:CTL: Shutting down the commissioner [1661871671.414422][4970:4970] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1661871671.414442][4970:4970] CHIP:CTL: Shutting down the controller [1661871671.414459][4970:4970] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1661871671.415351][4970:4970] CHIP:DMG: IM WH moving to [Uninitialized] [1661871671.415388][4970:4970] CHIP:DMG: IM WH moving to [Uninitialized] [1661871671.415406][4970:4970] CHIP:DMG: IM WH moving to [Uninitialized] [1661871671.415423][4970:4970] CHIP:DMG: IM WH moving to [Uninitialized] [1661871671.415443][4970:4970] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1661871671.415521][4970:4970] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented. [1661871671.415794][4970:4970] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-WusKLC) [1661871671.416518][4970:4970] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1661871671.416591][4970:4970] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1661871671.416613][4970:4970] CHIP:DL: Inet Layer shutdown [1661871671.416633][4970:4970] CHIP:DL: BLE shutdown [1661871671.416653][4970:4970] CHIP:DL: System Layer shutdown [1661871671.416740][4970:4970] CHIP:SPT: VerifyOrDie failure at ../../src/lib/support/Pool.h:318: Allocated() == 0 Aborted (core dumped)

[bzbarsky-apple]

@Carpao79 What SHA is this on? What exact chip-tool commands were executed prior to this one to set up the group bits?

[Carpao79]

I used chip-tool embedded on TH 2.3 image.

This is the commands sequence:

ubuntu@ubuntu:~/apps$ ./chip-tool pairing code 1 MT:-24J06VO00KA0648G00
ubuntu@ubuntu:~/apps$ ./chip-tool accesscontrol write acl '[{"fabricIndex": 1, "privilege": 5, "authMode": 2, "subjects": [112233], "targets": null },{"fabricIndex": 1, "privilege": 4, "authMode": 3, "subjects": [1], "targets": null }]' 1 0
ubuntu@ubuntu:~/apps$ ./chip-tool groupkeymanagement key-set-write '{"groupKeySetID": 42,"groupKeySecurityPolicy": 0, "epochKey0":"d0d1d2d3d4d5d6d7d8d9dadbdcdddedf", "epochStartTime0": 2220000,"epochKey1":"d1d1d2d3d4d5d6d7d8d9dadbdcdddedf", "epochStartTime1": 2220001,"epochKey2":"d2d1d2d3d4d5d6d7d8d9dadbdcdddedf", "epochStartTime2": 2220002 }' 1 0
ubuntu@ubuntu:~/apps$ ./chip-tool groupkeymanagement write group-key-map '[{"groupId": 1, "groupKeySetID": 42, "fabricIndex": 1}]' 1 0
ubuntu@ubuntu:~/apps$ ./chip-tool groups add-group 0x0001 grp1 1 3
ubuntu@ubuntu:~/apps$ ./chip-tool groups view-group 0x0001 3
ubuntu@ubuntu:~/apps$ ./chip-tool groups view-group 0x0001 1 3
ubuntu@ubuntu:~/apps$ ./chip-tool groupkeymanagement key-set-read 42 1 0
ubuntu@ubuntu:~/apps$ ./chip-tool groupkeymanagement read group-key-map 1 0
ubuntu@ubuntu:~/apps$ ./chip-tool identify identify 0x0078 0xffffffffffff0001 1

[sstruchtrup]

In the steps for TC-SC-5.1, there is some confusion between the decimal 42 and hexadecimal 0x42.

I can reproduce the above behavior if I do a

# chip-tool groupsettings add-keysets 0x42 0 0x000000000021dfe0 hex:d0d1d2d3d4d5d6d7d8d9dadbdcdddedf

with a hexadecimal 0x42 while using the decimal 42 elsewhere.

If using the decimal 42 everywhere, it will send the groupcast and terminate cleanly.

[Carpao79]

I was basically skipping TC-SC-5.1 step 9.

I can confirm tha using decimal 42 everything goes fine.

[andy31415]

Removed cert blocker: it looks like hex vs decimal argument.

Fixing a crash is fine as it will affect /examples only, however this will not block 1.0

[bzbarsky-apple]

This is the commands sequence:

@Carpao79 That's missing the "keysettings" command that's key to this whole issue, right? Can you please list the exact full set of commands used?

Fwiw, I tried running:

./chip-tool groupsettings add-keysets 0x42 0 0x000000000021dfe0 hex:d0d1d2d3d4d5d6d7d8d9dadbdcdddedf

./chip-tool groupsettings add-group "abc" 0x0001  

./chip-tool groupsettings bind-keyset 0x0001 42 

before the commands above, and I do not see a crash....

[Carpao79]

@franck-apple I confirm that I was missing the "keysettings" commands. As I wrote in my previous comment skipped step 9 on TC-SC-5.1 that is necessary for TC-SC-5.2. This is the commands sequence I sent:

ubuntu@ubuntu:~/apps$ ./chip-tool pairing code 1 MT:-24J06VO00KA0648G00
ubuntu@ubuntu:~/apps$ ./chip-tool accesscontrol write acl '[{"fabricIndex": 1, "privilege": 5, "authMode": 2, "subjects": [112233], "targets": null },{"fabricIndex": 1, "privilege": 4, "authMode": 3, "subjects": [1], "targets": null }]' 1 0
ubuntu@ubuntu:~/apps$ ./chip-tool groupkeymanagement key-set-write '{"groupKeySetID": 42,"groupKeySecurityPolicy": 0, "epochKey0":"d0d1d2d3d4d5d6d7d8d9dadbdcdddedf", "epochStartTime0": 2220000,"epochKey1":"d1d1d2d3d4d5d6d7d8d9dadbdcdddedf", "epochStartTime1": 2220001,"epochKey2":"d2d1d2d3d4d5d6d7d8d9dadbdcdddedf", "epochStartTime2": 2220002 }' 1 0
ubuntu@ubuntu:~/apps$ ./chip-tool groupkeymanagement write group-key-map '[{"groupId": 1, "groupKeySetID": 42, "fabricIndex": 1}]' 1 0
ubuntu@ubuntu:~/apps$ ./chip-tool groups add-group 0x0001 grp1 1 3
ubuntu@ubuntu:~/apps$ ./chip-tool groups view-group 0x0001 3
ubuntu@ubuntu:~/apps$ ./chip-tool groups view-group 0x0001 1 3
ubuntu@ubuntu:~/apps$ ./chip-tool groupkeymanagement key-set-read 42 1 0
ubuntu@ubuntu:~/apps$ ./chip-tool groupkeymanagement read group-key-map 1 0
ubuntu@ubuntu:~/apps$ ./chip-tool identify identify 0x0078 0xffffffffffff0001 1

[bzbarsky-apple]

@Carpao79 I don't get a crash (on tip) when I run those commands, at least on Mac.... What exact SHA is involved here?

[stale[bot]]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs.

[stale[bot]]

This stale issue has been automatically closed. Thank you for your contributions.