[BUG] chip-all-clusters-app in thread mode can not commissioned

[tianfeng-yang]

Reproduction steps

PreCondition:

1. Insert an external Bluetooth adapter into the Raspberry Pi 4B.
2. Insert SiLabs RCP into the Raspberry Pi 4B.

Steps:

1. start OTBR

ubuntu@ubuntu:~/chip-certification-tool/scripts/OTBR$ ./otbr_start.sh
connectedhomeip/otbr             sve2                                       cd81003a4ffe   10 months ago   436MB
otbr image connectedhomeip/otbr:sve2 already installed
a586eb9058005181cf90e88c6c71c8c78393d4693b15985ee2bacfcd035545fa
waiting 10 seconds to give the the docker container enough time to start up...
Param: 'dataset init new'
Done
Param: 'dataset channel 25'
Done
Param: 'dataset panid 0x5b35'
Done
Param: 'dataset extpanid 5b35dead5b35beef'
Done
Param: 'dataset networkname 5b35'
Done
Param: 'dataset networkkey 00112233445566778899aabbccddeeff'
Done
Param: 'dataset commit active'
Done
Param: 'prefix add fd11:35::/64 pasor'
Done
Param: 'ifconfig up'
Done
Param: 'thread start'
Done
Param: 'netdata register'
Done
Param: 'dataset active -x'
0e080000000000010000000300001935060004001fffe002085b35dead5b35beef0708fd1dc324dec8779d051000112233445566778899aabbccddeeff03043562333501025b3504108b930382a737b00cdd648e3ab3ee2e190c0402a0f7f8
Done
Simple Dataset:  000300001902085b35dead5b35beef051000112233445566778899aabbccddeeff01025b35

3. Open chip-all-clusters-app (using hci0)

ubuntu@ubuntu:~/apps$ rm -rf /tmp/chip_* && ./chip-all-clusters-app --thread --ble-device 0
......
[1686819634.447347][9051:9051] CHIP:DMG: AccessControl: checking f=1 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0031 e=0 p=a
[1686819634.447397][9051:9051] CHIP:DMG: AccessControl: implicit admin (PASE)
[1686819634.447444][9051:9051] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0006
[1686819634.450525][9051:9051] CHIP:DL: openthread: _SetThreadEnabled calling Reset failed: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name io.openthread.BorderRouter.wpan0 was not provided by any .service files
[1686819634.450633][9051:9051] CHIP:DMG: Command handler moving to [ Preparing]
[1686819634.450687][9051:9051] CHIP:DMG: Command handler moving to [AddingComm]
[1686819634.450737][9051:9051] CHIP:DMG: Command handler moving to [AddedComma]
[1686819634.450776][9051:9051] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 1
[1686819634.450862][9051:9051] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0
[1686819634.451019][9051:9051] CHIP:EM: <<< [E:8470r S:24294 M:197402433] (S) Msg TX to 1:FFFFFFFB00000000 [2A1E] --- Type 0001:09 (IM:InvokeCommandResponse)
[1686819634.451143][9051:9051] CHIP:IN: (S) Sending msg 197402433 on secure session with LSID: 24294
[1686819634.451566][9051:9051] CHIP:DMG: Command handler moving to [CommandSen]
[1686819634.451618][9051:9051] CHIP:DMG: Command handler moving to [AwaitingDe]
[1686819634.543946][9051:9052] CHIP:BLE: Indication confirmation, 0xffff8c057510
[1686819637.196990][9051:9052] CHIP:DL: Bluez disconnected
[1686819637.197079][9051:9052] CHIP:DL: Bluez notify CHIPoBluez connection disconnected

4. Commission with chip-tool (using hci1)

ubuntu@ubuntu:~/apps$ ./chip-tool pairing ble-thread 1 hex:0e080000000000010000000300001935060004001fffe002085b35dead5b35beef0708fd1dc324dec8779d051000112233445566778899aabbccddeeff03043562333501025b3504108b930382a737b00cdd648e3ab3ee2e190c0402a0f7f8 20202021 3840 --ble-adapter 1
......
[1686819634.506231][9056:9058] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0007
[1686819634.506369][9056:9058] CHIP:CTL: Received ConnectNetwork response, networkingStatus=12
[1686819634.506430][9056:9058] CHIP:CTL: Error on commissioning step 'ThreadNetworkEnable': 'src/controller/CHIPDeviceController.cpp:2175: CHIP Error 0x000000AC: Internal error'
[1686819634.506466][9056:9058] CHIP:CTL: Failed to perform commissioning step 19
[1686819634.506508][9056:9058] CHIP:CTL: Going from commissioning step 'ThreadNetworkEnable' with lastErr = 'src/controller/CHIPDeviceController.cpp:2175: CHIP Error 0x000000AC: Internal error' -> 'Cleanup'
[1686819634.506557][9056:9058] CHIP:CTL: Performing next commissioning step 'Cleanup' with completion status = 'src/controller/CHIPDeviceController.cpp:2175: CHIP Error 0x000000AC: Internal error'
[1686819634.506596][9056:9058] CHIP:CTL: Successfully finished commissioning step 'Cleanup'
[1686819634.506643][9056:9058] CHIP:TOO: Device commissioning Failure: src/controller/CHIPDeviceController.cpp:2175: CHIP Error 0x000000AC: Internal error

Bug prevalence

every time

GitHub hash of the SDK that was being used

origin/release/2.9-TE1

Platform

raspi

Platform Version(s)

No response

Anything else?

No response

[bzbarsky-apple]

[1686819634.506369][9056:9058] CHIP:CTL: Received ConnectNetwork response, networkingStatus=12

Well, why did it fail to join the Thread network? What does the server-side log around this part look like?

[tianfeng-yang]

Well, why did it fail to join the Thread network? What does the server-side log around this part look like?

I may not have found the right way to use it. Does chip-all-cluster-app also need to rely on an additional hardware peripheral (support thread)?

[1686819634.450525][9051:9051] CHIP:DL: openthread: _SetThreadEnabled calling Reset failed: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name io.openthread.BorderRouter.wpan0 was not provided by any .service files

[bzbarsky-apple]

Does chip-all-cluster-app also need to rely on an additional hardware peripheral

I don't know.

[MonicaisHer]

I encounter a similar issue when running the chip-lighting-app in Thread mode; it cannot be commissioned due to a similar DBus-related error:

CHIP:DL: openthread: failed to read DeviceRole property: GDBus.Error:org.freedesktop.DBus.Error.NoReply: Message recipient disconnected from message bus without replying