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