Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

OTBR: 2.9.0 breaks nrf RPC spinel radio #3683

Open
Teagan42 opened this issue Jul 6, 2024 · 21 comments
Open

OTBR: 2.9.0 breaks nrf RPC spinel radio #3683

Teagan42 opened this issue Jul 6, 2024 · 21 comments

Comments

@Teagan42
Copy link

Teagan42 commented Jul 6, 2024 •
edited
Loading

Describe the issue you are experiencing

I have been successfully utilizing a nrf52840 MDK USB dongle, flashed with OTBR RPC firmware using west/zephyr as described by NRF52/openthread.io documentation https://openthread.io/codelabs/openthread-hardware#1, for the last year. Upon upgrading the OTBR addon to 2.9.0, the OTBR agent fails to start due to spinel_driver error/timeout (see addon logs). I was able to work around this breaking change by downloading the 2.8.0 OTBR addon and installing it as a local addon.

I also tried using a spare SkyConnect dongle (configured the add-on to flash firmware), which resulted in the same errors.

What type of installation are you running?

Home Assistant OS

Which operating system are you running on?

Home Assistant Operating System

Which add-on are you reporting an issue with?

OpenThread Border Router

What is the version of the add-on?

2.9.0

Steps to reproduce the issue

  1. Flash OTBR RPC firmware to nrf52xxx device
  2. Install OTBR addon version 2.9.0
  3. Configure OTBR addon to use this serial device
  4. Start OTBR addon
    ..

System Health information

System Information

version core-2024.7.1
installation_type Home Assistant OS
dev false
hassio true
docker true
user root
virtualenv false
python_version 3.12.4
os_name Linux
os_version 6.6.33-haos
arch x86_64
timezone America/Denver
config_dir /config
Home Assistant Community Store
GitHub API ok
GitHub Content ok
GitHub Web ok
GitHub API Calls Remaining 4999
Installed Version 1.34.0
Stage running
Available Repositories 1398
Downloaded Repositories 52
HACS Data ok
Home Assistant Cloud
logged_in false
can_reach_cert_server ok
can_reach_cloud_auth ok
can_reach_cloud ok
Home Assistant Supervisor
host_os Home Assistant OS 12.4
update_channel stable
supervisor_version supervisor-2024.06.2
agent_version 1.6.0
docker_version 26.1.4
disk_total 110.5 GB
disk_used 52.2 GB
healthy true
supported true
host_connectivity true
supervisor_connectivity true
ntp_synchronized true
virtualization kvm
board ova
supervisor_api ok
version_api ok
installed_addons Whisper (2.1.2), Piper (1.5.0), Advanced SSH & Web Terminal (18.0.0), ESPHome (2024.6.6), Studio Code Server (5.15.0), openWakeWord (1.10.0), Matter Server (6.2.1), EMQX (0.6.0), OpenThread Border Router (2.8.0)
Dashboards
dashboards 6
resources 34
views 15
mode storage
Recorder
oldest_recorder_run June 5, 2024 at 5:41 PM
current_recorder_run July 6, 2024 at 2:33 AM
estimated_db_size 8841.11 MiB
database_engine postgresql
database_version 16.2

Anything in the Supervisor logs that might be useful for us?

No response

Anything in the add-on logs that might be useful for us?

-----------------------------------------------------------
 Add-on: OpenThread Border Router
 OpenThread Border Router add-on
-----------------------------------------------------------
 Add-on version: 2.9.0
 You are running the latest version of this add-on.
 System: Home Assistant OS 12.4  (amd64 / qemux86-64)
 Home Assistant Core: 2024.7.1
 Home Assistant Supervisor: 2024.06.2
-----------------------------------------------------------
 Please, share the above information when looking for help
 or support in, e.g., GitHub, forums or the Discord chat.
-----------------------------------------------------------
s6-rc: info: service banner successfully started
s6-rc: info: service universal-silabs-flasher: starting
[03:00:25] INFO: Flashing firmware is disabled
s6-rc: info: service universal-silabs-flasher successfully started
s6-rc: info: service otbr-agent: starting
[03:00:26] INFO: Starting otbr-agent...
[NOTE]-AGENT---: Running 0.3.0-41474ce-dirty
[NOTE]-AGENT---: Thread version: 1.3.0
[NOTE]-AGENT---: Thread interface: wpan0
[NOTE]-AGENT---: Radio URL: spinel+hdlc+uart:///dev/ttyACM0?uart-baudrate=115200
[NOTE]-AGENT---: Radio URL: trel://enp6s18
[NOTE]-ILS-----: Infra link selected: enp6s18
52d.23:00:28.002 [W] P-SpinelDrive-: Wait for response timeout
52d.23:00:30.004 [W] P-SpinelDrive-: Wait for response timeout
52d.23:00:32.006 [W] P-SpinelDrive-: Wait for response timeout
52d.23:00:32.006 [C] Platform------: Init() at spinel_driver.cpp:82: Failure
52d.23:00:34.009 [W] P-SpinelDrive-: Wait for response timeout
[03:01:05] WARNING: otbr-agent exited with code 1 (by signal 0).
[03:01:05] INFO: OTBR firewall teardown completed.
s6-svlisten1: fatal: /run/s6-rc/servicedirs/otbr-agent failed permanently or its supervisor died
s6-rc: warning: unable to start service otbr-agent: command exited 1
s6-rc: info: service legacy-cont-init: stopping
s6-rc: info: service universal-silabs-flasher: stopping
s6-rc: info: service mdns: stopping
Default: mDNSResponder (Engineering Build) (Jul  2 2024 09:04:20) stopping
/run/s6/basedir/scripts/rc.init: warning: s6-rc failed to properly bring all the services up! Check your logs (in /run/uncaught-logs/current if you have in-container logging) for more information.
/run/s6/basedir/scripts/rc.init: fatal: stopping the container.
s6-rc: info: service universal-silabs-flasher successfully stopped
s6-rc: info: service banner: stopping
[03:01:05] INFO: mDNS ended with exit code 4 (signal 0)...
s6-rc: info: service banner successfully stopped
s6-rc: info: service legacy-cont-init successfully stopped
s6-rc: info: service fix-attrs: stopping
s6-rc: info: service mdns successfully stopped
s6-rc: info: service fix-attrs successfully stopped
s6-rc: info: service s6rc-oneshot-runner: stopping
s6-rc: info: service s6rc-oneshot-runner successfully stopped
-----------------------------------------------------------
 Add-on: OpenThread Border Router
 OpenThread Border Router add-on
-----------------------------------------------------------
 Add-on version: 2.8.0
 You are running the latest version of this add-on.
 System: Home Assistant OS 12.4  (amd64 / qemux86-64)
 Home Assistant Core: 2024.7.1
 Home Assistant Supervisor: 2024.06.2
-----------------------------------------------------------
 Please, share the above information when looking for help
 or support in, e.g., GitHub, forums or the Discord chat.
-----------------------------------------------------------
s6-rc: info: service banner successfully started
s6-rc: info: service universal-silabs-flasher: starting
[03:00:25] INFO: Flashing firmware is disabled
s6-rc: info: service universal-silabs-flasher successfully started
s6-rc: info: service otbr-agent: starting
[04:08:18] INFO: Setup OTBR firewall...
[04:08:18] INFO: Starting otbr-agent...
[NOTE]-AGENT---: Running 0.3.0-41474ce-dirty
[NOTE]-AGENT---: Thread version: 1.3.0
[NOTE]-AGENT---: Thread interface: wpan0
[NOTE]-AGENT---: Radio URL: spinel+hdlc+uart:///dev/ttyACM0?uart-baudrate=115200
[NOTE]-AGENT---: Radio URL: trel://enp6s18
[NOTE]-ILS-----: Infra link selected: enp6s18
[INFO]-NCP-----: OpenThread log level changed to 5
53d.00:08:17.817 [D] P-SpinelDrive-: Sent spinel frame, flg:0x2, iid:0, tid:0, cmd:RESET
53d.00:08:17.817 [D] P-SpinelDrive-: Waiting response: key=0
53d.00:08:17.827 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:0, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:RESET_POWER_ON
53d.00:08:17.827 [I] P-SpinelDrive-: co-processor reset: RESET_POWER_ON
53d.00:08:17.827 [C] P-SpinelDrive-: Software reset co-processor successfully
53d.00:08:17.827 [D] P-SpinelDrive-: Waiting response: key=1
53d.00:08:17.827 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:1, cmd:PROP_VALUE_IS, key:PROTOCOL_VERSION, major:4, minor:3
53d.00:08:17.827 [D] P-SpinelDrive-: Waiting response: key=2
53d.00:08:17.828 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:1, cmd:PROP_VALUE_IS, key:NCP_VERSION, version:OPENTHREAD/thread-reference-20230119-545-g992be2781; NRF52840; Aug  3 2023 01:02:17
53d.00:08:17.828 [D] P-SpinelDrive-: Waiting response: key=5
53d.00:08:17.828 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:1, cmd:PROP_VALUE_IS, key:CAPS, caps:COUNTERS UNSOL_UPDATE_FILTER 802_15_4_2450MHZ_OQPSK CONFIG_RADIO MAC_RAW RCP_API_VERSION RCP_MIN_HOST_API_VERSION 
53d.00:08:17.829 [D] P-RadioSpinel-: Wait response: tid=1 key=8
53d.00:08:17.829 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:1, cmd:PROP_VALUE_IS, key:HWADDR, eui64:f4ce365868d42a60
53d.00:08:17.829 [D] P-RadioSpinel-: Wait response: tid=2 key=176
53d.00:08:17.830 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:2, cmd:PROP_VALUE_IS, key:RCP_API_VERSION, version:9
53d.00:08:17.830 [D] P-RadioSpinel-: Wait response: tid=3 key=177
53d.00:08:17.830 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:3, cmd:PROP_VALUE_IS, key:RCP_MIN_HOST_API_VERSION, min-host-version:4
53d.00:08:17.830 [D] P-RadioSpinel-: Wait response: tid=4 key=4619
53d.00:08:17.830 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:4, cmd:PROP_VALUE_IS, key:RADIO_CAPS, caps:255
53d.00:08:17.830 [D] P-Trel--------: platformTrelInit(aTrelUrl:"trel://enp6s18")
[DEBG]-TrelDns-: Initialized on netif "enp6s18"
[DEBG]-TrelDns-: Netif enp6s18 is ready: index = 2
53d.00:08:17.831 [I] P-Netif-------: Sent request#1 to set addr_gen_mode to 1
00:00:00.000 [D] P-RadioSpinel-: Wait response: tid=5 key=34
00:00:00.001 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:5, cmd:PROP_VALUE_IS, key:PHY_CHAN_SUPPORTED, channelMask:0x07fff800
00:00:00.001 [D] P-RadioSpinel-: Wait response: tid=6 key=32
00:00:00.001 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:6, cmd:PROP_VALUE_IS, key:PHY_ENABLED, enabled:1
00:00:00.001 [D] P-RadioSpinel-: Wait response: tid=7 key=54
00:00:00.001 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:7, cmd:PROP_VALUE_IS, key:MAC_15_4_PANID, panid:0xffff
00:00:00.001 [D] P-RadioSpinel-: Wait response: tid=8 key=53
00:00:00.002 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:8, cmd:PROP_VALUE_IS, key:MAC_15_4_SADDR, saddr:0x0000
00:00:00.002 [D] P-RadioSpinel-: Wait response: tid=9 key=39
00:00:00.002 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:9, cmd:PROP_VALUE_IS, key:PHY_RX_SENSITIVITY, sensitivity:-100
00:00:00.002 [D] P-RadioSpinel-: Wait response: tid=10 key=2048
00:00:00.002 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:10, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
00:00:00.002 [D] P-RadioSpinel-: Wait response: tid=11 key=52
00:00:00.003 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:11, cmd:PROP_VALUE_IS, key:MAC_15_4_LADDR, laddr:8a3e7f2a66308cca
00:00:00.003 [D] P-RadioSpinel-: Wait response: tid=12 key=53
00:00:00.003 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:12, cmd:PROP_VALUE_IS, key:MAC_15_4_SADDR, saddr:0xfffe
00:00:00.003 [D] P-RadioSpinel-: Wait response: tid=13 key=4868
00:00:00.003 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:13, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
00:00:00.003 [D] P-RadioSpinel-: Wait response: tid=14 key=4869
00:00:00.004 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:14, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
00:00:00.004 [I] ChildSupervsn-: Timeout: 0 -> 190
00:00:00.004 [D] P-RadioSpinel-: Wait response: tid=15 key=2048
00:00:00.005 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:15, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
00:00:00.005 [D] P-RadioSpinel-: Wait response: tid=1 key=54
00:00:00.005 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:1, cmd:PROP_VALUE_IS, key:MAC_15_4_PANID, panid:0xd8cf
00:00:00.005 [I] Settings------: Read NetworkInfo {rloc:0xf400, extaddr:823092acf5b4adac, role:leader, mode:0x0f, version:4, keyseq:0x9, ...
00:00:00.005 [I] Settings------: ... pid:0x4cdd0775, mlecntr:0x3e9, maccntr:0x3e8, mliid:b331dd61476553b7}
00:00:00.005 [D] P-RadioSpinel-: Wait response: tid=2 key=2048
00:00:00.005 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:2, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
00:00:00.006 [D] P-RadioSpinel-: Wait response: tid=3 key=2049
00:00:00.006 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:3, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
00:00:00.006 [D] P-RadioSpinel-: Wait response: tid=4 key=2049
00:00:00.006 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:4, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
00:00:00.006 [D] P-RadioSpinel-: Wait response: tid=5 key=53
00:00:00.006 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:5, cmd:PROP_VALUE_IS, key:MAC_15_4_SADDR, saddr:0xf400
00:00:00.006 [D] P-RadioSpinel-: Wait response: tid=6 key=52
00:00:00.007 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:6, cmd:PROP_VALUE_IS, key:MAC_15_4_LADDR, laddr:823092acf5b4adac
00:00:00.007 [D] P-Trel--------: PrepareSocket()
[DEBG]-TrelDns-: Start browsing _trel._udp services ...
00:00:00.007 [I] TrelInterface-: Enabled interface, local port:50576
00:00:00.007 [I] RoutingManager: Initializing - InfraIfIndex:2
00:00:00.007 [I] InfraIf-------: Init infra netif 2
00:00:00.007 [I] Settings------: Read BrUlaPrefix fd8c:39b:a267::/48
00:00:00.007 [N] RoutingManager: BR ULA prefix: fd8c:39b:a267::/48 (loaded)
00:00:00.007 [I] RoutingManager: Generated local OMR prefix: fd8c:39b:a267:1::/64
00:00:00.007 [I] RoutingManager: Generated local NAT64 prefix: fd8c:39b:a267:2:0:0::/96
00:00:00.007 [N] RoutingManager: Local on-link prefix: fd63:75ee:6746:c180::/64
00:00:00.007 [I] InfraIf-------: State changed: NOT RUNNING -> RUNNING
00:00:00.007 [I] RoutingManager: Enabling
00:00:00.007 [I] Nat64---------: IPv4 CIDR for NAT64: 192.168.255.0/24 (actual address pool: 192.168.255.1 - 192.168.255.254, 254 addresses)
00:00:00.007 [I] Nat64---------: NAT64 translator is now Disabled
00:00:00.007 [I] P-Resolver----: Got nameserver #0: 172.30.32.3
[INFO]-UTILS---: Set state callback: OK
[DEBG]-TrelDns-: Stop browsing _trel._udp service.
[DEBG]-TrelDns-: mDNS Publisher is Ready
[INFO]-TrelDns-: TREL DNS-SD Is Now Ready: Netif=enp6s18(2), SubscriberId=0, Register=!
[INFO]-BA------: Start Thread Border Agent
[INFO]-BA------: Publish meshcop service Home Assistant OpenThread Border Router #ADAC._meshcop._udp.local.
00:00:00.008 [I] Settings------: Read BorderAgentId {id:40bc64a2dfef1ec6774b377c89bb57f5}
[INFO]-MDNS----: Registering service Home Assistant OpenThread Border Router #ADAC._meshcop._udp
00:00:00.008 [I] BbrLocal------: Add Domain Prefix: ::/0, NotFound
00:00:00.008 [I] BbrLocal------: Add BBR Service: seqno (89), delay (5s), timeout (3600s), InvalidState
[INFO]-ADPROXY-: Started
[INFO]-DPROXY--: Started
[INFO]-APP-----: Thread Border Router started on AIL enp6s18.

Additional information

No response
@rwkeane
Copy link

rwkeane commented Jul 17, 2024 •
edited
Loading

I received the same error (Platform------: Init() at spinel_driver.cpp:82: Failure) when running natively on an RPI (tried with both RPI3 and RPI4) with linux when using the SkyConnect stick flashed with the OTBR firmware (i.e. not on Home Assistant) . So I suspect the issue might be the firmware on the stick rather than something HA side

Was there a new version of the firmware released recently? It could be a firmware bug if its not OS specific - I'd be happy to load an old version of the firmware and give it a try if you give me a link to where I can download it

@akarabach
Copy link

I have the same issue, but I'm using OTBR in docker

@AdriSchmi
Copy link

AdriSchmi commented Jul 22, 2024 •
edited
Loading

I have this issue since today too. All my Matter devices are offline

@eground2000
Copy link

eground2000 commented Jul 23, 2024 •
edited
Loading

I have the same issue. I use a SLZB-06M [Kernel Version: 2.3.6 | Radio Version: 20241105 | Matter-over-Thread (Beta)]

-----------------------------------------------------------
Add-on: OpenThread Border Router
OpenThread Border Router add-on
-----------------------------------------------------------
Add-on version: 2.9.0
You are running the latest version of this add-on.
s6-rc: info: service socat-otbr-tcp successfully started
System: Home Assistant OS 12.4 (amd64 / qemux86-64)
Home Assistant Core: 2024.7.3
Home Assistant Supervisor: 2024.06.2
-----------------------------------------------------------
Please, share the above information when looking for help
or support in, e.g., GitHub, forums or the Discord chat.
-----------------------------------------------------------
s6-rc: info: service banner successfully started
s6-rc: info: service universal-silabs-flasher: starting
[15:23:02] INFO: Flashing firmware is disabled
s6-rc: info: service universal-silabs-flasher successfully started
s6-rc: info: service otbr-agent: starting
[15:23:02] INFO: Starting otbr-agent...
tiocmget: Inappropriate ioctl for device
[NOTE]-AGENT---: Running 0.3.0-41474ce-dirty
[NOTE]-AGENT---: Thread version: 1.3.0
[NOTE]-AGENT---: Thread interface: wpan0
[NOTE]-AGENT---: Radio URL: spinel+hdlc+uart:///tmp/ttyOTBR?uart-baudrate=460800
[NOTE]-AGENT---: Radio URL: trel://enp2s1
[NOTE]-ILS-----: Infra link selected: enp2s1
[INFO]-NCP-----: OpenThread log level changed to 5
53d.19:34:45.686 [D] P-SpinelDrive-: Sent spinel frame, flg:0x2, iid:0, tid:0, cmd:RESET
53d.19:34:45.686 [D] P-SpinelDrive-: Waiting response: key=0
53d.19:34:47.688 [W] P-SpinelDrive-: Wait for response timeout
53d.19:34:47.688 [I] P-SpinelDrive-: co-processor self reset successfully
53d.19:34:47.688 [D] P-SpinelDrive-: Waiting response: key=1
53d.19:34:49.690 [W] P-SpinelDrive-: Wait for response timeout
53d.19:34:49.690 [D] P-SpinelDrive-: Waiting response: key=1
53d.19:34:51.692 [W] P-SpinelDrive-: Wait for response timeout
53d.19:34:51.692 [C] Platform------: Init() at spinel_driver.cpp:82: Failure
53d.19:34:51.692 [D] P-SpinelDrive-: Waiting response: key=1
53d.19:34:53.694 [W] P-SpinelDrive-: Wait for response timeout
[15:23:10] WARNING: otbr-agent exited with code 1 (by signal 0).
[15:23:10] INFO: OTBR firewall teardown completed.
s6-svlisten1: fatal: /run/s6-rc/servicedirs/otbr-agent failed permanently or its supervisor died
s6-rc: warning: unable to start service otbr-agent: command exited 1
s6-rc: info: service legacy-cont-init: stopping
s6-rc: info: service universal-silabs-flasher: stopping
s6-rc: info: service socat-otbr-tcp: stopping
s6-rc: info: service mdns: stopping
/run/s6/basedir/scripts/rc.init: warning: s6-rc failed to properly bring all the services up! Check your logs (in /run/uncaught-logs/current if you have in-container logging) for more information.
/run/s6/basedir/scripts/rc.init: fatal: stopping the container.
s6-rc: info: service universal-silabs-flasher successfully stopped
s6-rc: info: service banner: stopping
2024/07/23 15:23:10 socat[74] W exiting on signal 15
Default: mDNSResponder (Engineering Build) (Jul 2 2024 09:04:20) stopping
s6-rc: info: service socat-otbr-tcp successfully stopped
s6-rc: info: service banner successfully stopped
s6-rc: info: service legacy-cont-init successfully stopped
s6-rc: info: service fix-attrs: stopping
s6-rc: info: service fix-attrs successfully stopped
s6-rc: info: service s6rc-oneshot-runner: stopping
s6-rc: info: service s6rc-oneshot-runner successfully stopped
[15:23:10] INFO: mDNS ended with exit code 4 (signal 0)...
s6-rc: info: service mdns successfully stopped`

@rwkeane
Copy link

rwkeane commented Jul 24, 2024 •
edited
Loading

So after digging through the manufacturer documentation, I think I figured it out!

When the baud rate is set to the default, I get this error. After updating it to 460800, the error resolved itself

@akarabach
Copy link

So after digging through the manufacturer documentation, I think I figured it out!

When the baud rate is set to the default, I get this error. After updating it to 460800, the error resolved itself

didnt help for me

@AdriSchmi
Copy link

So after digging through the manufacturer documentation, I think I figured it out!

When the baud rate is set to the default, I get this error. After updating it to 460800, the error resolved itself

me neither

@Electron1007
Copy link

I have the same issue and proposed solution didn't help

@Benschi99
Copy link

Benschi99 commented Jul 24, 2024 •
edited
Loading

I have the same error!

Is there any way to downgrade to 2.8.0. without a backup? Sadly I just did a fresh installation of HA.

@Leah-Anderson
Copy link

I just wanted to throw this here because I came across the same thing running the openthread container with the nrf52840 MDK. The fix for me was to add "uart-baudrate=1000000&uart-flow-control". Credit goes to this issue: openthread/openthread#10538.

@tl-sl
Copy link
Contributor

tl-sl commented Jul 26, 2024

I also tried using a spare SkyConnect dongle (configured the add-on to flash firmware), which resulted in the same errors.

SkyConnect requires you enable flow control. It appears that nRf dongle may also require this.

The fix for me was to add "uart-baudrate=1000000&uart-flow-control"

For those using the addon, just enable the flow control button in configuration.

@IngmarStein
Copy link

As of recently, I found myself in the same situation after it has been working fine for a while.

After a reboot of my Synology NAS, the serial USB driver for a ZBT-1 is correctly loaded:

$ dmesg | grep -Fi usb
[52258.716119] usb 1-3: cp210I x converter now attached to ttyUSB0
$ lsusb -cui
|__usb1          1d6b:0002:0404 09  2.00  480MBit/s 0mA 1IF  (Linux 4.4.302+ xhci-hcd xHCI Host Controller 0000:09:00.3) hub
  |__1-1         f400:f400:0100 00  2.00  480MBit/s 200mA 1IF  (Synology DiskStation 650026E98013F214)
  1-1:1.0         (IF) 08:06:50 2EPs () usb-storage host7 (synoboot)
  |__1-3         10c4:ea60:0100 00  2.00   12MBit/s 100mA 1IF  (Nabu Casa SkyConnect v1.0 8eb63fd4089bed1184547708a8669f5d)
  1-3:1.0         (IF) ff:00:00 2EPs () cp210x ttyUSB0

This device is attached to a virtual machine running HAOS with the otbr addon.
When I start OTRB, I get the Init() at spinel_driver.cpp:82: Failure error:

[13:55:48] INFO: Starting universal-silabs-flasher with /dev/ttyUSB0
2024-08-16 13:55:48.915 homeassistant universal_silabs_flasher.flash INFO Extracted GBL metadata: NabuCasaMetadata(metadata_version=1, sdk_version='4.4.0', ezsp_version=None, ot_rcp_version='SL-OPENTHREAD/2.4.0.0_GitHub-7074a43e4' (2.4.0.0), cpc_version=None, fw_type=<FirmwareImageType.OT_RCP: 'ot-rcp'>, baudrate=460800)
2024-08-16 13:55:48.915 homeassistant universal_silabs_flasher.flasher INFO Probing ApplicationType.GECKO_BOOTLOADER at 115200 baud
2024-08-16 13:55:50.958 homeassistant universal_silabs_flasher.flasher INFO Probing ApplicationType.SPINEL at 460800 baud
2024-08-16 13:55:50.999 homeassistant universal_silabs_flasher.flasher INFO Detected ApplicationType.SPINEL, version 'SL-OPENTHREAD/2.4.0.0_GitHub-7074a43e4' (2.4.0.0) at 460800 baudrate (bootloader baudrate None)
2024-08-16 13:55:50.999 homeassistant universal_silabs_flasher.flash INFO Firmware version 'SL-OPENTHREAD/2.4.0.0_GitHub-7074a43e4' (2.4.0.0) is flashed, not re-installing
s6-rc: info: service universal-silabs-flasher successfully started
s6-rc: info: service otbr-agent: starting
[13:55:51] INFO: Setup OTBR firewall...
[13:55:51] INFO: Starting otbr-agent...
[NOTE]-AGENT---: Running 0.3.0-41474ce-dirty
[NOTE]-AGENT---: Thread version: 1.3.0
[NOTE]-AGENT---: Thread interface: wpan0
[NOTE]-AGENT---: Radio URL: spinel+hdlc+uart:///dev/ttyUSB0?uart-baudrate=115200&uart-flow-control
[NOTE]-AGENT---: Radio URL: trel://enp0s3
[NOTE]-ILS-----: Infra link selected: enp0s3
49d.20:26:11.560 [W] P-SpinelDrive-: Wait for response timeout
49d.20:26:13.562 [W] P-SpinelDrive-: Wait for response timeout
49d.20:26:15.565 [W] P-SpinelDrive-: Wait for response timeout
49d.20:26:15.565 [C] Platform------: Init() at spinel_driver.cpp:82: Failure
49d.20:26:17.567 [W] P-SpinelDrive-: Wait for response timeout
[13:55:59] WARNING: otbr-agent exited with code 1 (by signal 0).

This seems to cause a USB disconnect:

$ dmesg | grep -Fi usb
[52300.582799] cp210x ttyUSB0: cp210x converter now disconnected from ttyUSB0

And the serial module is no longer used for the ZBT-1 (changed to usbfs):

$ lsusb -cui
|__usb1          1d6b:0002:0404 09  2.00  480MBit/s 0mA 1IF  (Linux 4.4.302+ xhci-hcd xHCI Host Controller 0000:09:00.3) hub
  |__1-1         f400:f400:0100 00  2.00  480MBit/s 200mA 1IF  (Synology DiskStation 650026E98013F214)
  1-1:1.0         (IF) 08:06:50 2EPs () usb-storage host7 (synoboot)
  |__1-3         10c4:ea60:0100 00  2.00   12MBit/s 100mA 1IF  (Nabu Casa SkyConnect v1.0 8eb63fd4089bed1184547708a8669f5d)
  1-3:1.0         (IF) ff:00:00 2EPs () usbfs

@IngmarStein
Copy link

I was able to work around the issue by setting autoflash_firmware: false.

@github-actions GitHub Actions
Copy link

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

@github-actions github-actions bot added the stale label Sep 15, 2024
@akarabach
Copy link

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

Still a problem

@github-actions github-actions bot removed the stale label Sep 15, 2024
@oilid
Copy link

oilid commented Oct 8, 2024 •
edited
Loading

I also tried using a spare SkyConnect dongle (configured the add-on to flash firmware), which resulted in the same errors.

SkyConnect requires you enable flow control. It appears that nRf dongle may also require this.

The fix for me was to add "uart-baudrate=1000000&uart-flow-control"

For those using the addon, just enable the flow control button in configuration.

Thanks a lot, this helped me. I'm using a slzb-06 with Matter-over-Thread (beta). Before enabling the setting "Hardware flow control" after few restarts the OTBR always stopped running with the last message "service mdns successfully stopped" in the logs.
But enabling "Hardware flow control" helps although the official documentation on https://smlight.tech/manual/slzb-06/guide/thread-matter/ recommend:

Hardware flow control: click No.

I don't know why?!

Update: After few minutes it stopped working again... :-(

00:00:00.092 [N] RoutingManager: BR ULA prefix: fd06:befa:3b94::/48 (loaded)
00:00:00.092 [N] RoutingManager: Local on-link prefix: fd9a:1d1f:969e:48fa::/64
00:00:00.130 [N] Mle-----------: Role disabled -> detached
00:00:00.163 [N] P-Netif-------: Changing interface state to up.
00:00:00.186 [W] P-Netif-------: Failed to process request#2: No such process
00:00:00.187 [W] P-Netif-------: Failed to process request#6: No such process
s6-rc: info: service otbr-agent successfully started
s6-rc: info: service otbr-agent-rest-discovery: starting
s6-rc: info: service otbr-agent-configure: starting
00:00:00.307 [N] Mle-----------: Role detached -> router
00:00:00.307 [N] Mle-----------: Partition ID 0x3ed00eba
00:00:00.349 [W] P-Netif-------: Successfully added an external route fd9c:1945:69a7:ffff:0:0::/96 in kernel
00:00:00.349 [W] P-Netif-------: Successfully added an external route ::/0 in kernel
Done

s6-rc: info: service otbr-agent-configure successfully started
[13:42:13] INFO: Successfully sent discovery information to Home Assistant.
s6-rc: info: service otbr-agent-rest-discovery successfully started
s6-rc: info: service legacy-services: starting
s6-rc: info: service legacy-services successfully started
00:00:02.088 [W] DuaManager----: Failed to perform next registration: NotFound
00:00:15.241 [W] P-HdlcIntface-: Error decoding hdlc frame: Parse
00:00:21.624 [N] MeshForwarder-: Dropping rx frag frame, error:Drop, len:88, src:7235eb0cb7769c4b, dst:0xffff, sec:yes, tag:62139, offset:128, dglen:233
00:00:23.122 [W] Mle-----------: Failed to process Data Request: Security
00:00:29.319 [N] Mle-----------: Different partition (peer:1100402483, local:1053822650)
00:00:45.191 [N] Mle-----------: Different partition (peer:823648658, local:1053822650)
00:00:53.920 [N] Mle-----------: Different partition (peer:1100402483, local:1053822650)
00:01:15.541 [N] Mle-----------: Different partition (peer:823648658, local:1053822650)
00:01:38.228 [N] Mle-----------: Different partition (peer:1100402483, local:1053822650)
00:01:52.152 [N] Mle-----------: Different partition (peer:823648658, local:1053822650)
00:02:00.843 [N] Mle-----------: Different partition (peer:1100402483, local:1053822650)
00:02:48.150 [N] Mle-----------: Different partition (peer:823648658, local:1053822650)
00:03:01.541 [N] Mle-----------: Different partition (peer:1100402483, local:1053822650)
00:03:29.480 [N] Mle-----------: Different partition (peer:823648658, local:1053822650)
00:03:52.257 [N] Mle-----------: Different partition (peer:823648658, local:1053822650)
00:04:16.531 [W] Mle-----------: Failed to process Child ID Request: Security
00:04:29.199 [N] Mle-----------: Different partition (peer:823648658, local:1053822650)
00:04:41.474 [N] Mle-----------: Different partition (peer:1100402483, local:1053822650)
00:05:27.860 [N] Mle-----------: Different partition (peer:823648658, local:1053822650)
00:06:05.291 [N] Mle-----------: Different partition (peer:823648658, local:1053822650)
00:06:36.883 [N] Mle-----------: Different partition (peer:823648658, local:1053822650)
00:07:17.512 [N] Mle-----------: Different partition (peer:823648658, local:1053822650)
00:07:45.585 [N] Mle-----------: Different partition (peer:823648658, local:1053822650)
00:07:53.765 [W] Mle-----------: Failed to process Child ID Request: Security
00:08:01.730 [N] Mle-----------: Different partition (peer:1100402483, local:1053822650)
00:08:23.766 [N] Mle-----------: Different partition (peer:1100402483, local:1053822650)
00:08:53.292 [N] Mle-----------: Different partition (peer:823648658, local:1053822650)
00:09:16.496 [N] Mle-----------: Different partition (peer:823648658, local:1053822650)
00:09:30.305 [N] Mle-----------: Different partition (peer:1100402483, local:1053822650)
00:09:57.751 [W] Mle-----------: Failed to process Child ID Request: Security
00:10:09.792 [N] Mle-----------: Different partition (peer:1100402483, local:1053822650)
00:10:24.510 [N] Mle-----------: Different partition (peer:823648658, local:1053822650)
00:10:32.426 [N] Mle-----------: Different partition (peer:1100402483, local:1053822650)
00:11:01.014 [N] Mle-----------: Different partition (peer:823648658, local:1053822650)
00:11:04.539 [W] P-HdlcIntface-: Error decoding hdlc frame: Parse
00:11:09.432 [W] P-RadioSpinel-: radio tx timeout
00:11:09.432 [C] P-RadioSpinel-: Failed to communicate with RCP - no response from RCP during initialization
00:11:09.432 [C] P-RadioSpinel-: This is not a bug and typically due a config error (wrong URL parameters) or bad RCP image:
00:11:09.432 [C] P-RadioSpinel-: - Make sure RCP is running the correct firmware
00:11:09.432 [C] P-RadioSpinel-: - Double check the config parameters passed as `RadioURL` input
00:11:09.432 [C] Platform------: HandleRcpTimeout() at radio_spinel.cpp:1991: RadioSpinelNoResponse
[13:53:22] WARNING: otbr-agent exited with code 6 (by signal 0).
Chain OTBR_FORWARD_INGRESS (0 references)
target     prot opt source               destination         
DROP       all  --  anywhere             anywhere             PKTTYPE = unicast
DROP       all  --  anywhere             anywhere             match-set otbr-ingress-deny-src src
ACCEPT     all  --  anywhere             anywhere             match-set otbr-ingress-allow-dst dst
DROP       all  --  anywhere             anywhere             PKTTYPE = unicast
ACCEPT     all  --  anywhere             anywhere            
otbr-ingress-deny-src
otbr-ingress-deny-src-swap
otbr-ingress-allow-dst
otbr-ingress-allow-dst-swap
Chain OTBR_FORWARD_EGRESS (0 references)
target     prot opt source               destination         
ACCEPT     all  --  anywhere             anywhere            
[13:53:22] INFO: OTBR firewall teardown completed.
s6-rc: info: service legacy-services: stopping
s6-rc: info: service legacy-services successfully stopped
s6-rc: info: service otbr-agent-rest-discovery: stopping
s6-rc: info: service otbr-agent-configure: stopping
s6-rc: info: service otbr-agent-rest-discovery successfully stopped
s6-rc: info: service otbr-agent-configure successfully stopped
s6-rc: info: service otbr-agent: stopping
s6-rc: info: service otbr-agent successfully stopped
s6-rc: info: service legacy-cont-init: stopping
s6-rc: info: service universal-silabs-flasher: stopping
s6-rc: info: service socat-otbr-tcp: stopping
s6-rc: info: service mdns: stopping
s6-rc: info: service universal-silabs-flasher successfully stopped
Default: mDNSResponder (Engineering Build) (Oct  7 2024 16:49:24) stopping
2024/10/08 13:53:22 socat[79] W exiting on signal 15
s6-rc: info: service banner: stopping
s6-rc: info: service banner successfully stopped
s6-rc: info: service socat-otbr-tcp successfully stopped
s6-rc: info: service legacy-cont-init successfully stopped
s6-rc: info: service fix-attrs: stopping
s6-rc: info: service fix-attrs successfully stopped
s6-rc: info: service s6rc-oneshot-runner: stopping
s6-rc: info: service s6rc-oneshot-runner successfully stopped
[13:53:22] INFO: mDNS ended with exit code 4 (signal 0)...
s6-rc: info: service mdns successfully stopped

@alexpfau
Copy link

Same issue here with SLZB-06M on Matter-over-Thread firmware

@oilid
Copy link

oilid commented Oct 24, 2024

after the upgrade from 20240401 to thread firmware 20240727 it works now for me!!!

@akarabach
Copy link

Same issue here with SLZB-06M on Matter-over-Thread firmware

I have SLZB-06 and it works smoothly, may you share how have you configured it ? You need to follow official guide, connect the stick via usb to the HA instance, connect stick to ethernet, configure OTBR to work over ethernet (connect stick directly to HA via usb is required and important for stability, there were a bunch of issues and OTBR shutdown for me)

@akarabach
Copy link

It works for me for 20240401 as well

@tl-sl
Copy link
Contributor

tl-sl commented Oct 24, 2024

If you are having issues with SMLIGHT devices please file a new issue, rather than hijacking an unrelated issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests