Skip to content

migrate_otbr_settings.py TimeoutError on fresh install with Sonoff Dongle Lite MG21 prevents otbr-agent from starting #4475

@adaptazbysek

Description

@adaptazbysek

Describe the issue you are experiencing

On a fresh HAOS install with no existing OTBR configuration, the migrate_otbr_settings.py script runs unconditionally and attempts to communicate with the dongle via the Spinel protocol. It fails with a TimeoutError after 3 retries and exits with code 1, preventing otbr-agent from ever starting. There is no existing config to migrate — /addon_configs contains no OTBR-related files and find /data -path "*openthread*" returns nothing.

Add-on version: 2.16.5
System: Home Assistant OS 17.1 (aarch64 / raspberrypi4-64)
Home Assistant Core: 2026.3.0
Home Assistant Supervisor: 2026.02.3

Hardware: Sonoff Dongle Lite MG21 (EFR32MG21), flashed with MultiPAN RCP firmware via Sonoff's official flasher at dongle.sonoff.tech
Device path: /dev/ttyUSB0 (symlinked via /dev/serial/by-id/)
Flow control: false (confirmed rtscts=False in logs)

Key log excerpt:

[INFO] Migrating OTBR settings if needed...
universal_silabs_flasher.spinel DEBUG Device did not respond to reset, continuing
universal_silabs_flasher.spinel DEBUG Failed to send SpinelFrame ... trying again in 0.10s (attempt 1 of 3)
universal_silabs_flasher.spinel DEBUG Failed to send SpinelFrame ... trying again in 0.10s (attempt 2 of 3)
universal_silabs_flasher.spinel DEBUG Failed to send SpinelFrame ... trying again in 0.10s (attempt 3 of 3)
TimeoutError
[WARNING] otbr-agent exited with code 1 (by signal 0).

Expected behaviour: When no existing OTBR config is present, migrate_otbr_settings.py should skip the hardware address query entirely and exit cleanly, allowing otbr-agent to start.

Confirmed no port conflicts: lsof and fuser show nothing holding the serial port. No ZHA or Zigbee2MQTT installed.

Related: This appears to be the same class of issue as #4222, which was supposedly fixed in #4263 but the problem persists on 2.16.5 with this hardware.

What type of installation are you running?

Home Assistant OS

Which operating system are you running on?

Home Assistant Operating System

Which app are you reporting an issue with?

OpenThread Border Router

What is the version of the app?

2.16.5

Steps to reproduce the issue

  1. Fresh HAOS install (no prior OTBR config)
  2. Install OpenThread Border Router add-on 2.16.5
  3. Configure with Sonoff Dongle Lite MG21, baudrate 460800, flow_control false
  4. Start the add-on
  5. Observe migrate_otbr_settings.py timeout and crash before otbr-agent starts

System Health information

There are currently no repairs pending

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

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

s6-rc: info: service mdns: starting
s6-rc: info: service s6rc-oneshot-runner: starting
s6-rc: info: service mdns successfully started
s6-rc: info: service s6rc-oneshot-runner successfully started
s6-rc: info: service fix-attrs: starting
s6-rc: info: service banner: starting
[08:57:02] INFO: �[32mStarting mDNS Responder...�[0m
Default: mDNSResponder (Engineering Build) (Feb 25 2026 17:38:09) starting
s6-rc: info: service fix-attrs successfully started
s6-rc: info: service legacy-cont-init: starting
s6-rc: info: service legacy-cont-init successfully started

�[34m-----------------------------------------------------------�[0m
�[34m Add-on: OpenThread Border Router�[0m
�[34m OpenThread Border Router add-on�[0m
�[34m-----------------------------------------------------------�[0m
�[34m Add-on version: 2.16.5�[0m
�[32m You are running the latest version of this add-on.�[0m
�[34m System: Home Assistant OS 17.1  (aarch64 / raspberrypi4-64)�[0m
�[34m Home Assistant Core: 2026.3.0�[0m
�[34m Home Assistant Supervisor: 2026.02.3�[0m
�[34m-----------------------------------------------------------�[0m
�[34m Please, share the above information when looking for help�[0m
�[34m or support in, e.g., GitHub, forums or the Discord chat.�[0m
�[34m-----------------------------------------------------------�[0m
s6-rc: info: service banner successfully started
s6-rc: info: service otbr-agent: starting
[08:57:03] INFO: �[32mSetup OTBR firewall...�[0m
[08:57:03] INFO: �[32mMigrating OTBR settings if needed...�[0m
2026-03-05 08:57:06 null-assistant asyncio[241] DEBUG Using selector: EpollSelector
2026-03-05 08:57:06 null-assistant zigpy.serial[241] DEBUG Opening a serial connection to '/dev/serial/by-id/usb-SONOFF_SONOFF_Dongle_Lite_MG21_e0801d0bf1a2ef11b691976661ce3355-if00-port0' (baudrate=460800, xonxoff=False, rtscts=False)
2026-03-05 08:57:06 null-assistant serialx.platforms.serial_posix[241] DEBUG Configuring serial port '/dev/serial/by-id/usb-SONOFF_SONOFF_Dongle_Lite_MG21_e0801d0bf1a2ef11b691976661ce3355-if00-port0'
2026-03-05 08:57:06 null-assistant serialx.platforms.serial_posix[241] DEBUG Configuring serial port: [0, 0, 3248, 0, 4100, 4100, [b'\x03', b'\x1c', b'\x7f', b'\x15', b'\x04', 0, 0, b'\x00', b'\x11', b'\x13', b'\x1a', b'\x00', b'\x12', b'\x0f', b'\x17', b'\x16', b'\x00', b'\x00', b'\x00', b'\x00', b'\x00', b'\x00', b'\x00', b'\x00', b'\x00', b'\x00', b'\x00', b'\x00', b'\x00', b'\x00', b'\x00', b'\x00']]
2026-03-05 08:57:06 null-assistant serialx.platforms.serial_posix[241] DEBUG Setting low latency mode: True
2026-03-05 08:57:06 null-assistant serialx.platforms.serial_posix[241] DEBUG Setting modem pins: ModemPins[!dtr !rts]
2026-03-05 08:57:06 null-assistant serialx.platforms.serial_posix[241] DEBUG TIOCMBIC: 0x00000006
2026-03-05 08:57:06 null-assistant zigpy.serial[241] DEBUG Connection made: <serialx.platforms.serial_posix.PosixSerialTransport object at 0x7f813b46d0>
2026-03-05 08:57:06 null-assistant universal_silabs_flasher.spinel[241] DEBUG Sending frame SpinelFrame(header=SpinelHeader(transaction_id=0, network_link_id=0, flag=2), command_id=<CommandID.RESET: 1>, data=b'\x02')
2026-03-05 08:57:06 null-assistant universal_silabs_flasher.spinel[241] DEBUG Sending data b'~\x80\x01\x02\xea\xf0~'
2026-03-05 08:57:06 null-assistant serialx.descriptor_transport[241] DEBUG Immediately writing b'~\x80\x01\x02\xea\xf0~'
2026-03-05 08:57:06 null-assistant serialx.descriptor_transport[241] DEBUG Sent 7 of 7 bytes
2026-03-05 08:57:08 null-assistant universal_silabs_flasher.spinel[241] DEBUG Device did not respond to reset, continuing
2026-03-05 08:57:08 null-assistant universal_silabs_flasher.spinel[241] DEBUG Sending frame SpinelFrame(header=SpinelHeader(transaction_id=3, network_link_id=0, flag=2), command_id=<CommandID.PROP_VALUE_GET: 2>, data=b'\x08')
2026-03-05 08:57:08 null-assistant universal_silabs_flasher.spinel[241] DEBUG Sending data b'~\x83\x02\x08\xbc\x9a~'
2026-03-05 08:57:08 null-assistant serialx.descriptor_transport[241] DEBUG Immediately writing b'~\x83\x02\x08\xbc\x9a~'
2026-03-05 08:57:08 null-assistant serialx.descriptor_transport[241] DEBUG Sent 7 of 7 bytes
2026-03-05 08:57:10 null-assistant universal_silabs_flasher.spinel[241] DEBUG Failed to send SpinelFrame(header=SpinelHeader(network_link_id=0, flag=2), command_id=<CommandID.PROP_VALUE_GET: 2>, data=b'\x08'), trying again in 0.10s (attempt 1 of 3)
2026-03-05 08:57:10 null-assistant universal_silabs_flasher.spinel[241] DEBUG Sending frame SpinelFrame(header=SpinelHeader(transaction_id=3, network_link_id=0, flag=2), command_id=<CommandID.PROP_VALUE_GET: 2>, data=b'\x08')
2026-03-05 08:57:10 null-assistant universal_silabs_flasher.spinel[241] DEBUG Sending data b'~\x83\x02\x08\xbc\x9a~'
2026-03-05 08:57:10 null-assistant serialx.descriptor_transport[241] DEBUG Immediately writing b'~\x83\x02\x08\xbc\x9a~'
2026-03-05 08:57:10 null-assistant serialx.descriptor_transport[241] DEBUG Sent 7 of 7 bytes
2026-03-05 08:57:12 null-assistant universal_silabs_flasher.spinel[241] DEBUG Failed to send SpinelFrame(header=SpinelHeader(network_link_id=0, flag=2), command_id=<CommandID.PROP_VALUE_GET: 2>, data=b'\x08'), trying again in 0.10s (attempt 2 of 3)
2026-03-05 08:57:13 null-assistant universal_silabs_flasher.spinel[241] DEBUG Sending frame SpinelFrame(header=SpinelHeader(transaction_id=3, network_link_id=0, flag=2), command_id=<CommandID.PROP_VALUE_GET: 2>, data=b'\x08')
2026-03-05 08:57:13 null-assistant universal_silabs_flasher.spinel[241] DEBUG Sending data b'~\x83\x02\x08\xbc\x9a~'
2026-03-05 08:57:13 null-assistant serialx.descriptor_transport[241] DEBUG Immediately writing b'~\x83\x02\x08\xbc\x9a~'
2026-03-05 08:57:13 null-assistant serialx.descriptor_transport[241] DEBUG Sent 7 of 7 bytes
2026-03-05 08:57:15 null-assistant universal_silabs_flasher.spinel[241] DEBUG Failed to send SpinelFrame(header=SpinelHeader(network_link_id=0, flag=2), command_id=<CommandID.PROP_VALUE_GET: 2>, data=b'\x08'), trying again in 0.10s (attempt 3 of 3)
2026-03-05 08:57:15 null-assistant serialx.descriptor_transport[241] DEBUG Closing at the request of the application
2026-03-05 08:57:15 null-assistant zigpy.serial[241] DEBUG Waiting for serial port to close
2026-03-05 08:57:15 null-assistant serialx.descriptor_transport[241] DEBUG Closing connection: None
2026-03-05 08:57:15 null-assistant serialx.descriptor_transport[241] DEBUG Closing file descriptor 7
2026-03-05 08:57:15 null-assistant serialx.descriptor_transport[241] DEBUG Calling protocol `connection_lost` with exc=None
2026-03-05 08:57:15 null-assistant zigpy.serial[241] DEBUG Connection lost: None
Traceback (most recent call last):
  File "/usr/local/lib/python3.13/dist-packages/universal_silabs_flasher/spinel.py", line 260, in send_frame
    return await asyncio.shield(future)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/local/bin/migrate_otbr_settings.py", line 228, in <module>
    asyncio.run(main())
    ~~~~~~~~~~~^^^^^^^^
  File "/usr/lib/python3.13/asyncio/runners.py", line 195, in run
    return runner.run(main)
           ~~~~~~~~~~^^^^^^
  File "/usr/lib/python3.13/asyncio/runners.py", line 118, in run
    return self._loop.run_until_complete(task)
           ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^
  File "/usr/lib/python3.13/asyncio/base_events.py", line 725, in run_until_complete
    return future.result()
           ~~~~~~~~~~~~~^^
  File "/usr/local/bin/migrate_otbr_settings.py", line 156, in main
    hwaddr = await get_adapter_hardware_addr(
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    ...<3 lines>...
    )
    ^
  File "/usr/local/bin/migrate_otbr_settings.py", line 103, in get_adapter_hardware_addr
    rsp = await protocol.send_command(
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    ...<2 lines>...
    )
    ^
  File "/usr/local/lib/python3.13/dist-packages/universal_silabs_flasher/spinel.py", line 292, in send_command
    return await self.send_frame(frame, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/dist-packages/universal_silabs_flasher/spinel.py", line 259, in send_frame
    async with asyncio_timeout(timeout):
               ~~~~~~~~~~~~~~~^^^^^^^^^
  File "/usr/lib/python3.13/asyncio/timeouts.py", line 116, in __aexit__
    raise TimeoutError from exc_val
TimeoutError
[08:57:15] WARNING: �[33motbr-agent exited with code 1 (by signal 0).�[0m
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            
[08:57:15] INFO: �[32mOTBR firewall teardown completed.�[0m
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 banner: 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.
Default: mDNSResponder (Engineering Build) (Feb 25 2026 17:38:09) stopping
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
[08:57:15] INFO: �[32mmDNS ended with exit code 4 (signal 0)...�[0m
s6-rc: info: service mdns successfully stopped

Additional information

No response

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Priority

    None yet

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions