[BUG] chip-tool Segmentation fault

[lbuque]

Reproduction steps

1. source scripts/bootstrap.sh
2. source ./scripts/activate.sh
3. cd examples/chip-tool/
4. gn gen out
5. ninja -C out
6. cd out/
7. ./chip-tool pairing ble-wifi 0x7283  GL-MT1300-44e 88888888 20202021 3840

Are my steps to run chip-tool correct, and if not, what should I do?

Bug prevalence

must appear

GitHub hash of the SDK that was being used

9a41c9c

Platform

other

Platform Version(s)

mint linux 20

Anything else?

[1669284666.196442][187164:187164] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1669284666.196504][187164:187164] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1669284666.196517][187164:187164] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1669284666.196525][187164:187164] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1669284666.196567][187164:187164] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-0udutD)
[1669284666.196634][187164:187164] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1669284666.196639][187164:187164] CHIP:DL: NVS set: chip-counters/reboot-count = 4 (0x4)
[1669284666.196754][187164:187164] CHIP:DL: Got Ethernet interface: enp2s0
[1669284666.196845][187164:187164] CHIP:DL: Found the primary Ethernet interface:enp2s0
[1669284666.196935][187164:187164] CHIP:DL: Got WiFi interface: wlo1
[1669284666.198344][187164:187164] CHIP:DL: Found the primary WiFi interface:wlo1
[1669284666.198357][187164:187164] CHIP:IN: UDP::Init bind&listen port=0
[1669284666.198367][187164:187164] CHIP:IN: UDP::Init bound to port=39339
[1669284666.198370][187164:187164] CHIP:IN: UDP::Init bind&listen port=0
[1669284666.198376][187164:187164] CHIP:IN: UDP::Init bound to port=60141
[1669284666.198378][187164:187164] CHIP:IN: BLEBase::Init - setting/overriding transport
[1669284666.198380][187164:187164] CHIP:IN: TransportMgr initialized
[1669284666.198385][187164:187164] CHIP:FP: Initializing FabricTable from persistent storage
[1669284666.198405][187164:187164] CHIP:TS: Last Known Good Time: 2022-11-24T18:02:01
[1669284666.198485][187164:187164] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0xCA80C6A7EA0F05FD, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1669284666.198644][187164:187164] CHIP:ZCL: Using ZAP configuration...
[1669284666.199020][187164:187164] CHIP:CTL: System State Initialized...
[1669284666.199029][187164:187164] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1669284666.199038][187164:187164] CHIP:CTL: Setting attestation nonce to random value
[1669284666.199042][187164:187164] CHIP:CTL: Setting CSR nonce to random value
[1669284666.199050][187164:187164] CHIP:IN: UDP::Init bind&listen port=5550
[1669284666.199055][187164:187164] CHIP:IN: UDP::Init bound to port=5550
[1669284666.199057][187164:187164] CHIP:IN: UDP::Init bind&listen port=5550
[1669284666.199062][187164:187164] CHIP:IN: UDP::Init bound to port=5550
[1669284666.199064][187164:187164] CHIP:IN: TransportMgr initialized
[1669284666.199089][187164:187166] CHIP:DL: CHIP task running
[1669284666.199144][187164:187166] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1669284666.199151][187164:187166] CHIP:CTL: Setting attestation nonce to random value
[1669284666.199160][187164:187166] CHIP:CTL: Setting CSR nonce to random value
[1669284666.199657][187164:187166] CHIP:CTL: Generating NOC
[1669284666.199803][187164:187166] CHIP:FP: Validating NOC chain
[1669284666.200088][187164:187166] CHIP:FP: NOC chain validation successful
[1669284666.200116][187164:187166] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1669284666.200119][187164:187166] CHIP:TS: Last Known Good Time: 2022-11-24T18:02:01
[1669284666.200123][187164:187166] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
[1669284666.200125][187164:187166] CHIP:TS: Retaining current Last Known Good Time
[1669284666.200281][187164:187166] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
[1669284666.200411][187164:187166] CHIP:TS: Committing Last Known Good Time to storage: 2022-11-24T18:02:01
[1669284666.200527][187164:187166] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: CA80C6A7EA0F05FD)
[1669284666.200535][187164:187166] CHIP:IN: UDP::Init bind&listen port=5550
[1669284666.200544][187164:187166] CHIP:IN: UDP::Init bound to port=5550
[1669284666.200546][187164:187166] CHIP:IN: UDP::Init bind&listen port=5550
[1669284666.200551][187164:187166] CHIP:IN: UDP::Init bound to port=5550
[1669284666.200553][187164:187166] CHIP:IN: TransportMgr initialized
[1669284666.201360][187164:187166] CHIP:IN: SecureSession[0x7f1934021850]: Allocated Type:1 LSID:60275
[1669284666.201366][187164:187166] CHIP:SC: Assigned local session key ID 60275
[1669284666.201378][187164:187166] CHIP:EM: <<< [E:34443i M:255561211] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest)
[1669284666.201384][187164:187166] CHIP:IN: (U) Sending msg 255561211 to IP address 'BLE'
[1669284666.201387][187164:187166] CHIP:IN: Message appended to BLE send queue
[1669284666.201390][187164:187166] CHIP:SC: Sent PBKDF param request
[1669284666.201393][187164:187166] CHIP:CTL: Setting wifi credentials from parameters
[1669284666.201395][187164:187166] CHIP:CTL: Setting attestation nonce to random value
[1669284666.201398][187164:187166] CHIP:CTL: Setting CSR nonce to random value
[1669284666.201401][187164:187166] CHIP:CTL: Commission called for node ID 0x0000000000007283
[1669284666.202084][187164:187165] CHIP:DL: TRACE: Bus acquired for name C-db1c
[1669284666.202989][187164:187166] CHIP:DL: PlatformBlueZInit init success
[1669284666.203664][187164:187165] CHIP:BLE: BLE removing known devices.
[1669284666.203879][187164:187165] CHIP:BLE: BLE initiating scan.
[1669284666.320711][187164:187166] CHIP:DL: Long dispatch time: 120 ms, for event type 2
[1669284666.503484][187164:187165] CHIP:BLE: Device 6F:C6:1D:88:17:CF does not look like a CHIP device.
[1669284666.503993][187164:187165] CHIP:BLE: Device D5:56:7A:A4:65:7E does not look like a CHIP device.
[1669284666.701980][187164:187165] CHIP:BLE: Device F8:AF:05:1B:7A:94 does not look like a CHIP device.
[1669284666.702427][187164:187165] CHIP:BLE: Device 64:90:C1:79:4E:20 does not look like a CHIP device.
[1669284666.727725][187164:187165] CHIP:BLE: Device A4:C1:38:35:8A:0D does not look like a CHIP device.
[1669284666.769143][187164:187165] CHIP:BLE: Device 6F:C6:1D:88:17:CF does not look like a CHIP device.
[1669284667.045428][187164:187165] CHIP:BLE: Device 6F:C6:1D:88:17:CF does not look like a CHIP device.
[1669284667.178262][187164:187165] CHIP:BLE: Device F8:AF:05:1B:7A:94 does not look like a CHIP device.
[1669284667.181176][187164:187165] CHIP:BLE: Device 3F:59:C8:82:A8:1E does not look like a CHIP device.
[1669284667.321148][187164:187165] CHIP:BLE: Device 6F:C6:1D:88:17:CF does not look like a CHIP device.
[1669284667.542213][187164:187165] CHIP:BLE: Device F8:AF:05:1B:7A:94 does not look like a CHIP device.
[1669284667.770791][187164:187165] CHIP:BLE: Device C5:48:9A:8E:23:C6 does not look like a CHIP device.
[1669284667.787736][187164:187165] CHIP:BLE: Device EA:3B:F8:99:CB:CA does not look like a CHIP device.
[1669284667.870142][187164:187165] CHIP:BLE: Device 6F:C6:1D:88:17:CF does not look like a CHIP device.
[1669284668.012260][187164:187165] CHIP:BLE: Device F8:AF:05:1B:7A:94 does not look like a CHIP device.
[1669284668.145189][187164:187165] CHIP:BLE: Device 6F:C6:1D:88:17:CF does not look like a CHIP device.
[1669284668.185395][187164:187165] CHIP:BLE: Device 3F:59:C8:82:A8:1E does not look like a CHIP device.
[1669284668.202689][187164:187166] CHIP:SC: PASESession timed out while waiting for a response from the peer. Expected message type was 33
[1669284668.202717][187164:187166] CHIP:IN: SecureSession[0x7f1934021850]: Released - Type:1 LSID:60275
[1669284668.202731][187164:187166] CHIP:TOO: Secure Pairing Failed
[1669284668.202747][187164:187166] CHIP:DIS: Closing all BLE connections
[1669284668.202769][187164:187166] CHIP:TOO: Pairing Failure: ../third_party/connectedhomeip/src/protocols/secure_channel/PASESession.cpp:254: CHIP Error 0x00000032: Timeout
[1669284668.202892][187164:187164] CHIP:CTL: Shutting down the commissioner
[1669284668.202912][187164:187164] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1669284668.202956][187164:187164] CHIP:CTL: Shutting down the controller
[1669284668.202967][187164:187164] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1669284668.202976][187164:187164] CHIP:FP: Forgetting fabric 0x1
[1669284668.202992][187164:187164] CHIP:TS: Pending Last Known Good Time: 2022-11-24T18:02:01
[1669284668.203071][187164:187164] CHIP:TS: Previous Last Known Good Time: 2022-11-24T18:02:01
[1669284668.203079][187164:187164] CHIP:TS: Reverted Last Known Good Time to previous value
[1669284668.203102][187164:187164] CHIP:CTL: Shutting down the commissioner
[1669284668.203109][187164:187164] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1669284668.203128][187164:187164] CHIP:CTL: Shutting down the controller
[1669284668.203136][187164:187164] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1669284668.203223][187164:187164] CHIP:DMG: IM WH moving to [Uninitialized]
[1669284668.203231][187164:187164] CHIP:DMG: IM WH moving to [Uninitialized]
[1669284668.203238][187164:187164] CHIP:DMG: IM WH moving to [Uninitialized]
[1669284668.203244][187164:187164] CHIP:DMG: IM WH moving to [Uninitialized]
[1669284668.203249][187164:187164] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1669284668.203273][187164:187164] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.
[1669284668.203290][187164:187164] CHIP:FP: Shutting down FabricTable
[1669284668.203300][187164:187164] CHIP:TS: Pending Last Known Good Time: 2022-11-24T18:02:01
[1669284668.203342][187164:187164] CHIP:TS: Previous Last Known Good Time: 2022-11-24T18:02:01
[1669284668.203349][187164:187164] CHIP:TS: Reverted Last Known Good Time to previous value
[1669284668.203449][187164:187164] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-fr0QoH)
[1669284668.203644][187164:187164] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1669284668.203664][187164:187164] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1669284668.203674][187164:187164] CHIP:DL: Inet Layer shutdown
[1669284668.203681][187164:187164] CHIP:DL: BLE shutdown
Segmentation fault (core dumped)

[bzbarsky-apple]

It looks like there was no device with discriminator 3840 around, so the BLE discovery failed.

You should try running under a debugger to see why that leads to a crash during shutdown, but presumably we are shutting down while there is BLE stuff still going on or something like that....

[smishra-volansys]

I am also facing the same issue but instead of Chip-tool my Lighting app is crashing during the BLE commissioning, I am providing the SSID and PSK from the chip tool command which is thrown on another device, and the LinuxNetworkCommissioningDelegate prints the string of SSID and then crashes on the other device.

I am using the same commands as given in the README files.

[bzbarsky-apple]

That sounds like a very different issue. @sid514-m I filed #24271 on that.

[stale]

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]

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