I cannot get matter over thread working!

Here is my setup.

  • HA installed in a docker container
  • matter server installed in a docker container: Package python-matter-server · GitHub
  • Matter over Wi-Fi works fine
  • raspberry PI for OTBR (I have tried several different container images to no avail current attempt is openthread/border-router)
  • esp32-H2 with ot_rcp firmware
  • I have ipv6 enabled on my IOT network (the HA, Matter and OTBR docker containers have host networking mode)
  • the raspberry pi is connected to the IOT network via wifi
  • esp32-h2 is connected USB to the raspberry PI
  • iPhone on IOT wi-fi

I see the thread network in HA. I am able to make it preferred after pasting in the TLV info. all looks good. I am able to send the credentials to my iPhone but have never successfully added a thread device. after a short period of time, the border router goes missing from HA. I see nothing useful in the logs of the OTBR container (that I can tell). Restarting the otbr container brings the otbr back in HA.

Any help is greatly appreciated!!

OTBR logs:

s6-rc: info: service otbr-agent successfully started

s6-rc: info: service legacy-services: starting

00:00:00.256 [I] Settings------: Saved NetworkInfo {rloc:0x4800, extaddr:4ea8ba839f61326f, role:leader, mode:0x0f, version:5, keyseq:0x0, ...

00:00:00.256 [I] Settings------: ... pid:0x1dd94d57, mlecntr:0x4333, maccntr:0x427a, mliid:54989531eaa02f04}

00:00:00.257 [I] Mle-----------: Send Link Request (ff02:0:0:0:0:0:0:2)

00:00:00.257 [I] P-Netif-------: Succeeded to process request#1

00:00:00.258 [I] P-Netif-------: Message dropped by Thread

00:00:00.258 [W] P-Netif-------: Failed to process request#2: No such process

00:00:00.258 [I] P-Netif-------: ADD [M] ff33:40:fd1a:ffa6:4ae4:5eb1:0:1 (already subscribed, ignored)

00:00:00.259 [I] P-Netif-------: ADD [M] ff32:40:fd1a:ffa6:4ae4:5eb1:0:1 (already subscribed, ignored)

00:00:00.259 [I] P-Netif-------: ADD [M] ff03::fc (already subscribed, ignored)

00:00:00.259 [I] P-Netif-------: ADD [M] ff03::1 (already subscribed, ignored)

00:00:00.259 [I] P-Netif-------: ADD [M] ff02::16

00:00:00.259 [I] P-Netif-------: ADD [M] ff02::2 (rejected)

00:00:00.259 [I] Notifier------: StateChanged (0x00001000) [Ip6Mult+]

00:00:00.261 [I] P-Netif-------: Succeeded to process request#3

00:00:00.261 [I] P-Netif-------: ADD [M] ff33:40:fd1a:ffa6:4ae4:5eb1:0:1 (already subscribed, ignored)

00:00:00.261 [I] P-Netif-------: ADD [M] ff32:40:fd1a:ffa6:4ae4:5eb1:0:1 (already subscribed, ignored)

00:00:00.261 [I] P-Netif-------: ADD [M] ff03::fc (already subscribed, ignored)

00:00:00.261 [I] P-Netif-------: ADD [M] ff03::1 (already subscribed, ignored)

00:00:00.261 [I] P-Netif-------: ADD [M] ff02::16 (already subscribed, ignored)

00:00:00.261 [I] P-Netif-------: ADD [M] ff02::2 (rejected)

00:00:00.262 [D] P-SpinelDrive-: Sent spinel frame, flg:0x2, iid:0, tid:8, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:61, channel:25, maxbackoffs:4, maxretries:15 ...

00:00:00.262 [D] P-SpinelDrive-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0

00:00:00.263 [I] P-Netif-------: ADD [U] fe80::4ca8:ba83:9f61:326f

00:00:00.263 [D] P-Netif-------: Unexpected address type (6).

00:00:00.263 [D] P-Netif-------: Unexpected address type (8).

00:00:00.263 [I] P-Netif-------: Succeeded to process request#4

00:00:00.263 [I] P-Netif-------: ADD [U] fd1a:ffa6:4ae4:5eb1:5498:9531:eaa0:2f04

00:00:00.263 [D] P-Netif-------: Unexpected address type (6).

00:00:00.263 [D] P-Netif-------: Unexpected address type (8).

00:00:00.263 [I] P-Netif-------: Succeeded to process request#5

00:00:00.263 [I] P-Netif-------: ADD [U] fd1a:ffa6:4ae4:5eb1:0:ff:fe00:4800

00:00:00.263 [D] P-Netif-------: Unexpected address type (6).

00:00:00.263 [D] P-Netif-------: Unexpected address type (8).

00:00:00.263 [I] P-Netif-------: Host netif is up

00:00:00.263 [W] P-Netif-------: Failed to process request#6: No such process

s6-rc: info: service legacy-services successfully started

00:00:00.275 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:8, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK

00:00:00.275 [I] MeshForwarder-: Sent IPv6 UDP msg, len:82, chksum:be87, ecn:no, to:0xffff, sec:no, prio:net, radio:all

00:00:00.276 [I] MeshForwarder-: src:[fe80:0:0:0:4ca8:ba83:9f61:326f]:19788

00:00:00.276 [I] MeshForwarder-: dst:[ff02:0:0:0:0:0:0:2]:19788

00:00:00.778 [I] P-Netif-------: Message dropped by Thread

00:00:00.779 [I] P-Netif-------: ADD [M] ff33:40:fd1a:ffa6:4ae4:5eb1:0:1 (already subscribed, ignored)

00:00:00.779 [I] P-Netif-------: ADD [M] ff32:40:fd1a:ffa6:4ae4:5eb1:0:1 (already subscribed, ignored)

00:00:00.779 [I] P-Netif-------: ADD [M] ff03::fc (already subscribed, ignored)

00:00:00.779 [I] P-Netif-------: ADD [M] ff03::1 (already subscribed, ignored)

00:00:00.779 [I] P-Netif-------: ADD [M] ff02::16 (already subscribed, ignored)

00:00:00.779 [I] P-Netif-------: ADD [M] ff02::2 (rejected)

00:00:00.779 [I] P-Netif-------: Message dropped by Thread

00:00:00.780 [I] P-Netif-------: ADD [M] ff33:40:fd1a:ffa6:4ae4:5eb1:0:1 (already subscribed, ignored)

00:00:00.780 [I] P-Netif-------: ADD [M] ff32:40:fd1a:ffa6:4ae4:5eb1:0:1 (already subscribed, ignored)

00:00:00.780 [I] P-Netif-------: ADD [M] ff03::fc (already subscribed, ignored)

00:00:00.780 [I] P-Netif-------: ADD [M] ff03::1 (already subscribed, ignored)

00:00:00.780 [I] P-Netif-------: ADD [M] ff02::16 (already subscribed, ignored)

00:00:00.780 [I] P-Netif-------: ADD [M] ff02::2 (rejected)

00:00:00.780 [I] P-Netif-------: ADD [M] ff33:40:fd1a:ffa6:4ae4:5eb1:0:1 (already subscribed, ignored)

00:00:00.780 [I] P-Netif-------: ADD [M] ff32:40:fd1a:ffa6:4ae4:5eb1:0:1 (already subscribed, ignored)

00:00:00.780 [I] P-Netif-------: ADD [M] ff03::fc (already subscribed, ignored)

00:00:00.780 [I] P-Netif-------: ADD [M] ff03::1 (already subscribed, ignored)

00:00:00.780 [I] P-Netif-------: ADD [M] ff02::16 (already subscribed, ignored)

00:00:00.780 [I] P-Netif-------: ADD [M] ff02::2 (rejected)

00:00:00.781 [I] P-Netif-------: ADD [M] ff33:40:fd1a:ffa6:4ae4:5eb1:0:1 (already subscribed, ignored)

00:00:00.781 [I] P-Netif-------: ADD [M] ff32:40:fd1a:ffa6:4ae4:5eb1:0:1 (already subscribed, ignored)

00:00:00.781 [I] P-Netif-------: ADD [M] ff03::fc (already subscribed, ignored)

00:00:00.781 [I] P-Netif-------: ADD [M] ff03::1 (already subscribed, ignored)

00:00:00.781 [I] P-Netif-------: ADD [M] ff02::16 (already subscribed, ignored)

00:00:00.781 [I] P-Netif-------: ADD [M] ff02::2 (rejected)

00:00:01.069 [I] TrelDiscoverer: DNS-SD service registered successfully

00:00:01.070 [I] TrelPeerTable-: Added peer otTREL4ea8ba839f61326f, dnssd-state:resolving

00:00:01.071 [I] TrelDiscoverer: Peer otTREL4ea8ba839f61326f is this device itself

00:00:01.071 [I] TrelPeerTable-: Deleted peer otTREL4ea8ba839f61326f, dnssd-state:resolving

00:00:04.709 [I] Mle-----------: Send Link Request (ff02:0:0:0:0:0:0:2)

00:00:04.710 [D] P-SpinelDrive-: Sent spinel frame, flg:0x2, iid:0, tid:9, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:61, channel:25, maxbackoffs:4, maxretries:15 ...

00:00:04.710 [D] P-SpinelDrive-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0

00:00:04.725 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:9, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK

00:00:04.725 [I] MeshForwarder-: Sent IPv6 UDP msg, len:82, chksum:75c4, ecn:no, to:0xffff, sec:no, prio:net, radio:all

00:00:04.725 [I] MeshForwarder-: src:[fe80:0:0:0:4ca8:ba83:9f61:326f]:19788

00:00:04.725 [I] MeshForwarder-: dst:[ff02:0:0:0:0:0:0:2]:19788

00:00:09.578 [I] Mle-----------: Send Link Request (ff02:0:0:0:0:0:0:2)

00:00:09.579 [D] P-SpinelDrive-: Sent spinel frame, flg:0x2, iid:0, tid:10, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:61, channel:25, maxbackoffs:4, maxretries:15 ...

00:00:09.579 [D] P-SpinelDrive-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0

00:00:09.605 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:10, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK

00:00:09.605 [I] MeshForwarder-: Sent IPv6 UDP msg, len:82, chksum:1095, ecn:no, to:0xffff, sec:no, prio:net, radio:all

00:00:09.605 [I] MeshForwarder-: src:[fe80:0:0:0:4ca8:ba83:9f61:326f]:19788

00:00:09.605 [I] MeshForwarder-: dst:[ff02:0:0:0:0:0:0:2]:19788

00:00:14.591 [I] Mle-----------: Send Link Request (ff02:0:0:0:0:0:0:2)

00:00:14.592 [D] P-SpinelDrive-: Sent spinel frame, flg:0x2, iid:0, tid:11, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:61, channel:25, maxbackoffs:4, maxretries:15 ...

00:00:14.592 [D] P-SpinelDrive-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0

00:00:14.605 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:11, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK

00:00:14.605 [I] MeshForwarder-: Sent IPv6 UDP msg, len:82, chksum:a050, ecn:no, to:0xffff, sec:no, prio:net, radio:all

00:00:14.605 [I] MeshForwarder-: src:[fe80:0:0:0:4ca8:ba83:9f61:326f]:19788

00:00:14.605 [I] MeshForwarder-: dst:[ff02:0:0:0:0:0:0:2]:19788

00:00:19.824 [I] Mle-----------: Send Link Request (ff02:0:0:0:0:0:0:2)

00:00:19.825 [D] P-SpinelDrive-: Sent spinel frame, flg:0x2, iid:0, tid:12, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:61, channel:25, maxbackoffs:4, maxretries:15 ...

00:00:19.825 [D] P-SpinelDrive-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0

00:00:19.835 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:12, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK

00:00:19.835 [I] MeshForwarder-: Sent IPv6 UDP msg, len:82, chksum:aed9, ecn:no, to:0xffff, sec:no, prio:net, radio:all

00:00:19.835 [I] MeshForwarder-: src:[fe80:0:0:0:4ca8:ba83:9f61:326f]:19788

00:00:19.835 [I] MeshForwarder-: dst:[ff02:0:0:0:0:0:0:2]:19788

00:00:24.396 [I] Mle-----------: Send Link Request (ff02:0:0:0:0:0:0:2)

00:00:24.397 [D] P-SpinelDrive-: Sent spinel frame, flg:0x2, iid:0, tid:13, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:61, channel:25, maxbackoffs:4, maxretries:15 ...

00:00:24.397 [D] P-SpinelDrive-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0

00:00:24.415 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:13, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK

00:00:24.415 [I] MeshForwarder-: Sent IPv6 UDP msg, len:82, chksum:62e2, ecn:no, to:0xffff, sec:no, prio:net, radio:all

00:00:24.415 [I] MeshForwarder-: src:[fe80:0:0:0:4ca8:ba83:9f61:326f]:19788

00:00:24.415 [I] MeshForwarder-: dst:[ff02:0:0:0:0:0:0:2]:19788

00:00:26.396 [I] Mle-----------: Failed to restore prev role

00:00:26.396 [I] BbrLocal------: Remove BBR Service: seqno (24), delay (5s), timeout (3600s), NotFound

00:00:26.396 [N] Mle-----------: RLOC16 4800 -> fffe

00:00:26.396 [I] P-Netif-------: Sent request#7 to remove fd1a:ffa6:4ae4:5eb1:0:ff:fe00:4800/64

00:00:26.397 [D] P-SpinelDrive-: Sent spinel frame, flg:0x2, iid:0, tid:14, cmd:PROP_VALUE_SET, key:MAC_15_4_SADDR, saddr:0xfffe

00:00:26.397 [D] P-RadioSpinel-: Wait response: tid=14 key=53

00:00:26.399 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:14, cmd:PROP_VALUE_IS, key:MAC_15_4_SADDR, saddr:0xfffe

00:00:26.399 [I] Mle-----------: AttachState Idle -> Start

00:00:26.399 [I] Notifier------: StateChanged (0x00000040) [Rloc-]

00:00:26.405 [I] P-Netif-------: DEL [U] fd1a:ffa6:4ae4:5eb1:0:ff:fe00:4800 (not found, ignored)

00:00:26.405 [D] P-Netif-------: Unexpected address type (6).

00:00:26.405 [D] P-Netif-------: Unexpected address type (8).

00:00:26.405 [I] P-Netif-------: Succeeded to process request#7

00:00:26.965 [N] Mle-----------: Attach attempt 1, AnyPartition reattaching with Active Dataset

00:00:26.965 [I] Mle-----------: AttachState Start -> ParentReq

00:00:26.965 [I] Mle-----------: Send Parent Request to routers (ff02:0:0:0:0:0:0:2)

00:00:26.966 [D] P-SpinelDrive-: Sent spinel frame, flg:0x2, iid:0, tid:15, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:63, channel:25, maxbackoffs:4, maxretries:15 ...

00:00:26.966 [D] P-SpinelDrive-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0

00:00:26.985 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:15, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK

00:00:26.986 [I] MeshForwarder-: Sent IPv6 UDP msg, len:84, chksum:0eec, ecn:no, to:0xffff, sec:no, prio:net, radio:all

00:00:26.986 [I] MeshForwarder-: src:[fe80:0:0:0:4ca8:ba83:9f61:326f]:19788

00:00:26.986 [I] MeshForwarder-: dst:[ff02:0:0:0:0:0:0:2]:19788

00:00:27.715 [I] Mle-----------: Send Parent Request to routers (ff02:0:0:0:0:0:0:2)

00:00:27.717 [D] P-SpinelDrive-: Sent spinel frame, flg:0x2, iid:0, tid:1, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:63, channel:25, maxbackoffs:4, maxretries:15 ...

00:00:27.717 [D] P-SpinelDrive-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0

00:00:27.745 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:1, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK

00:00:27.745 [I] MeshForwarder-: Sent IPv6 UDP msg, len:84, chksum:91b6, ecn:no, to:0xffff, sec:no, prio:net, radio:all

00:00:27.746 [I] MeshForwarder-: src:[fe80:0:0:0:4ca8:ba83:9f61:326f]:19788

00:00:27.746 [I] MeshForwarder-: dst:[ff02:0:0:0:0:0:0:2]:19788

00:00:28.466 [I] Mle-----------: Send Parent Request to routers and REEDs (ff02:0:0:0:0:0:0:2)

00:00:28.467 [D] P-SpinelDrive-: Sent spinel frame, flg:0x2, iid:0, tid:2, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:63, channel:25, maxbackoffs:4, maxretries:15 ...

00:00:28.467 [D] P-SpinelDrive-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0

00:00:28.495 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:2, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK

00:00:28.495 [I] MeshForwarder-: Sent IPv6 UDP msg, len:84, chksum:a632, ecn:no, to:0xffff, sec:no, prio:net, radio:all

00:00:28.496 [I] MeshForwarder-: src:[fe80:0:0:0:4ca8:ba83:9f61:326f]:19788

00:00:28.496 [I] MeshForwarder-: dst:[ff02:0:0:0:0:0:0:2]:19788

00:00:29.716 [I] Mle-----------: Send Parent Request to routers and REEDs (ff02:0:0:0:0:0:0:2)

00:00:29.717 [D] P-SpinelDrive-: Sent spinel frame, flg:0x2, iid:0, tid:3, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:63, channel:25, maxbackoffs:4, maxretries:15 ...

00:00:29.717 [D] P-SpinelDrive-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0

00:00:29.735 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:3, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK

00:00:29.735 [I] MeshForwarder-: Sent IPv6 UDP msg, len:84, chksum:7edd, ecn:no, to:0xffff, sec:no, prio:net, radio:all

00:00:29.735 [I] MeshForwarder-: src:[fe80:0:0:0:4ca8:ba83:9f61:326f]:19788

00:00:29.735 [I] MeshForwarder-: dst:[ff02:0:0:0:0:0:0:2]:19788

00:00:30.966 [I] Mle-----------: Send Parent Request to routers and REEDs (ff02:0:0:0:0:0:0:2)

00:00:30.967 [D] P-SpinelDrive-: Sent spinel frame, flg:0x2, iid:0, tid:4, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:63, channel:25, maxbackoffs:4, maxretries:15 ...

00:00:30.967 [D] P-SpinelDrive-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0

00:00:30.995 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:4, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK

00:00:30.995 [I] MeshForwarder-: Sent IPv6 UDP msg, len:84, chksum:2862, ecn:no, to:0xffff, sec:no, prio:net, radio:all

00:00:30.995 [I] MeshForwarder-: src:[fe80:0:0:0:4ca8:ba83:9f61:326f]:19788

00:00:30.995 [I] MeshForwarder-: dst:[ff02:0:0:0:0:0:0:2]:19788

00:00:32.216 [I] Mle-----------: Send Parent Request to routers and REEDs (ff02:0:0:0:0:0:0:2)

00:00:32.217 [D] P-SpinelDrive-: Sent spinel frame, flg:0x2, iid:0, tid:5, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:63, channel:25, maxbackoffs:4, maxretries:15 ...

00:00:32.217 [D] P-SpinelDrive-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0

00:00:32.245 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:5, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK

00:00:32.245 [I] MeshForwarder-: Sent IPv6 UDP msg, len:84, chksum:04e8, ecn:no, to:0xffff, sec:no, prio:net, radio:all

00:00:32.245 [I] MeshForwarder-: src:[fe80:0:0:0:4ca8:ba83:9f61:326f]:19788

00:00:32.245 [I] MeshForwarder-: dst:[ff02:0:0:0:0:0:0:2]:19788

00:00:33.466 [I] Mle-----------: AttachState ParentReq -> Idle

00:00:33.466 [N] RouterTable---: Allocate router id 18

00:00:33.466 [N] Mle-----------: RLOC16 fffe -> 4800

00:00:33.467 [D] P-SpinelDrive-: Sent spinel frame, flg:0x2, iid:0, tid:6, cmd:PROP_VALUE_SET, key:MAC_15_4_SADDR, saddr:0x4800

00:00:33.467 [D] P-RadioSpinel-: Wait response: tid=6 key=53

00:00:33.469 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:6, cmd:PROP_VALUE_IS, key:MAC_15_4_SADDR, saddr:0x4800

00:00:33.469 [I] P-Netif-------: Sent request#8 to add fd1a:ffa6:4ae4:5eb1:0:ff:fe00:4800/64

00:00:33.469 [N] Mle-----------: Role detached -> leader

00:00:33.470 [I] P-Netif-------: Added multicast address ff02::2

00:00:33.470 [I] P-Netif-------: Added multicast address ff03::2

00:00:33.470 [I] P-Netif-------: Sent request#9 to add fd1a:ffa6:4ae4:5eb1:0:ff:fe00:fc00/64

00:00:33.471 [N] Mle-----------: Partition ID 0xc678e4c

00:00:33.472 [I] RouterTable---: Route table

00:00:33.472 [I] RouterTable---: 18 0x4800 - me - leader

00:00:33.472 [I] Notifier------: StateChanged (0x100012a5) [Ip6+ Role Rloc+ PartitionId NetData Ip6Mult+ ActDset]

00:00:33.473 [I] Mle-----------: Send Data Response (ff02:0:0:0:0:0:0:1)

00:00:33.486 [I] Settings------: Saved NetworkInfo {rloc:0x4800, extaddr:4ea8ba839f61326f, role:leader, mode:0x0f, version:5, keyseq:0x0, ...

00:00:33.487 [I] Settings------: ... pid:0xc678e4c, mlecntr:0x433f, maccntr:0x427a, mliid:54989531eaa02f04}

00:00:33.487 [I] BbrLeader-----: PBBR state: None

00:00:33.487 [I] AnnounceSender: Started

00:00:33.488 [I] BorderAgent---: Border Agent start listening on port 49154

00:00:33.488 [I] BorderRouting-: RIO Preference changed: low -> medium

00:00:33.488 [I] BorderRouting-: Starting

00:00:33.488 [I] BorderRouting-: RsSender: Starting - will send first RS in 595 msec

00:00:33.488 [I] BorderRouting-: RoutePublisher state: none -> ula

00:00:33.488 [I] NetDataPublshr: Publishing ExternalRoute fc00::/7

00:00:33.488 [I] NetDataPublshr: ExternalRoute fc00::/7 - State: NoEntry -> ToAdd

00:00:33.488 [I] NetDataPublshr: ExternalRoute fc00::/7 (state:ToAdd) in netdata - total:0, preferred:0, desired:10

00:00:33.488 [I] NetDataPublshr: ExternalRoute fc00::/7 - State: ToAdd -> Adding

00:00:33.488 [I] NetDataPublshr: ExternalRoute fc00::/7 (state:Adding) - update in 1000 msec

00:00:33.488 [I] BorderRouting-: Starting Nat64PrefixManager

00:00:33.488 [I] BorderRouting-: Will evaluate routing policy in 00:02.703 (2703 msec)

00:00:33.488 [I] MultiAilDetect: State: Stopped -> Running

00:00:33.489 [I] NetDataPublshr: ExternalRoute fc00::/7 (state:Adding) in netdata - total:0, preferred:0, desired:10

00:00:33.502 [I] Platform------: Execute command `ipset flush otbr-ingress-allow-dst-swap` = 0

00:00:33.514 [I] Platform------: Execute command `ipset flush otbr-ingress-deny-src-swap` = 0

00:00:33.525 [I] Platform------: Execute command `ipset add otbr-ingress-deny-src-swap fd1a:ffa6:4ae4:5eb1::/64 -exist` = 0

00:00:33.535 [I] Platform------: Execute command `ipset swap otbr-ingress-deny-src-swap otbr-ingress-deny-src` = 0

00:00:33.546 [I] Platform------: Execute command `ipset swap otbr-ingress-allow-dst-swap otbr-ingress-allow-dst` = 0

[INFO]-BA------: Start Thread Border Agent

00:00:33.547 [I] BorderRouting-: Will evaluate routing policy in 00:02.233 (2233 msec)

00:00:33.547 [I] BorderRouting-: NAT64 prefix timer scheduled in 300 seconds

00:00:33.547 [I] P-Netif-------: Succeeded to process request#8

00:00:33.550 [I] P-Netif-------: Message dropped by Thread

00:00:33.550 [I] P-Netif-------: ADD [U] fd1a:ffa6:4ae4:5eb1:0:ff:fe00:4800

00:00:33.551 [D] P-Netif-------: Unexpected address type (6).

00:00:33.551 [D] P-Netif-------: Unexpected address type (8).

00:00:33.551 [I] P-Netif-------: ADD [M] ff03::2 (already subscribed, ignored)

00:00:33.551 [I] P-Netif-------: ADD [M] ff33:40:fd1a:ffa6:4ae4:5eb1:0:1 (already subscribed, ignored)

00:00:33.552 [I] P-Netif-------: ADD [M] ff32:40:fd1a:ffa6:4ae4:5eb1:0:1 (already subscribed, ignored)

00:00:33.552 [I] P-Netif-------: ADD [M] ff03::fc (already subscribed, ignored)

00:00:33.552 [I] P-Netif-------: ADD [M] ff03::1 (already subscribed, ignored)

00:00:33.552 [I] P-Netif-------: ADD [M] ff02::16 (already subscribed, ignored)

00:00:33.552 [I] P-Netif-------: ADD [M] ff02::2 (already subscribed, ignored)

00:00:33.553 [I] P-Netif-------: Succeeded to process request#9

00:00:33.554 [I] P-Netif-------: ADD [M] ff03::2 (already subscribed, ignored)

00:00:33.554 [I] P-Netif-------: ADD [M] ff33:40:fd1a:ffa6:4ae4:5eb1:0:1 (already subscribed, ignored)

00:00:33.554 [I] P-Netif-------: ADD [M] ff32:40:fd1a:ffa6:4ae4:5eb1:0:1 (already subscribed, ignored)

00:00:33.554 [I] P-Netif-------: ADD [M] ff03::fc (already subscribed, ignored)

00:00:33.554 [I] P-Netif-------: ADD [M] ff03::1 (already subscribed, ignored)

00:00:33.554 [I] P-Netif-------: ADD [M] ff02::16 (already subscribed, ignored)

00:00:33.554 [I] P-Netif-------: ADD [M] ff02::2 (already subscribed, ignored)

00:00:33.555 [D] P-SpinelDrive-: Sent spinel frame, flg:0x2, iid:0, tid:7, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:75, channel:25, maxbackoffs:4, maxretries:15 ...

00:00:33.555 [D] P-SpinelDrive-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0

00:00:33.558 [I] P-Netif-------: ADD [U] fd1a:ffa6:4ae4:5eb1:0:ff:fe00:fc00

00:00:33.558 [D] P-Netif-------: Unexpected address type (6).

00:00:33.558 [D] P-Netif-------: Unexpected address type (8).

00:00:33.576 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:7, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK

00:00:33.576 [I] MeshForwarder-: Sent IPv6 UDP msg, len:96, chksum:6535, ecn:no, to:0xffff, sec:no, prio:net, radio:all

00:00:33.576 [I] MeshForwarder-: src:[fe80:0:0:0:4ca8:ba83:9f61:326f]:19788

00:00:33.576 [I] MeshForwarder-: dst:[ff02:0:0:0:0:0:0:1]:19788

00:00:33.724 [I] BbrLocal------: Add BBR Service: seqno (24), delay (5s), timeout (3600s), OK

00:00:33.724 [I] NetworkData---: Sent ServerData

00:00:33.725 [I] NetworkData---: Received ServerData

00:00:33.725 [I] NetworkData---: Allocated Service ID = 0

00:00:33.725 [I] NetworkData---: Sent ServerData ack

00:00:33.725 [I] Notifier------: StateChanged (0x00000200) [NetData]

00:00:33.725 [I] Mle-----------: Send Data Response (ff02:0:0:0:0:0:0:1)

00:00:33.726 [I] P-Netif-------: Sent request#10 to add fd1a:ffa6:4ae4:5eb1:0:ff:fe00:fc10/64

00:00:33.726 [I] BbrLeader-----: PBBR state: Added

00:00:33.726 [I] BbrLeader-----: Rloc16:0x4800, seqno:24, delay:5, timeout:3600

00:00:33.726 [I] P-Netif-------: Sent request#11 to add fd1a:ffa6:4ae4:5eb1:0:ff:fe00:fc38/64

00:00:33.726 [I] BorderRouting-: Will evaluate routing policy in 00:03.613 (3613 msec)

00:00:33.727 [I] NetDataPublshr: ExternalRoute fc00::/7 (state:Adding) in netdata - total:0, preferred:0, desired:10

00:00:33.742 [I] Platform------: Execute command `ipset flush otbr-ingress-allow-dst-swap` = 0

00:00:33.754 [I] Platform------: Execute command `ipset flush otbr-ingress-deny-src-swap` = 0

00:00:33.765 [I] Platform------: Execute command `ipset add otbr-ingress-deny-src-swap fd1a:ffa6:4ae4:5eb1::/64 -exist` = 0

00:00:33.776 [I] Platform------: Execute command `ipset swap otbr-ingress-deny-src-swap otbr-ingress-deny-src` = 0

00:00:33.785 [I] Platform------: Execute command `ipset swap otbr-ingress-allow-dst-swap otbr-ingress-allow-dst` = 0

00:00:33.786 [I] Notifier------: StateChanged (0x02000001) [Ip6+ BbrState]

00:00:33.786 [I] Bbr-----------: Start listening on port 61631

00:00:33.786 [I] Bbr-----------: Backbone TMF subscribes ff32:40:fd1a:ffa6:4ae4:5eb1:0:3: OK

00:00:33.786 [I] BbrManager----: Start Backbone TMF agent: OK

00:00:33.787 [I] P-McastRtMgr--: Enable: OK

[DEBG]-BBA-----: BackboneAgent: HandleBackboneRouterState: state=2, mBackboneRouterState=1

[NOTE]-BBA-----: BackboneAgent: Backbone Router becomes Primary!

00:00:33.789 [I] P-Netif-------: Message dropped by Thread

00:00:33.789 [I] P-Netif-------: Succeeded to process request#10

00:00:33.790 [I] P-Netif-------: ADD [M] ff03::2 (already subscribed, ignored)

00:00:33.790 [I] P-Netif-------: ADD [M] ff33:40:fd1a:ffa6:4ae4:5eb1:0:1 (already subscribed, ignored)

00:00:33.790 [I] P-Netif-------: ADD [M] ff32:40:fd1a:ffa6:4ae4:5eb1:0:1 (already subscribed, ignored)

00:00:33.790 [I] P-Netif-------: ADD [M] ff03::fc (already subscribed, ignored)

00:00:33.790 [I] P-Netif-------: ADD [M] ff03::1 (already subscribed, ignored)

00:00:33.790 [I] P-Netif-------: ADD [M] ff02::16 (already subscribed, ignored)

00:00:33.790 [I] P-Netif-------: ADD [M] ff02::2 (already subscribed, ignored)

00:00:33.792 [D] P-SpinelDrive-: Sent spinel frame, flg:0x2, iid:0, tid:8, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:91, channel:25, maxbackoffs:4, maxretries:15 ...

00:00:33.792 [D] P-SpinelDrive-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0

00:00:33.793 [I] P-Netif-------: ADD [U] fd1a:ffa6:4ae4:5eb1:0:ff:fe00:fc10

00:00:33.793 [D] P-Netif-------: Unexpected address type (6).

00:00:33.794 [D] P-Netif-------: Unexpected address type (8).

00:00:33.794 [I] P-Netif-------: ADD [M] ff03::2 (already subscribed, ignored)

00:00:33.794 [I] P-Netif-------: ADD [M] ff33:40:fd1a:ffa6:4ae4:5eb1:0:1 (already subscribed, ignored)

00:00:33.794 [I] P-Netif-------: ADD [M] ff32:40:fd1a:ffa6:4ae4:5eb1:0:1 (already subscribed, ignored)

00:00:33.794 [I] P-Netif-------: ADD [M] ff03::fc (already subscribed, ignored)

00:00:33.794 [I] P-Netif-------: ADD [M] ff03::1 (already subscribed, ignored)

00:00:33.794 [I] P-Netif-------: ADD [M] ff02::16 (already subscribed, ignored)

00:00:33.794 [I] P-Netif-------: ADD [M] ff02::2 (already subscribed, ignored)

00:00:33.795 [I] P-Netif-------: Succeeded to process request#11

00:00:33.796 [I] P-Netif-------: ADD [U] fd1a:ffa6:4ae4:5eb1:0:ff:fe00:fc38

00:00:33.797 [D] P-Netif-------: Unexpected address type (6).

00:00:33.797 [D] P-Netif-------: Unexpected address type (8).

00:00:33.806 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:8, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK

00:00:33.806 [I] MeshForwarder-: Sent IPv6 UDP msg, len:112, chksum:9be3, ecn:no, to:0xffff, sec:no, prio:net, radio:all

00:00:33.806 [I] MeshForwarder-: src:[fe80:0:0:0:4ca8:ba83:9f61:326f]:19788

00:00:33.806 [I] MeshForwarder-: dst:[ff02:0:0:0:0:0:0:1]:19788

00:00:34.083 [I] BorderRouting-: RsSender: Sent RS 1/3

00:00:34.084 [I] BorderRouting-: Received RS from fe80:0:0:0:8ee8:3052:565a:c49f on infra netif 2

00:00:34.117 [I] BorderRouting-: Received RA from fe80:0:0:0:ca4f:86ff:fefc:1 on infra netif 2

00:00:34.117 [I] BorderRouting-: - RA Header - flags - M:0 O:0 S:0

00:00:34.117 [I] BorderRouting-: - RA Header - default route - lifetime:1800

00:00:34.118 [I] BorderRouting-: - PIO fc00:110:0:0::/64 (valid:86400, preferred:14400, flags - L:1 A:1 P:0)

00:00:34.386 [I] Mle-----------: Send Advertisement (ff02:0:0:0:0:0:0:1)

00:00:34.387 [D] P-SpinelDrive-: Sent spinel frame, flg:0x2, iid:0, tid:9, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:69, channel:25, maxbackoffs:4, maxretries:15 ...

00:00:34.387 [D] P-SpinelDrive-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0

00:00:34.405 [D] P-SpinelDrive-: Received spinel frame, flg:0x2, iid:0, tid:9, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK

Just to be sure, can you tell me what is your serial device current name detected on /dev ? what firmware did you flash it with and what guide bring you to this point

Its /dev/ttyACM0. This is the firmware: esp-idf/examples/openthread/ot_rcp at v5.5.1 · espressif/esp-idf · GitHub.

this is the main guide I have been following. I have also been using the HA documentation.
https://openthread.io/guides/border-router

This suggests the otbr-agent process is crashing. I also use an esp32-h2 w/ot_rcp as my “dongle” and my container-based otbr also tends to stop working after a few days, with no obvious explanation in the logs. In fact if I run ps -ef I can verify that otbr-agent is not running until I restart the container.

Sorry I don’t have a repair for this (yet), but I don’t really use my otbr as I also have several HomePods Mini. But since we both are using the same dongle I might recommend trying a different one to see if you get different results. You could also perhaps try a different usb cable.

I think Unexpected address error seen on your logs might causing this issue. Maybe its related to your *home network environment ? Is this native install or docker install ?

I’ve spent the past day looking at OTBR logs (though I’m not an expert or anything) and I can’t see anything in your logs.

  • Maybe try disabling NAT64 in OTBR addon configuration?
  • Maybe you can try this guide, it uses the latest stable esp-idf toolchain. Disclaimer: I wrote it.
1 Like