Communication between RCP and OTBR over SPI fails

[chenyixi1997]

Hello~ I’m having an issue.
I am using this codebase: https://github.com/openthread/ot-nrf528xx to test the connection between the RCP and the OTBR.
According to the README, I used ./script/build nrf52840 USB_trans to build the RCP firmware and flashed it to the nrf52840. This process went smoothly and I could connect to the OTBR, input commands, and create the first Thread node.

Then I wanted to use SPI to communicate with the Raspberry Pi. I used ./script/build nrf52840 SPI_trans_NCP to rebuild the firmware, reflashed it, and connected it to the Raspberry Pi. However, I found that I couldn't input commands. Sometimes, I would see the following log messages:

● otbr-agent.service - OpenThread Border Router Agent
Loaded: loaded (/lib/systemd/system/otbr-agent.service; enabled; preset: enabled)
Active: active (running) since Mon 2025-05-26 06:46:20 BST; 705ms ago
Process: 690205 ExecStartPre=/usr/sbin/service mdns start (code=exited, status=0/SUCCESS)
Main PID: 690215 (otbr-agent)
Tasks: 1 (limit: 3909)
CPU: 44ms
CGroup: /system.slice/otbr-agent.service
└─690215 /usr/sbin/otbr-agent -I wpan0 -B wlan0 "spinel+spi:///dev/spidev0.0?gpio-int-device=/dev/gpiochip0&gpio-int-line=21&gpio-reset-device=/dev/gpiochip0&gpio-reset-line=20&no-reset=1&spispeed=1000000" trel://w>

May 26 06:46:21 cyx otbr-agent[690215]: 63d.21:05:25.800 [W] P-SpiIntface--: Garbage in header : 1F C0 1F FF FF
May 26 06:46:21 cyx otbr-agent[690215]: 63d.21:05:25.833 [W] P-SpiIntface--: Garbage in header : 1F E0 1F FF FF
May 26 06:46:21 cyx otbr-agent[690215]: 63d.21:05:25.866 [W] P-SpiIntface--: Garbage in header : 1F E0 1F FF FF
May 26 06:46:21 cyx otbr-agent[690215]: 63d.21:05:25.899 [W] P-SpiIntface--: Garbage in header : 1F E0 1F FF FF
May 26 06:46:21 cyx otbr-agent[690215]: 63d.21:05:25.932 [W] P-SpiIntface--: Garbage in header : 1F C0 1F FF FF
May 26 06:46:21 cyx otbr-agent[690215]: 63d.21:05:25.966 [W] P-SpiIntface--: Garbage in header : 1F E0 1F FF FF
May 26 06:46:21 cyx otbr-agent[690215]: 63d.21:05:25.999 [W] P-SpiIntface--: Garbage in header : 1F C0 1F FF FF
May 26 06:46:21 cyx otbr-agent[690215]: 63d.21:05:26.165 [W] P-SpiIntface--: Slave seems stuck.
May 26 06:46:21 cyx otbr-agent[690215]: 63d.21:05:26.201 [W] P-SpiIntface--: Garbage in header : F8 00 00 00 00
May 26 06:46:21 cyx otbr-agent[690215]: 63d.21:05:26.234 [W] P-SpiIntface--: Garbage in header : F9 F8 00 00 FF
Sometimes, it would just display "waiting response" instead of "Garbage in header."

Why does this happen?

I have modified the OTBR configuration as follows:

OTBR_AGENT_OPTS="-I wpan0 -B wlan0 spinel+spi:///dev/spidev0.0?gpio-int-device=/dev/gpiochip0&gpio-int-line=21&gpio-reset-device=/dev/gpiochip0&gpio-reset-line=20&no-reset=1&spispeed=1000000 trel://wlan0"
My hardware wiring is as follows:

SPIS_PIN_MOSI P0.04 → Raspberry Pi 4B Pin 19
SPIS_PIN_MISO P0.28 → Raspberry Pi 4B Pin 21
SPIS_PIN_SCK P0.03 → Raspberry Pi 4B Pin 23
SPIS_PIN_CSN P0.29 → Raspberry Pi 4B Pin 24
SPIS_PIN_HOST_IRQ P0.30 → Raspberry Pi 4B Pin 40
Additionally, I connected RESET to Raspberry Pi Pin 38 and also connected GND.
Is there anything missing in my steps?
I have checked the information in the README.
Do I need to install spi-hdlc-adapter and wpantund?
I have installed wpantund, but I cannot modify its configuration and it doesn’t seem to be effective.
Is there anything wrong or incomplete with my process?
Thanks~

[zhanglongxia]

@chenyixi1997 Could you check whether the GPIO voltages on the Pi and nRF52840DK are match with each other? Both spi-hdlc-adapter and wpantund are not needed. They are deprecated programs.

[chenyixi1997]

Hello, thank you very much for your help.
First, I tested the GPIO voltage (RESET pin). When it is at a high level, it is 3.3V, and both the Raspberry Pi and the NRF52840 have this value.
Then, according to your suggestion, I modified the URL and measured the pins with a logic analyzer. Now the SCK looks normal and the frequency is 1MHz, but the OTBR side still shows "Garbage in header".
log:
May 29 03:55:49 cyx otbr-agent[943145]: [NOTE]-AGENT---: Thread interface: wpan0
May 29 03:55:49 cyx otbr-agent[943145]: [NOTE]-AGENT---: Radio URL: spinel+spi:///dev/spidev0.0?gpio-int-device=/dev/gpiochip0&gpio-int-line=21&gpio-reset-device=/dev/gpiochip0&gpio-reset-line=20&spi-mode=0&spi-speed=1000000&spi-cs-delay>
May 29 03:55:49 cyx otbr-agent[943145]: [NOTE]-AGENT---: Radio URL: trel://wlan0
May 29 03:55:49 cyx otbr-agent[943145]: [NOTE]-ILS-----: Infra link selected: wlan0
May 29 03:55:49 cyx otbr-agent[943145]: [INFO]-RCP_HOS-: OpenThread log level changed to 4
May 29 03:55:49 cyx otbr-agent[943145]: 66d.18:14:40.630 [N] P-SpinelDrive-: SoftwareReset is 1
May 29 03:55:49 cyx otbr-agent[943145]: 66d.18:14:40.630 [W] P-SpiIntface--: Garbage in header : 02 FF FF FF FF
May 29 03:55:49 cyx otbr-agent[943145]: 66d.18:14:40.630 [N] P-SpinelDrive-: Waiting response: key=0
May 29 03:55:49 cyx otbr-agent[943145]: 66d.18:14:40.631 [W] P-SpiIntface--: Garbage in header : 02 FF FF FF 02
May 29 03:55:49 cyx otbr-agent[943145]: 66d.18:14:40.631 [I] P-SpiIntface--: Slave is rate limiting transactions

What could be causing this?
Also, the changes on the SCK seem to occur after a period following a reset. Is this because a delay has been added in the settings?
Thank you again for your help.

[zhanglongxia]

I parsed the SPI frame. The format of the SPI frame is correct(rx_len=32 is from here, the rx_len=507 is from here(512-5 (HeaderSize))). So I think the SPI is working now. Could you enable the DEBUG log level to get more detailed logs?

The spi-cs-delay is used to set the delay between the CS and the CLK starts.

[chenyixi1997]

Hi, how do I set the DEBUG log level on the OTBR side? My current log level is 4. I tried modifying the configuration, but it doesn’t seem to be effective.
Thank you for your help.

[zhanglongxia]

Set the build option -DOT_LOG_LEVEL=DEBG should enable the DEBUG log when you are building the otbr-agent. For example: ./script/cmake-build -DOT_LOG_LEVEL=DEBG . Or you can directly change the code here to set the log level to DEBUG.

[chenyixi1997]

Hello~Following your suggestion, I added -DOT_LOG_LEVEL=DEBG after INFRA_IF_NAME=wlan0 ./script/setup, but after compiling and restarting OTBR, it still shows the log level as 4. Then I tried modifying the code by setting set(OT_LOG_LEVEL "DEBG" CACHE STRING "set OpenThread log level to DEBG" FORCE), yet after recompiling, it still shows the log level as 4. This confuses me—why do my modifications seem to have no effect at all? Thank you for your help, and I wish you a happy Dragon Boat Festival!

[Xhimself805]

I can use the OBTR Just follow this tutorial https://www.youtube.com/watch?v=xCyzNzYSG4U&t=1044s but I meet some problems, my CLI device can't ping 8.8.8.8 there is something wrong with my nat64. Someone suggests me use the latest version RPi OS, But I can't enter the desktop after reboot. lol

[jwhui]

I would suggest looking at the latest OpenThread Border Router Setup Guide.