Problem with otbr-agent status. Init() at spinel_driver.cpp:82: Failure.

[cvfabian]

Hi,

I've come across with a problem regarding the connection of my nRF52840-DK board to my Raspberry Pi 4B to start the otbr-agent service. I followed the instructions indicated here: https://openthread.io/codelabs/openthread-border-router#1, but to no avail.

Are there any solutions to this? I can't run the succeeding commands, e.g., "sudo ot-ctl dataset init new".

Thanks!

[superwhd]

Have you flashed the latest ot-rcp firmware for your nRF52840-DK? I think it may be an incompatibility between the host and the RCP.

cc @zhanglongxia @Irving-cl

[cvfabian]

Yes, I followed the same steps here in flashing the device. Is there a much newer version than this?

Thanks!

[zhanglongxia]

Could you provide logs of the otbr-agent? You can see the log via tail -f /var/log/syslog | grep otbr.

[scratchclaggy]

I'm getting the same error message, looking at the line the error message is referencing my best guess is there's a version mismatch between the border router and the RCP?

[scratchclaggy]

Here are the logs too:

Aug 05 21:15:47 apollo otbr-agent[2373]: [NOTE]-AGENT---: Thread interface: wpan0
Aug 05 21:15:47 apollo otbr-agent[2373]: [NOTE]-AGENT---: Radio URL: spinel+hdlc+uart:///dev/ttyACM0
Aug 05 21:15:47 apollo otbr-agent[2373]: [NOTE]-AGENT---: Radio URL: trel://eth0
Aug 05 21:15:47 apollo otbr-agent[2373]: [NOTE]-ILS-----: Infra link selected: eth0
Aug 05 21:15:47 apollo otbr-agent[2373]: [INFO]-RCP_HOS-: OpenThread log level changed to 4
Aug 05 21:15:49 apollo otbr-agent[2373]: 49d.17:06:09.397 [W] P-SpinelDrive-: Wait for response timeout
Aug 05 21:15:49 apollo otbr-agent[2373]: 49d.17:06:09.397 [I] P-SpinelDrive-: co-processor self reset successfully
Aug 05 21:15:51 apollo otbr-agent[2373]: 49d.17:06:11.399 [W] P-SpinelDrive-: Wait for response timeout
Aug 05 21:15:53 apollo otbr-agent[2373]: 49d.17:06:13.401 [W] P-SpinelDrive-: Wait for response timeout
Aug 05 21:15:53 apollo otbr-agent[2373]: 49d.17:06:13.401 [C] Platform------: Init() at spinel_driver.cpp:82: Failure

[tdzt]

Hello,
Seems to be the same issue for us.

Here is our setup :

• Sonoff ZBDongle-E (OpenThread (RCP) SL-OPENTHREAD/2.4.3.0_GitHub-7074a43e4)
  • Linked on /dev/ttyACM1 on host and on container
• Latest docker image for otb (updated 3 days ago on Docker Hub)

ot-agent are crashing and daemon isn't running.

Logs :

Aug  5 20:48:22 2a45fc7d7e9e mDNSResponder: Default: mDNSResponder (Engineering Build) (Aug  2 2024 16:28:17) starting
Aug  5 20:48:23 2a45fc7d7e9e rsyslogd: rsyslogd's groupid changed to 101
Aug  5 20:48:23 2a45fc7d7e9e rsyslogd: rsyslogd's userid changed to 101
Aug  5 20:48:23 2a45fc7d7e9e rsyslogd:  [origin software="rsyslogd" swVersion="8.32.0" x-pid="98" x-info="http://www.rsyslog.com"] start
Aug  5 20:48:24 2a45fc7d7e9e otbr-web[172]: [INFO]-WEB-----: Running 0.3.0-da1f867
Aug  5 20:48:24 2a45fc7d7e9e otbr-web[172]: [INFO]-WEB-----: Border router web started on wpan0
Aug  5 20:48:24 2a45fc7d7e9e otbr-web[172]: [ERR ]-WEB-----: OpenThread daemon is not running.
Aug  5 20:48:24 2a45fc7d7e9e otbr-agent: [NOTE]-AGENT---: Backbone interface: eth0
Aug  5 20:48:24 2a45fc7d7e9e otbr-agent[199]: [NOTE]-AGENT---: Running 0.3.0-da1f867
Aug  5 20:48:24 2a45fc7d7e9e otbr-agent[199]: [NOTE]-AGENT---: Thread version: 1.3.0
Aug  5 20:48:24 2a45fc7d7e9e otbr-agent[199]: [NOTE]-AGENT---: Thread interface: wpan0
Aug  5 20:48:24 2a45fc7d7e9e otbr-agent[199]: [NOTE]-AGENT---: Radio URL: spinel+hdlc+uart:///dev/ttyACM1
Aug  5 20:48:24 2a45fc7d7e9e otbr-agent[199]: [NOTE]-ILS-----: Infra link selected: eth0
Aug  5 20:48:24 2a45fc7d7e9e otbr-agent[199]: [INFO]-RCP_HOS-: OpenThread log level changed to 5
Aug  5 20:48:24 2a45fc7d7e9e otbr-agent[199]: 58d.21:22:42.935 [D] P-SpinelDrive-: Sent spinel frame, flg:0x2, iid:0, tid:0, cmd:RESET
Aug  5 20:48:24 2a45fc7d7e9e otbr-agent[199]: 58d.21:22:42.935 [D] P-SpinelDrive-: Waiting response: key=0
Aug  5 20:48:26 2a45fc7d7e9e otbr-agent[199]: 58d.21:22:44.937 [W] P-SpinelDrive-: Wait for response timeout
Aug  5 20:48:26 2a45fc7d7e9e otbr-agent[199]: 58d.21:22:44.937 [I] P-SpinelDrive-: co-processor self reset successfully
Aug  5 20:48:26 2a45fc7d7e9e otbr-agent[199]: 58d.21:22:44.937 [D] P-SpinelDrive-: Sent spinel frame, flg:0x2, iid:0, tid:1, cmd:PROP_VALUE_GET, key:PROTOCOL_VERSION
Aug  5 20:48:26 2a45fc7d7e9e otbr-agent[199]: 58d.21:22:44.938 [D] P-SpinelDrive-: Waiting response: key=1
Aug  5 20:48:28 2a45fc7d7e9e otbr-agent[199]: 58d.21:22:46.940 [W] P-SpinelDrive-: Wait for response timeout
Aug  5 20:48:28 2a45fc7d7e9e otbr-agent[199]: 58d.21:22:46.940 [D] P-SpinelDrive-: Sent spinel frame, flg:0x2, iid:0, tid:1, cmd:PROP_VALUE_GET, key:PROTOCOL_VERSION
Aug  5 20:48:28 2a45fc7d7e9e otbr-agent[199]: 58d.21:22:46.940 [D] P-SpinelDrive-: Waiting response: key=1
Aug  5 20:48:30 2a45fc7d7e9e otbr-agent[199]: 58d.21:22:48.942 [W] P-SpinelDrive-: Wait for response timeout
Aug  5 20:48:30 2a45fc7d7e9e otbr-agent[199]: 58d.21:22:48.942 [C] Platform------: Init() at spinel_driver.cpp:82: Failure
Aug  5 20:48:30 2a45fc7d7e9e otbr-agent[199]: 58d.21:22:48.943 [D] P-SpinelDrive-: Sent spinel frame, flg:0x2, iid:0, tid:1, cmd:PROP_VALUE_GET, key:PROTOCOL_VERSION
Aug  5 20:48:30 2a45fc7d7e9e otbr-agent[199]: 58d.21:22:48.943 [D] P-SpinelDrive-: Waiting response: key=1
Aug  5 20:48:32 2a45fc7d7e9e otbr-agent[199]: 58d.21:22:50.945 [W] P-SpinelDrive-: Wait for response timeout

[lukeotto]

I do have the same problem while using a ESP32-C6 with the most recent rcp image connected via USB
ot_rcp

2024-08-05T22:33:06.572147+01:00 otbr2 otbr-agent: [NOTE]-AGENT---: Backbone interface: wlan0
2024-08-05T22:33:06.572485+01:00 otbr2 otbr-agent[9110]: [NOTE]-AGENT---: Running 0.3.0-thread-reference-20230710-339-gda1f867030
2024-08-05T22:33:06.572623+01:00 otbr2 otbr-agent[9110]: [NOTE]-AGENT---: Thread version: 1.3.0
2024-08-05T22:33:06.572718+01:00 otbr2 otbr-agent[9110]: [NOTE]-AGENT---: Thread interface: wpan0
2024-08-05T22:33:06.572795+01:00 otbr2 otbr-agent[9110]: [NOTE]-AGENT---: Radio URL: spinel+hdlc+uart:///dev/ttyACM0?uart-baudrate=460800
2024-08-05T22:33:06.572877+01:00 otbr2 otbr-agent[9110]: [NOTE]-AGENT---: Radio URL: trel://wlan0
2024-08-05T22:33:06.572948+01:00 otbr2 otbr-agent[9110]: [NOTE]-ILS-----: Infra link selected: wlan0
2024-08-05T22:33:06.573046+01:00 otbr2 otbr-agent[9110]: [INFO]-RCP_HOS-: OpenThread log level changed to 4
2024-08-05T22:33:08.576571+01:00 otbr2 otbr-agent[9110]: 49d.19:00:21.954 [W] P-SpinelDrive-: Wait for response timeout
2024-08-05T22:33:08.576760+01:00 otbr2 otbr-agent[9110]: 49d.19:00:21.954 [I] P-SpinelDrive-: co-processor self reset successfully
2024-08-05T22:33:10.578648+01:00 otbr2 otbr-agent[9110]: 49d.19:00:23.956 [W] P-SpinelDrive-: Wait for response timeout
2024-08-05T22:33:12.581322+01:00 otbr2 otbr-agent[9110]: 49d.19:00:25.958 [W] P-SpinelDrive-: Wait for response timeout
2024-08-05T22:33:12.581681+01:00 otbr2 otbr-agent[9110]: 49d.19:00:25.958 [C] Platform------: Init() at spinel_driver.cpp:82: Failure
2024-08-05T22:33:14.583655+01:00 otbr2 otbr-agent[9110]: 49d.19:00:27.960 [W] P-SpinelDrive-: Wait for response timeout

[ihidchaos]

Perhaps you can refer to this link to try adding flow control parameters.

[scratchclaggy]

@ihidchaos Thanks, I can confirm that this works! TLDR: edit /etc/default/otbr so that it includes the following or similar:

OTBR_AGENT_OPTS="-I wpan0 -B eth0 spinel+hdlc+uart:///dev/ttyACM0?uart-flow-control trel://eth0"

[StrippgenHTW]

I cannot bring it to work with a Sonoff ZBDongle-E, too?
Log: with an error on spinel_driver.cpp:83(!)

2024-12-09T18:42:54.433987+01:00 dspi otbr-agent[29507]: 49d.17:58:08.106 [I] P-SpinelDrive-: co-processor self reset successfully
2024-12-09T18:42:56.436555+01:00 dspi otbr-agent[29507]: 49d.17:58:10.108 [W] P-SpinelDrive-: Wait for response timeout
2024-12-09T18:42:58.438888+01:00 dspi otbr-agent[29507]: 49d.17:58:12.110 [W] P-SpinelDrive-: Wait for response timeout
2024-12-09T18:42:58.439326+01:00 dspi otbr-agent[29507]: 49d.17:58:12.110 [C] Platform------: Init() at spinel_driver.cpp:83: Failure
2024-12-09T18:43:00.440255+01:00 dspi otbr-agent[29507]: 49d.17:58:14.112 [W] P-SpinelDrive-: Wait for response timeout
2024-12-09T18:43:01.184773+01:00 dspi systemd[1]: otbr-agent.service: Main process exited, code=exited, status=1/FAILURE

On a raspi 4. Adding the ?uart-flow-control did not make any change.
Does anybody know a solution, or is the (newer) Sonoff ZBDongle-E not usable with otbr?
Thanks and greetings!

[Mrz-creator]

I had the same problem when updating to GSDK4.4.5 using multi-protocol firmware.
For multi-protocol, the "adding flow control parameters" method has no effect.

• ubuntu@ubuntu:~$ sudo otbr-agent -I wpan0 -B eth0 "spinel+cpc://cpcd_0?iid=2&iid-list=0" -v
• otbr-agent[1634]: [NOTE]-AGENT---: Running 0.3.0-bff5d377-dirty
• otbr-agent[1634]: [NOTE]-AGENT---: Thread version: 1.4.0
• otbr-agent[1634]: [NOTE]-AGENT---: Thread interface: wpan0
• otbr-agent[1634]: [NOTE]-AGENT---: Radio URL: spinel+cpc://cpcd_0?iid=2&iid-list=0
• otbr-agent[1634]: [NOTE]-ILS-----: Infra link selected: eth0
• otbr-agent[1634]: [INFO]-RCP_HOS-: OpenThread log level changed to 4
• otbr-agent[1634]: 49d.17:16:59.025 [W] P-SpinelDrive-: Wait for response timeout
• otbr-agent[1634]: 49d.17:16:59.025 [I] P-SpinelDrive-: co-processor self reset successfully
• otbr-agent[1634]: 49d.17:17:01.026 [W] P-SpinelDrive-: Wait for response timeout
• otbr-agent[1634]: 49d.17:17:03.026 [W] P-SpinelDrive-: Wait for response timeout
• otbr-agent[1634]: 49d.17:17:03.026 [C] Platform------: Init() at spinel_driver.cpp:82: Failure
• otbr-agent[1634]: 49d.17:17:05.026 [W] P-SpinelDrive-: Wait for response timeout
• ubuntu@ubuntu:~$

[StrippgenHTW]

@Mrz-creator : I could get it to work, after I inserted both parameters, the "flow control" and the correct "baudrate"!

OTBR_AGENT_OPTS="-I wpan0 -B wlan0 spinel+hdlc+uart:///dev/ttyUSB0?uart-flow-control&uart-baudrate=460800 trel://wlan0"
OTBR_NO_AUTO_ATTACH=0

Sorry... It only worked with leaving out the uart-flow-control for the sonoff! And I used eth0 so:
OTBR_AGENT_OPTS="-I wpan0 -B eth0 spinel+hdlc+uart:///dev/ttyUSB0?uart-baudrate=460800 trel://eth0"
OTBR_NO_AUTO_ATTACH=0

[Mrz-creator]

@StrippgenHTW Thank you for your reply, but I am using multi-protocol mode and do not have uart. I am using cpcd. My configuration must be changed to the following：
-I wpan0 -B eth0 spinel+cpc://cpcd_0?iid=2&iid-list=0

[ihidchaos]

@StrippgenHTW Thank you for your reply, but I am using multi-protocol mode and do not have uart. I am using cpcd. My configuration must be changed to the following： -I wpan0 -B eth0 spinel+cpc://cpcd_0?iid=2&iid-list=0

Silabs' cpcd program also has a cpcd.conf configuration file to set up flow control, perhaps you can refer to this file to modify your device's parameters. https://github.com/SiliconLabs/cpc-daemon/blob/main/cpcd.conf#L42

Instead of modifying /etc/default/otbr, I meant modifying /somepath/cpcd.conf.

[Mrz-creator]

@ihidchaos Thanks for your answer，I tried single protocol thread RCP with success. I want multi-protocol to work too, I modified cpcd.conf as you said and configured the firmware to support flow control, but the result is still frustrating.