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.

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

otbr-agent crash after around a week of uptime #2085

Open
thedevleon opened this issue Nov 3, 2023 · 8 comments
Open

otbr-agent crash after around a week of uptime #2085

thedevleon opened this issue Nov 3, 2023 · 8 comments

Comments

@thedevleon
Copy link

thedevleon commented Nov 3, 2023

Describe the bug
The otbr-agent in the docker container crashes after around a week of uptime.

To Reproduce Information to reproduce the behavior, including:

  1. Git commit id -> docker container openthread/otbr@sha256:78543c07c08650044a35e6e938ae787f0bf48b059dd8a82883a14e97ce5c86cd
  2. IEEE 802.15.4 hardware platform -> esp32-c6 with ot_rcp connected via UART to Raspberry Pi 4
  3. Build steps
docker run -d -it --name otbr \
  --restart always \
  --sysctl "net.ipv6.conf.all.disable_ipv6=0 net.ipv4.conf.all.forwarding=1 net.ipv6.conf.all.forwarding=1" \
  -p 8080:80 \
  --dns=127.0.0.1 \
  --privileged \
  openthread/otbr@sha256:78543c07c08650044a35e6e938ae787f0bf48b059dd8a82883a14e97ce5c86cd --radio-url "spinel+hdlc+uart:///dev/ttyAMA0?uart-baudrate=460800"
  1. Network topology -> around 30 devices

Expected behavior
ot-agent shouldn't crash ;) And even if it does, it should either restart itself, or crash the docker container so that docker automatically restarts the container.

Console/log output

We have 4 pi's running the otbr docker image with around 30 devices each. Here are the 4 logs from each:

Oct 29 08:46:17 128f62455490 otbr-agent[200]: 2d.17:57:39.120 [I] MeshForwarder-: Sent IPv6 UDP msg, len:60, chksum:e2f2, ecn:no, to:0x2000, sec:yes, prio:low
Oct 29 08:46:17 128f62455490 otbr-agent[200]: 2d.17:57:39.120 [I] MeshForwarder-:     src:[fd3a:c703:91ab:2:0:0:34f:5ca3]:5683
Oct 29 08:46:17 128f62455490 otbr-agent[200]: 2d.17:57:39.121 [I] MeshForwarder-:     dst:[fd3a:c703:91ab:1:8b36:810d:eb40:9778]:59372
Oct 29 08:46:17 128f62455490 otbr-agent[200]: 2d.17:57:39.393 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:98, rssi:-93 ...
Oct 29 08:46:17 128f62455490 otbr-agent[200]: 2d.17:57:39.393 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:16, lqi:9, timestamp:237492347702, rxerr:0
Oct 29 08:46:17 128f62455490 otbr-agent[200]: 2d.17:57:39.394 [I] MeshForwarder-: Received IPv6 UDP msg, len:85, chksum:d044, ecn:no, from:0x3002, sec:yes, prio:normal, rss:-93.0
Oct 29 08:46:17 128f62455490 otbr-agent[200]: 2d.17:57:39.394 [I] MeshForwarder-:     src:[fd3a:c703:91ab:1:ad57:a49f:2ce2:9010]:49153
Oct 29 08:46:17 128f62455490 otbr-agent[200]: 2d.17:57:39.394 [I] MeshForwarder-:     dst:[fd3a:c703:91ab:2:0:0:101:101]:53
Oct 29 08:46:17 128f62455490 otbr-agent[200]: 2d.17:57:39.464 [D] P-RadioSpinel-: Sent spinel frame, flg:0x2, tid:12, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:115, channel:16, maxbackoffs:4, maxretries:15 ...
Oct 29 08:46:17 128f62455490 otbr-agent[200]: 2d.17:57:39.464 [D] P-RadioSpinel-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0
Oct 29 08:46:17 128f62455490 otbr-agent[200]: 2d.17:57:39.481 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:12, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Oct 29 08:46:17 128f62455490 otbr-agent[200]: 2d.17:57:39.482 [I] MeshForwarder-: Sent IPv6 UDP msg, len:101, chksum:3a83, ecn:no, to:0x3000, sec:yes, prio:low
Oct 29 08:46:17 128f62455490 otbr-agent[200]: 2d.17:57:39.482 [I] MeshForwarder-:     src:[fd3a:c703:91ab:2:0:0:101:101]:53
Oct 29 08:46:17 128f62455490 otbr-agent[200]: 2d.17:57:39.482 [I] MeshForwarder-:     dst:[fd3a:c703:91ab:1:ad57:a49f:2ce2:9010]:49153
Oct 29 08:46:17 128f62455490 otbr-agent[200]: 2d.17:57:39.659 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:84, rssi:-88 ...
Oct 29 08:46:17 128f62455490 otbr-agent[200]: 2d.17:57:39.659 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:16, lqi:9, timestamp:237492614156, rxerr:0
Oct 29 08:46:17 128f62455490 otbr-agent[200]: 2d.17:57:39.659 [I] MeshForwarder-: Received IPv6 UDP msg, len:105, chksum:37d0, ecn:no, from:3e6393904d361d4c, sec:no, prio:net, rss:-88.0
Oct 29 08:46:17 128f62455490 otbr-agent[200]: 2d.17:57:39.660 [I] MeshForwarder-:     src:[fe80:0:0:0:3c63:9390:4d36:1d4c]:19788
Oct 29 08:46:17 128f62455490 otbr-agent[200]: 2d.17:57:39.660 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
Oct 29 08:46:17 128f62455490 otbr-agent[200]: 2d.17:57:39.660 [I] Mle-----------: Receive Advertisement (fe80:0:0:0:3c63:9390:4d36:1d4c,0x9400)
Oct 29 08:46:18 128f62455490 otbr-agent[200]: 2d.17:57:40.721 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:84, rssi:-91 ...
Oct 29 08:46:18 128f62455490 otbr-agent[200]: 2d.17:57:40.721 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:16, lqi:8, timestamp:237493675909, rxerr:0
Oct 29 08:46:18 128f62455490 otbr-agent[200]: 2d.17:57:40.721 [I] MeshForwarder-: Received IPv6 UDP msg, len:105, chksum:969a, ecn:no, from:3e3704f490444d44, sec:no, prio:net, rss:-91.0
Oct 29 08:46:18 128f62455490 otbr-agent[200]: 2d.17:57:40.722 [I] MeshForwarder-:     src:[fe80:0:0:0:3c37:4f4:9044:4d44]:19788
Oct 29 08:46:18 128f62455490 otbr-agent[200]: 2d.17:57:40.722 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
Oct 29 08:46:18 128f62455490 otbr-agent[200]: 2d.17:57:40.722 [I] Mle-----------: Receive Advertisement (fe80:0:0:0:3c37:4f4:9044:4d44,0x3c00)
Oct 29 08:46:19 128f62455490 otbr-agent[200]: 2d.17:57:41.620 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:84, rssi:-88 ...
Oct 29 08:46:19 128f62455490 otbr-agent[200]: 2d.17:57:41.620 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:16, lqi:10, timestamp:237494575288, rxerr:0
Oct 29 08:46:19 128f62455490 otbr-agent[200]: 2d.17:57:41.621 [I] MeshForwarder-: Received IPv6 UDP msg, len:105, chksum:62d1, ecn:no, from:ce52403a21fca490, sec:no, prio:net, rss:-88.0
Oct 29 08:46:19 128f62455490 otbr-agent[200]: 2d.17:57:41.621 [I] MeshForwarder-:     src:[fe80:0:0:0:cc52:403a:21fc:a490]:19788
Oct 29 08:46:19 128f62455490 otbr-agent[200]: 2d.17:57:41.621 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
Oct 29 08:46:19 128f62455490 otbr-agent[200]: 2d.17:57:41.621 [I] Mle-----------: Receive Advertisement (fe80:0:0:0:cc52:403a:21fc:a490,0xa400)
Oct 29 08:46:20 128f62455490 otbr-agent[200]: 2d.17:57:42.132 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:84, rssi:-100 ...
Oct 29 08:46:20 128f62455490 otbr-agent[200]: 2d.17:57:42.132 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:16, lqi:8, timestamp:237495086985, rxerr:0
Oct 29 08:46:20 128f62455490 otbr-agent[200]: 2d.17:57:42.132 [I] MeshForwarder-: Received IPv6 UDP msg, len:105, chksum:5d55, ecn:no, from:028e479a88c5fceb, sec:no, prio:net, rss:-100.0
Oct 29 08:46:20 128f62455490 otbr-agent[200]: 2d.17:57:42.133 [I] MeshForwarder-:     src:[fe80:0:0:0:8e:479a:88c5:fceb]:19788
Oct 29 08:46:20 128f62455490 otbr-agent[200]: 2d.17:57:42.133 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
Oct 29 08:46:20 128f62455490 otbr-agent[200]: 2d.17:57:42.133 [I] Mle-----------: Receive Advertisement (fe80:0:0:0:8e:479a:88c5:fceb,0xf000)
Oct 29 08:46:21 128f62455490 otbr-agent[200]: 2d.17:57:43.680 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:84, rssi:-101 ...
Oct 29 08:46:21 128f62455490 otbr-agent[200]: 2d.17:57:43.680 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:16, lqi:4, timestamp:237496635087, rxerr:0
Oct 29 08:46:21 128f62455490 otbr-agent[200]: 2d.17:57:43.680 [I] MeshForwarder-: Received IPv6 UDP msg, len:105, chksum:71c8, ecn:no, from:ae7be1bd4880d56b, sec:no, prio:net, rss:-101.0
Oct 29 08:46:21 128f62455490 otbr-agent[200]: 2d.17:57:43.681 [I] MeshForwarder-:     src:[fe80:0:0:0:ac7b:e1bd:4880:d56b]:19788
Oct 29 08:46:21 128f62455490 otbr-agent[200]: 2d.17:57:43.681 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
Oct 29 08:46:21 128f62455490 otbr-agent[200]: 2d.17:57:43.681 [I] Mle-----------: Receive Advertisement (fe80:0:0:0:ac7b:e1bd:4880:d56b,0xa000)
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:44.941 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:123, rssi:-104 ...
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:44.941 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:16, lqi:5, timestamp:237497895221, rxerr:0
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.001 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:123, rssi:-101 ...
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.001 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:16, lqi:4, timestamp:237497954975, rxerr:0
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.001 [I] Mac-----------: Frame rx failed, error:Duplicated, len:123, seqnum:207, type:Data, src:0x4800, dst:0x6800, sec:yes, ackreq:yes
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.004 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:54, rssi:-103 ...
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.005 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:16, lqi:4, timestamp:237497960337, rxerr:0
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.005 [I] MeshForwarder-: Received IPv6 UDP msg, len:140, chksum:e87a, ecn:no, from:0x4800, sec:yes, prio:normal, rss:-103.5
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.005 [I] MeshForwarder-:     src:[fd3a:c703:91ab:1:bec1:b66f:6f01:4ac7]:62306
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.005 [I] MeshForwarder-:     dst:[fd3a:c703:91ab:2:0:0:34f:5ca3]:5683
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.016 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:123, rssi:-102 ...
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.016 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:16, lqi:6, timestamp:237497970280, rxerr:0
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.024 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:122, rssi:-107 ...
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.024 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:16, lqi:7, timestamp:237497978427, rxerr:0
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.031 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:101, rssi:-102 ...
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.031 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:16, lqi:5, timestamp:237497985717, rxerr:0
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.031 [I] MeshForwarder-: Received IPv6 UDP msg, len:283, chksum:bb5f, ecn:no, from:0x4800, sec:yes, prio:normal, rss:-103.625
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.032 [I] MeshForwarder-:     src:[fd3a:c703:91ab:1:bec1:b66f:6f01:4ac7]:62306
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.032 [I] MeshForwarder-:     dst:[fd3a:c703:91ab:2:0:0:34f:5ca3]:5683
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.046 [D] P-RadioSpinel-: Sent spinel frame, flg:0x2, tid:13, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:70, channel:16, maxbackoffs:4, maxretries:15 ...
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.046 [D] P-RadioSpinel-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.060 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:13, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.060 [I] MeshForwarder-: Sent IPv6 UDP msg, len:62, chksum:5920, ecn:no, to:0x4800, sec:yes, prio:low
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.060 [I] MeshForwarder-:     src:[fd3a:c703:91ab:2:0:0:34f:5ca3]:5683
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.061 [I] MeshForwarder-:     dst:[fd3a:c703:91ab:1:bec1:b66f:6f01:4ac7]:62306
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.070 [D] P-RadioSpinel-: Sent spinel frame, flg:0x2, tid:14, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:68, channel:16, maxbackoffs:4, maxretries:15 ...
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.070 [D] P-RadioSpinel-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.096 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:123, rssi:-102 ...
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.096 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:16, lqi:6, timestamp:237498050192, rxerr:0
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.097 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:14, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.097 [I] MeshForwarder-: Sent IPv6 UDP msg, len:60, chksum:a663, ecn:no, to:0x4800, sec:yes, prio:low
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.097 [I] MeshForwarder-:     src:[fd3a:c703:91ab:2:0:0:34f:5ca3]:5683
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.097 [I] MeshForwarder-:     dst:[fd3a:c703:91ab:1:bec1:b66f:6f01:4ac7]:62306
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.112 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:122, rssi:-103 ...
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.112 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:16, lqi:5, timestamp:237498066210, rxerr:0
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.120 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:93, rssi:-101 ...
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.120 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:16, lqi:6, timestamp:237498075032, rxerr:0
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.120 [I] MeshForwarder-: Received IPv6 UDP msg, len:275, chksum:5e5a, ecn:no, from:0x4800, sec:yes, prio:normal, rss:-102.0
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.120 [I] MeshForwarder-:     src:[fd3a:c703:91ab:1:bec1:b66f:6f01:4ac7]:62306
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.121 [I] MeshForwarder-:     dst:[fd3a:c703:91ab:2:0:0:34f:5ca3]:5683
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.168 [D] P-RadioSpinel-: Sent spinel frame, flg:0x2, tid:15, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:68, channel:16, maxbackoffs:4, maxretries:15 ...
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.168 [D] P-RadioSpinel-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.213 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:15, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.213 [W] P-RadioSpinel-: Handle radio frame failed: Parse
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.213 [W] P-RadioSpinel-: Handle transmit done failed: Parse
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.214 [C] Platform------: ------------------ BEGINNING OF CRASH -------------
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.214 [C] Platform------: *** FATAL ERROR: Caught signal: 6 (Aborted)
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.225 [C] Platform------: # 0: /usr/sbin/otbr-agent(+0x2bc6e0) [0x5576a9c6e0]
Oct 29 08:46:23 128f62455490 otbr-agent[200]: 2d.17:57:45.225 [C] Platform------: ------------------ END OF CRASH ------------------
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.525 [D] P-RadioSpinel-: Sent spinel frame, flg:0x2, tid:5, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:68, channel:11, maxbackoffs:4, maxretries:15 ...
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.525 [D] P-RadioSpinel-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.528 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:123, rssi:-78 ...
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.528 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:10, timestamp:597462909928, rxerr:0
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.536 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:122, rssi:-78 ...
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.536 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:10, timestamp:597462917495, rxerr:0
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.537 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:5, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.537 [I] MeshForwarder-: Sent IPv6 UDP msg, len:60, chksum:63de, ecn:no, to:0xe400, sec:yes, prio:low
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.537 [I] MeshForwarder-:     src:[fd10:5b3e:f160:2:0:0:34f:5ca3]:5683
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.538 [I] MeshForwarder-:     dst:[fd10:5b3e:f160:1:be23:f61e:cd81:8d90]:43693
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.544 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:95, rssi:-78 ...
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.544 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:10, timestamp:597462926546, rxerr:0
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.545 [I] MeshForwarder-: Received IPv6 UDP msg, len:277, chksum:c14b, ecn:no, from:0xe400, sec:yes, prio:normal, rss:-78.0
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.545 [I] MeshForwarder-:     src:[fd10:5b3e:f160:1:be23:f61e:cd81:8d90]:43693
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.545 [I] MeshForwarder-:     dst:[fd10:5b3e:f160:2:0:0:34f:5ca3]:5683
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.573 [D] P-RadioSpinel-: Sent spinel frame, flg:0x2, tid:6, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:68, channel:11, maxbackoffs:4, maxretries:15 ...
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.573 [D] P-RadioSpinel-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.592 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:6, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.593 [I] MeshForwarder-: Sent IPv6 UDP msg, len:60, chksum:a02c, ecn:no, to:0xe400, sec:yes, prio:low
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.593 [I] MeshForwarder-:     src:[fd10:5b3e:f160:2:0:0:34f:5ca3]:5683
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.593 [I] MeshForwarder-:     dst:[fd10:5b3e:f160:1:be23:f61e:cd81:8d90]:43693
Nov  2 08:00:25 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:17.604 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:83, rssi:-85 ...
Nov  2 08:00:25 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:17.604 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:9, timestamp:597464986189, rxerr:0
Nov  2 08:00:25 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:17.604 [I] MeshForwarder-: Received IPv6 UDP msg, len:104, chksum:c77f, ecn:no, from:4aaa38eed734f919, sec:no, prio:net, rss:-85.0
Nov  2 08:00:25 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:17.605 [I] MeshForwarder-:     src:[fe80:0:0:0:48aa:38ee:d734:f919]:19788
Nov  2 08:00:25 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:17.605 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
Nov  2 08:00:25 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:17.605 [I] Mle-----------: Receive Advertisement (fe80:0:0:0:48aa:38ee:d734:f919,0x1400)
Nov  2 08:00:26 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.402 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:78, rssi:-85 ...
Nov  2 08:00:26 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.402 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:10, timestamp:597465784499, rxerr:0
Nov  2 08:00:26 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.403 [I] MeshForwarder-: Received IPv6 UDP msg, len:83, chksum:6f90, ecn:no, from:3a1868db3e3a1d57, sec:no, prio:net, rss:-85.0
Nov  2 08:00:26 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.403 [I] MeshForwarder-:     src:[fe80:0:0:0:3818:68db:3e3a:1d57]:19788
Nov  2 08:00:26 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.403 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.921 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:83, rssi:-71 ...
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.922 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:11, timestamp:597466303737, rxerr:0
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.922 [I] MeshForwarder-: Received IPv6 UDP msg, len:104, chksum:70dc, ecn:no, from:6e08f249140d6189, sec:no, prio:net, rss:-71.0
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.922 [I] MeshForwarder-:     src:[fe80:0:0:0:6c08:f249:140d:6189]:19788
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.922 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.923 [I] Mle-----------: Receive Advertisement (fe80:0:0:0:6c08:f249:140d:6189,0xcc00)
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.968 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:83, rssi:-79 ...
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.968 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:10, timestamp:597466350148, rxerr:0
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.968 [I] MeshForwarder-: Received IPv6 UDP msg, len:104, chksum:47bb, ecn:no, from:6aa816a0e2d2f045, sec:no, prio:net, rss:-79.0
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.969 [I] MeshForwarder-:     src:[fe80:0:0:0:68a8:16a0:e2d2:f045]:19788
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.969 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.969 [I] Mle-----------: Receive Advertisement (fe80:0:0:0:68a8:16a0:e2d2:f045,0xe400)
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.772 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:123, rssi:-69 ...
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.772 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:10, timestamp:597467152988, rxerr:0
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.776 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:54, rssi:-69 ...
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.777 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:10, timestamp:597467159347, rxerr:0
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.777 [I] MeshForwarder-: Received IPv6 UDP msg, len:140, chksum:198d, ecn:no, from:0x2400, sec:yes, prio:normal, rss:-69.0
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.777 [I] MeshForwarder-:     src:[fd10:5b3e:f160:1:3035:5deb:868a:4adb]:53415
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.777 [I] MeshForwarder-:     dst:[fd10:5b3e:f160:2:0:0:34f:5ca3]:5683
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.808 [D] P-RadioSpinel-: Sent spinel frame, flg:0x2, tid:7, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:70, channel:11, maxbackoffs:4, maxretries:15 ...
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.808 [D] P-RadioSpinel-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.823 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:7, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.823 [I] MeshForwarder-: Sent IPv6 UDP msg, len:62, chksum:b6d2, ecn:no, to:0x2400, sec:yes, prio:low
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.823 [I] MeshForwarder-:     src:[fd10:5b3e:f160:2:0:0:34f:5ca3]:5683
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.823 [I] MeshForwarder-:     dst:[fd10:5b3e:f160:1:3035:5deb:868a:4adb]:53415
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.843 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:123, rssi:-69 ...
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.844 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:10, timestamp:597467224869, rxerr:0
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.851 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:122, rssi:-69 ...
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.851 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:10, timestamp:597467232527, rxerr:0
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.861 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:122, rssi:-69 ...
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.861 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:10, timestamp:597467242373, rxerr:0
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.864 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:36, rssi:-69 ...
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.865 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:10, timestamp:597467247789, rxerr:0
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.865 [I] MeshForwarder-: Received IPv6 UDP msg, len:314, chksum:1511, ecn:no, from:0x2400, sec:yes, prio:normal, rss:-69.0
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.865 [I] MeshForwarder-:     src:[fd10:5b3e:f160:1:3035:5deb:868a:4adb]:53415
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.865 [I] MeshForwarder-:     dst:[fd10:5b3e:f160:2:0:0:34f:5ca3]:5683
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.900 [D] P-RadioSpinel-: Sent spinel frame, flg:0x2, tid:8, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:68, channel:11, maxbackoffs:4, maxretries:15 ...
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.900 [D] P-RadioSpinel-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.915 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:80, rssi:-104 ...
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.915 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:5, timestamp:597467296926, rxerr:0
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.915 [I] MeshForwarder-: Received IPv6 UDP msg, len:96, chksum:117d, ecn:no, from:3a9afdb74dc1ce7a, sec:no, prio:net, rss:-104.0
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.915 [I] MeshForwarder-:     src:[fe80:0:0:0:389a:fdb7:4dc1:ce7a]:19788
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.915 [I] MeshForwarder-:     dst:[fe80:0:0:0:c47c:6f6d:bffb:1aee]:19788
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.916 [I] Mle-----------: Receive Link Request (fe80:0:0:0:389a:fdb7:4dc1:ce7a)
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.916 [I] Mle-----------: Send Link Accept (fe80:0:0:0:389a:fdb7:4dc1:ce7a)
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.916 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:8, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.916 [I] MeshForwarder-: Sent IPv6 UDP msg, len:60, chksum:f9c2, ecn:no, to:0x2400, sec:yes, prio:low
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.917 [I] MeshForwarder-:     src:[fd10:5b3e:f160:2:0:0:34f:5ca3]:5683
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.917 [I] MeshForwarder-:     dst:[fd10:5b3e:f160:1:3035:5deb:868a:4adb]:53415
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.917 [D] P-RadioSpinel-: Sent spinel frame, flg:0x2, tid:9, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:117, channel:11, maxbackoffs:4, maxretries:15 ...
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.917 [D] P-RadioSpinel-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.950 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:80, rssi:-99 ...
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.950 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:4, timestamp:597467332205, rxerr:0
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.950 [I] MeshForwarder-: Received IPv6 UDP msg, len:96, chksum:117d, ecn:no, from:3a9afdb74dc1ce7a, sec:no, prio:net, rss:-99.0
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.950 [I] MeshForwarder-:     src:[fe80:0:0:0:389a:fdb7:4dc1:ce7a]:19788
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.951 [I] MeshForwarder-:     dst:[fe80:0:0:0:c47c:6f6d:bffb:1aee]:19788
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.951 [W] Mle-----------: Failed to process UDP: Duplicated
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:20.247 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:9, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:20.247 [W] P-RadioSpinel-: Handle radio frame failed: Parse
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:20.247 [W] P-RadioSpinel-: Handle transmit done failed: Parse
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:20.248 [C] Platform------: ------------------ BEGINNING OF CRASH -------------
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:20.248 [C] Platform------: *** FATAL ERROR: Caught signal: 6 (Aborted)
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:20.260 [C] Platform------: # 0: /usr/sbin/otbr-agent(+0x2bc6e0) [0x5581e7c6e0]
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:20.260 [C] Platform------: ------------------ END OF CRASH ------------------
Nov  2 08:28:47 fb1b6f5f5d29 avahi-daemon[164]: Withdrawing address record for fd11:1111:1122:2221:42:acff:fe11:2 on eth0.
Nov  2 08:28:47 fb1b6f5f5d29 avahi-daemon[164]: Leaving mDNS multicast group on interface eth0.IPv6 with address fd11:1111:1122:2221:42:acff:fe11:2.
Nov  2 08:28:47 fb1b6f5f5d29 avahi-daemon[164]: Joining mDNS multicast group on interface eth0.IPv6 with address fe80::42:acff:fe11:2.
Nov  2 08:28:47 fb1b6f5f5d29 avahi-daemon[164]: Registering new address record for fe80::42:acff:fe11:2 on eth0.*.
Oct 27 12:32:30 8826213816e4 otbr-agent[200]: 03:11:51.690 [D] P-RadioSpinel-: Sent spinel frame, flg:0x2, tid:3, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:68, channel:15, maxbackoffs:4, maxretries:15 ...
Oct 27 12:32:30 8826213816e4 otbr-agent[200]: 03:11:51.690 [D] P-RadioSpinel-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0
Oct 27 12:32:30 8826213816e4 otbr-agent[200]: 03:11:51.703 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:3, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Oct 27 12:32:30 8826213816e4 otbr-agent[200]: 03:11:51.703 [I] MeshForwarder-: Sent IPv6 UDP msg, len:60, chksum:96ae, ecn:no, to:0x2c00, sec:yes, prio:low
Oct 27 12:32:30 8826213816e4 otbr-agent[200]: 03:11:51.704 [I] MeshForwarder-:     src:[fd9b:4dd6:b34d:2:0:0:34f:5ca3]:5683
Oct 27 12:32:30 8826213816e4 otbr-agent[200]: 03:11:51.704 [I] MeshForwarder-:     dst:[fd9b:4dd6:b34d:1:7fe7:4ddc:fdd4:1280]:39657
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:51.864 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:71, rssi:-81 ...
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:51.865 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:9, timestamp:81167406632, rxerr:0
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:51.865 [I] MeshForwarder-: Received IPv6 UDP msg, len:87, chksum:f5e8, ecn:no, from:cee05fb24ce7ad73, sec:no, prio:net, rss:-81.0
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:51.866 [I] MeshForwarder-:     src:[fe80:0:0:0:cce0:5fb2:4ce7:ad73]:19788
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:51.866 [I] MeshForwarder-:     dst:[fe80:0:0:0:88e:5d5e:8daf:63bf]:19788
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:51.866 [I] Mle-----------: Receive Child Update Request from child (fe80:0:0:0:cce0:5fb2:4ce7:ad73)
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:51.867 [I] Mle-----------: Send Child Update Response to child (fe80:0:0:0:cce0:5fb2:4ce7:ad73,0x9811)
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:51.867 [D] P-RadioSpinel-: Sent spinel frame, flg:0x2, tid:4, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:71, channel:15, maxbackoffs:4, maxretries:15 ...
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:51.868 [D] P-RadioSpinel-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:51.953 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:4, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:51.953 [I] MeshForwarder-: Sent IPv6 UDP msg, len:87, chksum:f360, ecn:no, to:cee05fb24ce7ad73, sec:no, prio:net
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:51.954 [I] MeshForwarder-:     src:[fe80:0:0:0:88e:5d5e:8daf:63bf]:19788
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:51.954 [I] MeshForwarder-:     dst:[fe80:0:0:0:cce0:5fb2:4ce7:ad73]:19788
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:52.526 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:86, rssi:-84 ...
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:52.526 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:9, timestamp:81168067826, rxerr:0
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:52.527 [I] MeshForwarder-: Received IPv6 UDP msg, len:107, chksum:24eb, ecn:no, from:3e08ca05c6e6299c, sec:no, prio:net, rss:-84.0
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:52.527 [I] MeshForwarder-:     src:[fe80:0:0:0:3c08:ca05:c6e6:299c]:19788
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:52.527 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:52.528 [I] Mle-----------: Receive Advertisement (fe80:0:0:0:3c08:ca05:c6e6:299c,0x3c00)
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:52.703 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:86, rssi:-84 ...
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:52.704 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:9, timestamp:81168245108, rxerr:0
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:52.704 [I] MeshForwarder-: Received IPv6 UDP msg, len:107, chksum:0020, ecn:no, from:6a0b95204df75439, sec:no, prio:net, rss:-84.0
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:52.704 [I] MeshForwarder-:     src:[fe80:0:0:0:680b:9520:4df7:5439]:19788
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:52.704 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
Oct 27 12:32:31 8826213816e4 otbr-agent[200]: 03:11:52.705 [I] Mle-----------: Receive Advertisement (fe80:0:0:0:680b:9520:4df7:5439,0x2800)
Oct 27 12:32:32 8826213816e4 otbr-agent[200]: 03:11:52.877 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:123, rssi:-87 ...
Oct 27 12:32:32 8826213816e4 otbr-agent[200]: 03:11:52.877 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:9, timestamp:81168417601, rxerr:0
Oct 27 12:32:32 8826213816e4 otbr-agent[200]: 03:11:52.881 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:54, rssi:-91 ...
Oct 27 12:32:32 8826213816e4 otbr-agent[200]: 03:11:52.881 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:7, timestamp:81168423522, rxerr:0
Oct 27 12:32:32 8826213816e4 otbr-agent[200]: 03:11:52.882 [I] MeshForwarder-: Received IPv6 UDP msg, len:140, chksum:1843, ecn:no, from:0x9819, sec:yes, prio:normal, rss:-89.0
Oct 27 12:32:32 8826213816e4 otbr-agent[200]: 03:11:52.882 [I] MeshForwarder-:     src:[fd9b:4dd6:b34d:1:db8d:f45c:5c55:6090]:33694
Oct 27 12:32:32 8826213816e4 otbr-agent[200]: 03:11:52.882 [I] MeshForwarder-:     dst:[fd9b:4dd6:b34d:2:0:0:34f:5ca3]:5683
Oct 27 12:32:32 8826213816e4 otbr-agent[200]: 03:11:52.899 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:123, rssi:-89 ...
Oct 27 12:32:32 8826213816e4 otbr-agent[200]: 03:11:52.899 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:8, timestamp:81168439791, rxerr:0
Oct 27 12:32:32 8826213816e4 otbr-agent[200]: 03:11:52.907 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:122, rssi:-86 ...
Oct 27 12:32:32 8826213816e4 otbr-agent[200]: 03:11:52.908 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:8, timestamp:81168448045, rxerr:0
Oct 27 12:32:32 8826213816e4 otbr-agent[200]: 03:11:52.925 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:122, rssi:-86 ...
Oct 27 12:32:32 8826213816e4 otbr-agent[200]: 03:11:52.925 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:8, timestamp:81168465608, rxerr:0
Oct 27 12:32:32 8826213816e4 otbr-agent[200]: 03:11:52.927 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:43, rssi:-91 ...
Oct 27 12:32:32 8826213816e4 otbr-agent[200]: 03:11:52.928 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:8, timestamp:81168470365, rxerr:0
Oct 27 12:32:32 8826213816e4 otbr-agent[200]: 03:11:52.928 [I] MeshForwarder-: Received IPv6 UDP msg, len:321, chksum:79ea, ecn:no, from:0x9819, sec:yes, prio:normal, rss:-88.0
Oct 27 12:32:32 8826213816e4 otbr-agent[200]: 03:11:52.928 [I] MeshForwarder-:     src:[fd9b:4dd6:b34d:1:db8d:f45c:5c55:6090]:33694
Oct 27 12:32:32 8826213816e4 otbr-agent[200]: 03:11:52.928 [I] MeshForwarder-:     dst:[fd9b:4dd6:b34d:2:0:0:34f:5ca3]:5683
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.192 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:123, rssi:-77 ...
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.192 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:9, timestamp:81169732690, rxerr:0
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.198 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:54, rssi:-77 ...
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.198 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:9, timestamp:81169740301, rxerr:0
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.198 [I] MeshForwarder-: Received IPv6 UDP msg, len:140, chksum:229f, ecn:no, from:0x0800, sec:yes, prio:normal, rss:-77.0
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.198 [I] MeshForwarder-:     src:[fd9b:4dd6:b34d:1:7339:e7ef:fdc:e6e]:61872
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.198 [I] MeshForwarder-:     dst:[fd9b:4dd6:b34d:2:0:0:34f:5ca3]:5683
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.215 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:123, rssi:-78 ...
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.215 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:9, timestamp:81169756021, rxerr:0
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.224 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:122, rssi:-79 ...
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.224 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:10, timestamp:81169765037, rxerr:0
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.231 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:101, rssi:-78 ...
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.232 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:9, timestamp:81169772912, rxerr:0
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.232 [I] MeshForwarder-: Received IPv6 UDP msg, len:283, chksum:e8ad, ecn:no, from:0x0800, sec:yes, prio:normal, rss:-78.25
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.232 [I] MeshForwarder-:     src:[fd9b:4dd6:b34d:1:7339:e7ef:fdc:e6e]:61872
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.232 [I] MeshForwarder-:     dst:[fd9b:4dd6:b34d:2:0:0:34f:5ca3]:5683
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.329 [D] P-RadioSpinel-: Sent spinel frame, flg:0x2, tid:5, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:70, channel:15, maxbackoffs:4, maxretries:15 ...
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.329 [D] P-RadioSpinel-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.343 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:5, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.343 [I] MeshForwarder-: Sent IPv6 UDP msg, len:62, chksum:a56f, ecn:no, to:0x9819, sec:yes, prio:low
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.344 [I] MeshForwarder-:     src:[fd9b:4dd6:b34d:2:0:0:34f:5ca3]:5683
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.344 [I] MeshForwarder-:     dst:[fd9b:4dd6:b34d:1:db8d:f45c:5c55:6090]:33694
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.344 [D] P-RadioSpinel-: Sent spinel frame, flg:0x2, tid:6, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:68, channel:15, maxbackoffs:4, maxretries:15 ...
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.344 [D] P-RadioSpinel-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.353 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:6, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.353 [I] MeshForwarder-: Sent IPv6 UDP msg, len:60, chksum:bc3d, ecn:no, to:0x9819, sec:yes, prio:low
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.354 [I] MeshForwarder-:     src:[fd9b:4dd6:b34d:2:0:0:34f:5ca3]:5683
Oct 27 12:32:33 8826213816e4 otbr-agent[200]: 03:11:54.354 [I] MeshForwarder-:     dst:[fd9b:4dd6:b34d:1:db8d:f45c:5c55:6090]:33694
Oct 27 12:32:34 8826213816e4 otbr-agent[200]: 03:11:55.306 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:80, rssi:-97 ...
Oct 27 12:32:34 8826213816e4 otbr-agent[200]: 03:11:55.307 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:7, timestamp:81170848418, rxerr:0
Oct 27 12:32:34 8826213816e4 otbr-agent[200]: 03:11:55.307 [I] MeshForwarder-: Received IPv6 UDP msg, len:96, chksum:7fab, ecn:no, from:e673394b3cf4996b, sec:no, prio:net, rss:-97.0
Oct 27 12:32:34 8826213816e4 otbr-agent[200]: 03:11:55.308 [I] MeshForwarder-:     src:[fe80:0:0:0:e473:394b:3cf4:996b]:19788
Oct 27 12:32:34 8826213816e4 otbr-agent[200]: 03:11:55.308 [I] MeshForwarder-:     dst:[fe80:0:0:0:88e:5d5e:8daf:63bf]:19788
Oct 27 12:32:34 8826213816e4 otbr-agent[200]: 03:11:55.309 [I] Mle-----------: Receive Link Request (fe80:0:0:0:e473:394b:3cf4:996b)
Oct 27 12:32:34 8826213816e4 otbr-agent[200]: 03:11:55.309 [I] Mle-----------: Send Link Accept and Request (fe80:0:0:0:e473:394b:3cf4:996b)
Oct 27 12:32:34 8826213816e4 otbr-agent[200]: 03:11:55.310 [D] P-RadioSpinel-: Sent spinel frame, flg:0x2, tid:7, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:126, channel:15, maxbackoffs:4, maxretries:15 ...
Oct 27 12:32:34 8826213816e4 otbr-agent[200]: 03:11:55.310 [D] P-RadioSpinel-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0
Oct 27 12:32:34 8826213816e4 otbr-agent[200]: 03:11:55.658 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:7, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Oct 27 12:32:34 8826213816e4 otbr-agent[200]: 03:11:55.658 [W] P-RadioSpinel-: Handle radio frame failed: Parse
Oct 27 12:32:34 8826213816e4 otbr-agent[200]: 03:11:55.659 [W] P-RadioSpinel-: Handle transmit done failed: Parse
Oct 27 12:32:34 8826213816e4 otbr-agent[200]: 03:11:55.659 [C] Platform------: ------------------ BEGINNING OF CRASH -------------
Oct 27 12:32:34 8826213816e4 otbr-agent[200]: 03:11:55.659 [C] Platform------: *** FATAL ERROR: Caught signal: 6 (Aborted)
Oct 27 12:32:34 8826213816e4 otbr-agent[200]: 03:11:55.660 [C] Platform------: # 0: /usr/sbin/otbr-agent(+0x2bc6e0) [0x558220c6e0]
Oct 27 12:32:34 8826213816e4 otbr-agent[200]: 03:11:55.661 [C] Platform------: ------------------ END OF CRASH ------------------
Oct 27 13:01:12 8826213816e4 avahi-daemon[164]: Withdrawing address record for fd11:1111:1122:2223:42:acff:fe11:2 on eth0.
Oct 27 13:01:12 8826213816e4 avahi-daemon[164]: Leaving mDNS multicast group on interface eth0.IPv6 with address fd11:1111:1122:2223:42:acff:fe11:2.
Oct 27 13:01:12 8826213816e4 avahi-daemon[164]: Joining mDNS multicast group on interface eth0.IPv6 with address fe80::42:acff:fe11:2.
Oct 27 13:01:12 8826213816e4 avahi-daemon[164]: Registering new address record for fe80::42:acff:fe11:2 on eth0.*.
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.525 [D] P-RadioSpinel-: Sent spinel frame, flg:0x2, tid:5, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:68, channel:11, maxbackoffs:4, maxretries:15 ...
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.525 [D] P-RadioSpinel-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.528 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:123, rssi:-78 ...
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.528 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:10, timestamp:597462909928, rxerr:0
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.536 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:122, rssi:-78 ...
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.536 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:10, timestamp:597462917495, rxerr:0
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.537 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:5, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.537 [I] MeshForwarder-: Sent IPv6 UDP msg, len:60, chksum:63de, ecn:no, to:0xe400, sec:yes, prio:low
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.537 [I] MeshForwarder-:     src:[fd10:5b3e:f160:2:0:0:34f:5ca3]:5683
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.538 [I] MeshForwarder-:     dst:[fd10:5b3e:f160:1:be23:f61e:cd81:8d90]:43693
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.544 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:95, rssi:-78 ...
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.544 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:10, timestamp:597462926546, rxerr:0
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.545 [I] MeshForwarder-: Received IPv6 UDP msg, len:277, chksum:c14b, ecn:no, from:0xe400, sec:yes, prio:normal, rss:-78.0
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.545 [I] MeshForwarder-:     src:[fd10:5b3e:f160:1:be23:f61e:cd81:8d90]:43693
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.545 [I] MeshForwarder-:     dst:[fd10:5b3e:f160:2:0:0:34f:5ca3]:5683
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.573 [D] P-RadioSpinel-: Sent spinel frame, flg:0x2, tid:6, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:68, channel:11, maxbackoffs:4, maxretries:15 ...
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.573 [D] P-RadioSpinel-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.592 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:6, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.593 [I] MeshForwarder-: Sent IPv6 UDP msg, len:60, chksum:a02c, ecn:no, to:0xe400, sec:yes, prio:low
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.593 [I] MeshForwarder-:     src:[fd10:5b3e:f160:2:0:0:34f:5ca3]:5683
Nov  2 08:00:23 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:15.593 [I] MeshForwarder-:     dst:[fd10:5b3e:f160:1:be23:f61e:cd81:8d90]:43693
Nov  2 08:00:25 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:17.604 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:83, rssi:-85 ...
Nov  2 08:00:25 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:17.604 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:9, timestamp:597464986189, rxerr:0
Nov  2 08:00:25 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:17.604 [I] MeshForwarder-: Received IPv6 UDP msg, len:104, chksum:c77f, ecn:no, from:4aaa38eed734f919, sec:no, prio:net, rss:-85.0
Nov  2 08:00:25 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:17.605 [I] MeshForwarder-:     src:[fe80:0:0:0:48aa:38ee:d734:f919]:19788
Nov  2 08:00:25 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:17.605 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
Nov  2 08:00:25 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:17.605 [I] Mle-----------: Receive Advertisement (fe80:0:0:0:48aa:38ee:d734:f919,0x1400)
Nov  2 08:00:26 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.402 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:78, rssi:-85 ...
Nov  2 08:00:26 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.402 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:10, timestamp:597465784499, rxerr:0
Nov  2 08:00:26 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.403 [I] MeshForwarder-: Received IPv6 UDP msg, len:83, chksum:6f90, ecn:no, from:3a1868db3e3a1d57, sec:no, prio:net, rss:-85.0
Nov  2 08:00:26 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.403 [I] MeshForwarder-:     src:[fe80:0:0:0:3818:68db:3e3a:1d57]:19788
Nov  2 08:00:26 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.403 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.921 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:83, rssi:-71 ...
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.922 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:11, timestamp:597466303737, rxerr:0
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.922 [I] MeshForwarder-: Received IPv6 UDP msg, len:104, chksum:70dc, ecn:no, from:6e08f249140d6189, sec:no, prio:net, rss:-71.0
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.922 [I] MeshForwarder-:     src:[fe80:0:0:0:6c08:f249:140d:6189]:19788
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.922 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.923 [I] Mle-----------: Receive Advertisement (fe80:0:0:0:6c08:f249:140d:6189,0xcc00)
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.968 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:83, rssi:-79 ...
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.968 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:10, timestamp:597466350148, rxerr:0
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.968 [I] MeshForwarder-: Received IPv6 UDP msg, len:104, chksum:47bb, ecn:no, from:6aa816a0e2d2f045, sec:no, prio:net, rss:-79.0
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.969 [I] MeshForwarder-:     src:[fe80:0:0:0:68a8:16a0:e2d2:f045]:19788
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.969 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:18.969 [I] Mle-----------: Receive Advertisement (fe80:0:0:0:68a8:16a0:e2d2:f045,0xe400)
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.772 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:123, rssi:-69 ...
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.772 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:10, timestamp:597467152988, rxerr:0
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.776 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:54, rssi:-69 ...
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.777 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:10, timestamp:597467159347, rxerr:0
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.777 [I] MeshForwarder-: Received IPv6 UDP msg, len:140, chksum:198d, ecn:no, from:0x2400, sec:yes, prio:normal, rss:-69.0
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.777 [I] MeshForwarder-:     src:[fd10:5b3e:f160:1:3035:5deb:868a:4adb]:53415
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.777 [I] MeshForwarder-:     dst:[fd10:5b3e:f160:2:0:0:34f:5ca3]:5683
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.808 [D] P-RadioSpinel-: Sent spinel frame, flg:0x2, tid:7, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:70, channel:11, maxbackoffs:4, maxretries:15 ...
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.808 [D] P-RadioSpinel-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.823 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:7, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.823 [I] MeshForwarder-: Sent IPv6 UDP msg, len:62, chksum:b6d2, ecn:no, to:0x2400, sec:yes, prio:low
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.823 [I] MeshForwarder-:     src:[fd10:5b3e:f160:2:0:0:34f:5ca3]:5683
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.823 [I] MeshForwarder-:     dst:[fd10:5b3e:f160:1:3035:5deb:868a:4adb]:53415
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.843 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:123, rssi:-69 ...
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.844 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:10, timestamp:597467224869, rxerr:0
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.851 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:122, rssi:-69 ...
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.851 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:10, timestamp:597467232527, rxerr:0
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.861 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:122, rssi:-69 ...
Nov  2 08:00:27 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.861 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:10, timestamp:597467242373, rxerr:0
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.864 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:36, rssi:-69 ...
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.865 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:10, timestamp:597467247789, rxerr:0
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.865 [I] MeshForwarder-: Received IPv6 UDP msg, len:314, chksum:1511, ecn:no, from:0x2400, sec:yes, prio:normal, rss:-69.0
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.865 [I] MeshForwarder-:     src:[fd10:5b3e:f160:1:3035:5deb:868a:4adb]:53415
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.865 [I] MeshForwarder-:     dst:[fd10:5b3e:f160:2:0:0:34f:5ca3]:5683
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.900 [D] P-RadioSpinel-: Sent spinel frame, flg:0x2, tid:8, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:68, channel:11, maxbackoffs:4, maxretries:15 ...
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.900 [D] P-RadioSpinel-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.915 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:80, rssi:-104 ...
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.915 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:5, timestamp:597467296926, rxerr:0
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.915 [I] MeshForwarder-: Received IPv6 UDP msg, len:96, chksum:117d, ecn:no, from:3a9afdb74dc1ce7a, sec:no, prio:net, rss:-104.0
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.915 [I] MeshForwarder-:     src:[fe80:0:0:0:389a:fdb7:4dc1:ce7a]:19788
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.915 [I] MeshForwarder-:     dst:[fe80:0:0:0:c47c:6f6d:bffb:1aee]:19788
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.916 [I] Mle-----------: Receive Link Request (fe80:0:0:0:389a:fdb7:4dc1:ce7a)
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.916 [I] Mle-----------: Send Link Accept (fe80:0:0:0:389a:fdb7:4dc1:ce7a)
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.916 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:8, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.916 [I] MeshForwarder-: Sent IPv6 UDP msg, len:60, chksum:f9c2, ecn:no, to:0x2400, sec:yes, prio:low
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.917 [I] MeshForwarder-:     src:[fd10:5b3e:f160:2:0:0:34f:5ca3]:5683
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.917 [I] MeshForwarder-:     dst:[fd10:5b3e:f160:1:3035:5deb:868a:4adb]:53415
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.917 [D] P-RadioSpinel-: Sent spinel frame, flg:0x2, tid:9, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:117, channel:11, maxbackoffs:4, maxretries:15 ...
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.917 [D] P-RadioSpinel-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.950 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:80, rssi:-99 ...
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.950 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:11, lqi:4, timestamp:597467332205, rxerr:0
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.950 [I] MeshForwarder-: Received IPv6 UDP msg, len:96, chksum:117d, ecn:no, from:3a9afdb74dc1ce7a, sec:no, prio:net, rss:-99.0
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.950 [I] MeshForwarder-:     src:[fe80:0:0:0:389a:fdb7:4dc1:ce7a]:19788
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.951 [I] MeshForwarder-:     dst:[fe80:0:0:0:c47c:6f6d:bffb:1aee]:19788
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:19.951 [W] Mle-----------: Failed to process UDP: Duplicated
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:20.247 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:9, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:20.247 [W] P-RadioSpinel-: Handle radio frame failed: Parse
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:20.247 [W] P-RadioSpinel-: Handle transmit done failed: Parse
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:20.248 [C] Platform------: ------------------ BEGINNING OF CRASH -------------
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:20.248 [C] Platform------: *** FATAL ERROR: Caught signal: 6 (Aborted)
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:20.260 [C] Platform------: # 0: /usr/sbin/otbr-agent(+0x2bc6e0) [0x5581e7c6e0]
Nov  2 08:00:28 fb1b6f5f5d29 otbr-agent[200]: 6d.21:57:20.260 [C] Platform------: ------------------ END OF CRASH ------------------
Nov  2 08:28:47 fb1b6f5f5d29 avahi-daemon[164]: Withdrawing address record for fd11:1111:1122:2221:42:acff:fe11:2 on eth0.
Nov  2 08:28:47 fb1b6f5f5d29 avahi-daemon[164]: Leaving mDNS multicast group on interface eth0.IPv6 with address fd11:1111:1122:2221:42:acff:fe11:2.
Nov  2 08:28:47 fb1b6f5f5d29 avahi-daemon[164]: Joining mDNS multicast group on interface eth0.IPv6 with address fe80::42:acff:fe11:2.
Nov  2 08:28:47 fb1b6f5f5d29 avahi-daemon[164]: Registering new address record for fe80::42:acff:fe11:2 on eth0.*.

Additional context Add any other context about the problem here.

@thedevleon
Copy link
Author

thedevleon commented Nov 6, 2023

Just had another crash after 3 days. Before the crash, we were sending a good amount of big packets, as 8 devices were receiving OTAs via CoAP block-wise transfer with a chunk size of 1024.

Nov  6 11:37:29 128f62455490 otbr-agent[200]: 2d.22:10:21.455 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:123, rssi:-81 ...
Nov  6 11:37:29 128f62455490 otbr-agent[200]: 2d.22:10:21.455 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:16, lqi:9, timestamp:938961714397, rxerr:0
Nov  6 11:37:29 128f62455490 otbr-agent[200]: 2d.22:10:21.459 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:49, rssi:-80 ...
Nov  6 11:37:29 128f62455490 otbr-agent[200]: 2d.22:10:21.459 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:16, lqi:11, timestamp:938961720156, rxerr:0
Nov  6 11:37:29 128f62455490 otbr-agent[200]: 2d.22:10:21.459 [I] MeshForwarder-: Received IPv6 UDP msg, len:135, chksum:d068, ecn:no, from:0xd400, sec:yes, prio:normal, rss:-80.5
Nov  6 11:37:29 128f62455490 otbr-agent[200]: 2d.22:10:21.460 [I] MeshForwarder-:     src:[fd3a:c703:91ab:1:9ca8:2073:403a:f4bd]:34962
Nov  6 11:37:29 128f62455490 otbr-agent[200]: 2d.22:10:21.460 [I] MeshForwarder-:     dst:[fd3a:c703:91ab:2:0:0:34f:5ca3]:5683
Nov  6 11:37:29 128f62455490 otbr-agent[200]: 2d.22:10:21.466 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:9, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Nov  6 11:37:29 128f62455490 otbr-agent[200]: 2d.22:10:21.466 [W] P-RadioSpinel-: Handle radio frame failed: Parse
Nov  6 11:37:29 128f62455490 otbr-agent[200]: 2d.22:10:21.466 [W] P-RadioSpinel-: Handle transmit done failed: Parse
Nov  6 11:37:29 128f62455490 otbr-agent[200]: 2d.22:10:21.467 [C] Platform------: ------------------ BEGINNING OF CRASH -------------
Nov  6 11:37:29 128f62455490 otbr-agent[200]: 2d.22:10:21.467 [C] Platform------: *** FATAL ERROR: Caught signal: 6 (Aborted)
Nov  6 11:37:29 128f62455490 otbr-agent[200]: 2d.22:10:21.469 [C] Platform------: # 0: /usr/sbin/otbr-agent(+0x2bc6e0) [0x555b07c6e0]
Nov  6 11:37:29 128f62455490 otbr-agent[200]: 2d.22:10:21.469 [C] Platform------: ------------------ END OF CRASH ------------------

@thedevleon
Copy link
Author

Yet another after 5 days:

Nov  8 22:34:43 8826213816e4 otbr-agent[200]: 5d.09:08:12.131 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:44, rssi:-67 ...
Nov  8 22:34:43 8826213816e4 otbr-agent[200]: 5d.09:08:12.131 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:10, timestamp:1154095791000, rxerr:0
Nov  8 22:34:43 8826213816e4 otbr-agent[200]: 5d.09:08:12.131 [I] MeshForwarder-: Received IPv6 UDP msg, len:322, chksum:9057, ecn:no, from:0xac00, sec:yes, prio:normal, rss:-66.625
Nov  8 22:34:43 8826213816e4 otbr-agent[200]: 5d.09:08:12.131 [I] MeshForwarder-:     src:[fd9b:4dd6:b34d:1:7e24:5ec4:ecc8:235b]:55369
Nov  8 22:34:43 8826213816e4 otbr-agent[200]: 5d.09:08:12.132 [I] MeshForwarder-:     dst:[fd9b:4dd6:b34d:2:0:0:34f:5ca3]:5683
Nov  8 22:34:43 8826213816e4 otbr-agent[200]: 5d.09:08:12.144 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:123, rssi:-84 ...
Nov  8 22:34:43 8826213816e4 otbr-agent[200]: 5d.09:08:12.144 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:10, timestamp:1154095802636, rxerr:0
Nov  8 22:34:43 8826213816e4 otbr-agent[200]: 5d.09:08:12.153 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:122, rssi:-86 ...
Nov  8 22:34:43 8826213816e4 otbr-agent[200]: 5d.09:08:12.153 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:9, timestamp:1154095811165, rxerr:0
Nov  8 22:34:44 8826213816e4 otbr-agent[200]: 5d.09:08:12.162 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:122, rssi:-87 ...
Nov  8 22:34:44 8826213816e4 otbr-agent[200]: 5d.09:08:12.163 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:9, timestamp:1154095820686, rxerr:0
Nov  8 22:34:44 8826213816e4 otbr-agent[200]: 5d.09:08:12.167 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:38, rssi:-84 ...
Nov  8 22:34:44 8826213816e4 otbr-agent[200]: 5d.09:08:12.167 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:9, timestamp:1154095827084, rxerr:0
Nov  8 22:34:44 8826213816e4 otbr-agent[200]: 5d.09:08:12.167 [I] MeshForwarder-: Received IPv6 UDP msg, len:316, chksum:8ef9, ecn:no, from:0xd800, sec:yes, prio:normal, rss:-85.125
Nov  8 22:34:44 8826213816e4 otbr-agent[200]: 5d.09:08:12.168 [I] MeshForwarder-:     src:[fd9b:4dd6:b34d:1:3a61:fa47:c2a1:5b93]:61703
Nov  8 22:34:44 8826213816e4 otbr-agent[200]: 5d.09:08:12.168 [I] MeshForwarder-:     dst:[fd9b:4dd6:b34d:2:0:0:34f:5ca3]:5683
Nov  8 22:34:44 8826213816e4 otbr-agent[200]: 5d.09:08:12.169 [D] P-RadioSpinel-: Sent spinel frame, flg:0x2, tid:3, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:68, channel:15, maxbackoffs:4, maxretries:15 ...
Nov  8 22:34:44 8826213816e4 otbr-agent[200]: 5d.09:08:12.169 [D] P-RadioSpinel-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0
Nov  8 22:34:44 8826213816e4 otbr-agent[200]: 5d.09:08:12.196 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:3, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Nov  8 22:34:44 8826213816e4 otbr-agent[200]: 5d.09:08:12.196 [I] MeshForwarder-: Sent IPv6 UDP msg, len:60, chksum:119d, ecn:no, to:0xac00, sec:yes, prio:low
Nov  8 22:34:44 8826213816e4 otbr-agent[200]: 5d.09:08:12.196 [I] MeshForwarder-:     src:[fd9b:4dd6:b34d:2:0:0:34f:5ca3]:5683
Nov  8 22:34:44 8826213816e4 otbr-agent[200]: 5d.09:08:12.196 [I] MeshForwarder-:     dst:[fd9b:4dd6:b34d:1:7e24:5ec4:ecc8:235b]:55369
Nov  8 22:34:44 8826213816e4 otbr-agent[200]: 5d.09:08:12.204 [D] P-RadioSpinel-: Sent spinel frame, flg:0x2, tid:4, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:68, channel:15, maxbackoffs:4, maxretries:15 ...
Nov  8 22:34:44 8826213816e4 otbr-agent[200]: 5d.09:08:12.204 [D] P-RadioSpinel-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0
Nov  8 22:34:44 8826213816e4 otbr-agent[200]: 5d.09:08:12.226 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:4, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Nov  8 22:34:44 8826213816e4 otbr-agent[200]: 5d.09:08:12.226 [I] MeshForwarder-: Sent IPv6 UDP msg, len:60, chksum:f45f, ecn:no, to:0xd800, sec:yes, prio:low
Nov  8 22:34:44 8826213816e4 otbr-agent[200]: 5d.09:08:12.226 [I] MeshForwarder-:     src:[fd9b:4dd6:b34d:2:0:0:34f:5ca3]:5683
Nov  8 22:34:44 8826213816e4 otbr-agent[200]: 5d.09:08:12.226 [I] MeshForwarder-:     dst:[fd9b:4dd6:b34d:1:3a61:fa47:c2a1:5b93]:61703
Nov  8 22:34:45 8826213816e4 otbr-agent[200]: 5d.09:08:14.015 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:86, rssi:-93 ...
Nov  8 22:34:45 8826213816e4 otbr-agent[200]: 5d.09:08:14.015 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:7, timestamp:1154097674122, rxerr:0
Nov  8 22:34:45 8826213816e4 otbr-agent[200]: 5d.09:08:14.015 [I] MeshForwarder-: Received IPv6 UDP msg, len:107, chksum:7bf8, ecn:no, from:c6a22f1a7f6fdac8, sec:no, prio:net, rss:-93.0
Nov  8 22:34:45 8826213816e4 otbr-agent[200]: 5d.09:08:14.016 [I] MeshForwarder-:     src:[fe80:0:0:0:c4a2:2f1a:7f6f:dac8]:19788
Nov  8 22:34:45 8826213816e4 otbr-agent[200]: 5d.09:08:14.016 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
Nov  8 22:34:45 8826213816e4 otbr-agent[200]: 5d.09:08:14.016 [I] Mle-----------: Receive Advertisement (fe80:0:0:0:c4a2:2f1a:7f6f:dac8,0xa800)
Nov  8 22:34:46 8826213816e4 otbr-agent[200]: 5d.09:08:15.110 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:71, rssi:-72 ...
Nov  8 22:34:46 8826213816e4 otbr-agent[200]: 5d.09:08:15.110 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:11, timestamp:1154098769603, rxerr:0
Nov  8 22:34:46 8826213816e4 otbr-agent[200]: 5d.09:08:15.111 [I] MeshForwarder-: Received IPv6 UDP msg, len:87, chksum:b475, ecn:no, from:c6fb9ad3cff93e9e, sec:no, prio:net, rss:-72.0
Nov  8 22:34:46 8826213816e4 otbr-agent[200]: 5d.09:08:15.111 [I] MeshForwarder-:     src:[fe80:0:0:0:c4fb:9ad3:cff9:3e9e]:19788
Nov  8 22:34:46 8826213816e4 otbr-agent[200]: 5d.09:08:15.111 [I] MeshForwarder-:     dst:[fe80:0:0:0:88e:5d5e:8daf:63bf]:19788
Nov  8 22:34:46 8826213816e4 otbr-agent[200]: 5d.09:08:15.111 [I] Mle-----------: Receive Child Update Request from child (fe80:0:0:0:c4fb:9ad3:cff9:3e9e)
Nov  8 22:34:46 8826213816e4 otbr-agent[200]: 5d.09:08:15.112 [I] Mle-----------: Send Child Update Response to child (fe80:0:0:0:c4fb:9ad3:cff9:3e9e,0x9884)
Nov  8 22:34:46 8826213816e4 otbr-agent[200]: 5d.09:08:15.112 [D] P-RadioSpinel-: Sent spinel frame, flg:0x2, tid:5, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:71, channel:15, maxbackoffs:4, maxretries:15 ...
Nov  8 22:34:46 8826213816e4 otbr-agent[200]: 5d.09:08:15.112 [D] P-RadioSpinel-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0
Nov  8 22:34:46 8826213816e4 otbr-agent[200]: 5d.09:08:15.126 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:5, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Nov  8 22:34:46 8826213816e4 otbr-agent[200]: 5d.09:08:15.126 [I] MeshForwarder-: Sent IPv6 UDP msg, len:87, chksum:f0a6, ecn:no, to:c6fb9ad3cff93e9e, sec:no, prio:net
Nov  8 22:34:46 8826213816e4 otbr-agent[200]: 5d.09:08:15.126 [I] MeshForwarder-:     src:[fe80:0:0:0:88e:5d5e:8daf:63bf]:19788
Nov  8 22:34:46 8826213816e4 otbr-agent[200]: 5d.09:08:15.126 [I] MeshForwarder-:     dst:[fe80:0:0:0:c4fb:9ad3:cff9:3e9e]:19788
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:15.327 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:101, rssi:-88 ...
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:15.327 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:7, timestamp:1154098985290, rxerr:0
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:15.327 [I] MeshForwarder-: Received IPv6 UDP msg, len:94, chksum:dd0d, ecn:no, from:0x9888, sec:yes, prio:normal, rss:-88.0
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:15.328 [I] MeshForwarder-:     src:[fd9b:4dd6:b34d:1:564f:f666:64c0:4c7f]:36395
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:15.328 [I] MeshForwarder-:     dst:[fd9b:4dd6:b34d:2:0:0:34f:5ca3]:5683
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:15.360 [D] P-RadioSpinel-: Sent spinel frame, flg:0x2, tid:6, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:69, channel:15, maxbackoffs:4, maxretries:15 ...
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:15.360 [D] P-RadioSpinel-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:15.386 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:6, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:15.386 [I] MeshForwarder-: Sent IPv6 UDP msg, len:61, chksum:125e, ecn:no, to:0x9888, sec:yes, prio:low
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:15.386 [I] MeshForwarder-:     src:[fd9b:4dd6:b34d:2:0:0:34f:5ca3]:5683
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:15.386 [I] MeshForwarder-:     dst:[fd9b:4dd6:b34d:1:564f:f666:64c0:4c7f]:36395
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:15.943 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:121, rssi:-98 ...
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:15.943 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:7, timestamp:1154099600887, rxerr:0
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:15.952 [I] Mle-----------: Router timeout expired
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:15.952 [I] Mle-----------: Send Link Request (fe80:0:0:0:a038:8ba7:d8ae:4ea5)
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:15.953 [D] P-RadioSpinel-: Sent spinel frame, flg:0x2, tid:7, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:80, channel:15, maxbackoffs:4, maxretries:15 ...
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:15.953 [D] P-RadioSpinel-: ... csmaCaEnabled:1, isHeaderUpdated:0, isARetx:0, skipAes:0, txDelay:0, txDelayBase:0
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.120 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:0, cmd:PROP_VALUE_IS, key:STREAM_RAW, len:120, rssi:-95 ...
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.120 [D] P-RadioSpinel-: ... noise:-128, flags:0x0000, channel:15, lqi:8, timestamp:1154099777772, rxerr:0
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.120 [I] MeshForwarder-: Received IPv6 UDP msg, len:136, chksum:a83e, ecn:no, from:a2388ba7d8ae4ea5, sec:no, prio:net, rss:-95.0
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.121 [I] MeshForwarder-:     src:[fe80:0:0:0:a038:8ba7:d8ae:4ea5]:19788
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.121 [I] MeshForwarder-:     dst:[fe80:0:0:0:88e:5d5e:8daf:63bf]:19788
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.121 [I] Mle-----------: Receive Link Accept (fe80:0:0:0:a038:8ba7:d8ae:4ea5,0x1000)
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.122 [I] RouterTable---: Route table
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.122 [I] RouterTable---:     50 0xc800 - nbr{lq[i/o]:3/3 cost:1} - nexthop{62 cost:1}
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.122 [I] RouterTable---:     43 0xac00 - nbr{lq[i/o]:3/3 cost:1} - nexthop{51 cost:1}
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.122 [I] RouterTable---:     14 0x3800 - nexthop{34 cost:1}
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.122 [I] RouterTable---:     51 0xcc00 - nbr{lq[i/o]:3/3 cost:1} - nexthop{43 cost:1}
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.123 [I] RouterTable---:      4 0x1000 - nbr{lq[i/o]:3/2 cost:2} - nexthop{61 cost:1}
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.123 [I] RouterTable---:     17 0x4400 - nbr{lq[i/o]:3/3 cost:1} - nexthop{61 cost:1} - leader
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.123 [I] RouterTable---:     42 0xa800 - nbr{lq[i/o]:3/3 cost:1} - nexthop{59 cost:1}
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.123 [I] RouterTable---:     46 0xb800 - nbr{lq[i/o]:3/3 cost:1} - nexthop{43 cost:1}
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.123 [I] RouterTable---:     38 0x9800 - me
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.124 [I] RouterTable---:      5 0x1400 - nexthop{45 cost:1}
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.124 [I] RouterTable---:     62 0xf800 - nbr{lq[i/o]:3/3 cost:1} - nexthop{50 cost:1}
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.124 [I] RouterTable---:     34 0x8800 - nbr{lq[i/o]:3/3 cost:1} - nexthop{61 cost:1}
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.124 [I] RouterTable---:     58 0xe800 - nbr{lq[i/o]:2/2 cost:2} - nexthop{34 cost:1}
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.124 [I] RouterTable---:     45 0xb400 - nbr{lq[i/o]:2/3 cost:2} - nexthop{51 cost:3}
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.124 [I] RouterTable---:     61 0xf400 - nbr{lq[i/o]:3/3 cost:1} - nexthop{51 cost:1}
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.125 [I] RouterTable---:     60 0xf000 - nbr{lq[i/o]:3/3 cost:1} - nexthop{50 cost:1}
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.125 [I] RouterTable---:     59 0xec00 - nbr{lq[i/o]:3/3 cost:1} - nexthop{42 cost:1}
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.125 [I] RouterTable---:     54 0xd800 - nbr{lq[i/o]:3/3 cost:1} - nexthop{17 cost:2}
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.125 [D] P-RadioSpinel-: Received spinel frame, flg:0x2, tid:7, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.126 [W] P-RadioSpinel-: Handle radio frame failed: Parse
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.126 [W] P-RadioSpinel-: Handle transmit done failed: Parse
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.126 [C] Platform------: ------------------ BEGINNING OF CRASH -------------
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.126 [C] Platform------: *** FATAL ERROR: Caught signal: 6 (Aborted)
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.128 [C] Platform------: # 0: /usr/sbin/otbr-agent(+0x2bc6e0) [0x55802cc6e0]
Nov  8 22:34:47 8826213816e4 otbr-agent[200]: 5d.09:08:16.129 [C] Platform------: ------------------ END OF CRASH ------------------
Nov  8 23:01:50 8826213816e4 avahi-daemon[164]: Withdrawing address record for fd11:1111:1122:2223:42:acff:fe11:2 on eth0.
Nov  8 23:01:50 8826213816e4 avahi-daemon[164]: Leaving mDNS multicast group on interface eth0.IPv6 with address fd11:1111:1122:2223:42:acff:fe11:2.
Nov  8 23:01:50 8826213816e4 avahi-daemon[164]: Joining mDNS multicast group on interface eth0.IPv6 with address fe80::42:acff:fe11:2.
Nov  8 23:01:50 8826213816e4 avahi-daemon[164]: Registering new address record for fe80::42:acff:fe11:2 on eth0.*.

@thedevleon
Copy link
Author

And another one after 3 days, they all seem to be related to this line:

Received spinel frame, flg:0x2, tid:9, cmd:PROP_VALUE_IS, key:LAST_STATUS, stat

Please let me know if I can enable any additional debugging or logging options to figure out the root cause of this crash.

@zhanglongxia
Copy link
Contributor

The error Handle transmit done failed: Parse means that the code has reached to the function HandleTransmitDone() and the error code mTxError is set to OT_ERROR_PARSE. The error code OT_ERROR_PARSE will be finally handled by the function SubMac::HandleTransmitDone. The function SubMac::HandleTransmitDone is unable to process the error code OT_ERROR_PARSE, so it calls the OT_ASSERT(false);. The OT_ASSERT() calls the assert() to make the program crashed.

So the root cause is that the Thread host receives a wrong Spinel frame from the esp32-c6. I think you can add the code to HandleTransmitDone() to print out the raw data of the Spinel message to better understand which field of the Spinel frame is wrong.

@dsyx
Copy link

dsyx commented Dec 6, 2023

I also encountered a similar problem. The platform I used was Silabs SoC + Raspberry Pi 4. Details are in the Silabs Community Discussion.

The following is part of the log:

Sep 27 08:16:01 otbr-4b otbr-agent[200]: 00:58:54.588 [D] Platform------: Process(): Interrupt.

Sep 27 08:16:01 otbr-4b otbr-agent[200]: 00:58:54.589 [D] Platform------: ============================[SPI-TX len=053]============================

Sep 27 08:16:01 otbr-4b otbr-agent[200]: 00:58:54.589 [D] Platform------: | 02 20 00 00 00 8A 03 71 | 55 00 69 98 21 CC CC 00 | . .....qU.i.!LL.

Sep 27 08:16:01 otbr-4b otbr-agent[200]: 00:58:54.589 [D] Platform------: | 94 00 8C 0D F4 6F 02 00 | 08 68 85 01 04 52 B4 06 | ....to...h...R4.

Sep 27 08:16:01 otbr-4b otbr-agent[200]: 00:58:54.589 [D] Platform------: | 3F 24 0E 03 B6 04 AB 03 | 20 52 8D 5C FF FE AC 8F | ?$..6.+. R.\.~,.

Sep 27 08:16:01 otbr-4b otbr-agent[200]: 00:58:54.589 [D] Platform------: | A5 0D 57 64 3A .. .. .. | .. .. .. .. .. .. .. .. | %.Wd:...........

Sep 27 08:16:01 otbr-4b otbr-agent[200]: 00:58:54.589 [D] Platform------: ------------------------------------------------------------------------

Sep 27 08:16:01 otbr-4b otbr-agent[200]: 00:58:54.589 [D] Platform------: ============================[SPI-RX len=053]============================

Sep 27 08:16:01 otbr-4b otbr-agent[200]: 00:58:54.589 [D] Platform------: | 02 FB 01 04 00 8A 06 00 | 04 FF FF FF FF FF FF FF | .{..............

Sep 27 08:16:01 otbr-4b otbr-agent[200]: 00:58:54.589 [D] Platform------: | FF FF FF FF FF FF FF FF | FF FF FF FF FF FF FF FF | ................

Sep 27 08:16:01 otbr-4b otbr-agent[200]: 00:58:54.589 [D] Platform------: | FF FF FF FF FF FF FF FF | FF FF FF FF FF FF FF FF | ................

Sep 27 08:16:01 otbr-4b otbr-agent[200]: 00:58:54.589 [D] Platform------: | FF FF FF FF FF .. .. .. | .. .. .. .. .. .. .. .. | ................

Sep 27 08:16:01 otbr-4b otbr-agent[200]: 00:58:54.589 [D] Platform------: ------------------------------------------------------------------------

Sep 27 08:16:01 otbr-4b otbr-agent[200]: 00:58:54.589 [D] Platform------: spi_transfer TX: H:02 ACCEPT:32 DATA:0

Sep 27 08:16:01 otbr-4b otbr-agent[200]: 00:58:54.589 [D] Platform------: spi_transfer RX: H:02 ACCEPT:507 DATA:4

Sep 27 08:16:01 otbr-4b otbr-agent[200]: 00:58:54.589 [D] Platform------: Received spinel frame, flg:0x2, iid:0, tid:10, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:INVALID_STATE

Sep 27 08:16:01 otbr-4b otbr-agent[200]: 00:58:54.589 [W] Platform------: Handle transmit done failed: Parse

Sep 27 08:16:01 otbr-4b otbr-agent[200]: 00:58:54.590 [C] Platform------: ------------------ BEGINNING OF CRASH -------------

Sep 27 08:16:01 otbr-4b otbr-agent[200]: 00:58:54.590 [C] Platform------: *** FATAL ERROR: Caught signal: 6 (Aborted)

Sep 27 08:16:01 otbr-4b otbr-agent[200]: 00:58:54.590 [C] Platform------: ------------------ END OF CRASH ------------------

Sep 27 08:16:03 otbr-4b mDNSResponder: Default: mDNS_Execute: SendResponses didn't send all its responses; will try again in one second

@jdswensen
Copy link
Contributor

I'm seeing a similar problem with a Silabs based device. It's usually in the context of an MLE channel announcement. I added some message dumps to the spinel code (this function).

0001-st-add-logging-to-HandleTransmitDone.patch

2024-01-28_18:38:33.050 | silabs-otbr-agent[1661]: 1d.16:11:32.901 [I] Mle-----------: Send Announce on channel 15
2024-01-28_18:38:33.052 | silabs-otbr-agent[1661]: 1d.16:11:32.902 [D] Mac-----------: Request to start operation "TransmitDataDirect"
2024-01-28_18:38:33.052 | silabs-otbr-agent[1661]: 1d.16:11:32.903 [D] Mac-----------: Starting operation "TransmitDataDirect"
2024-01-28_18:38:33.053 | silabs-otbr-agent[1661]: 1d.16:11:32.904 [D] SubMac--------: RadioState: Receive -> CsmaBackoff
2024-01-28_18:38:33.059 | silabs-otbr-agent[1661]: 1d.16:11:32.910 [D] SubMac--------: RadioState: CsmaBackoff -> Transmit
2024-01-28_18:38:33.061 | silabs-otbr-agent[1661]: 1d.16:11:32.911 [D] Platform------: Sent spinel frame, flg:0x2, iid:2, tid:12, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:82, channel:15, maxbackoffs:4, maxretries:15 ...
2024-01-28_18:38:33.061 | silabs-otbr-agent[1661]: 1d.16:11:32.912 [D] Platform------: ... csmaCaEnabled:1, isHeaderUpdated:1, isARetx:0, skipAes:1, txDelay:0, txDelayBase:0
2024-01-28_18:38:33.062 | silabs-otbr-agent[1661]: 1d.16:11:32.912 [D] TrelLink------: State: Receive -> Transmit
2024-01-28_18:38:33.063 | silabs-otbr-agent[1661]: 1d.16:11:32.914 [D] TrelLink------: BeginTransmit() [broadcast ch:15 panid:ffff num:15425 src:02e46158a6cee849 no-ack] plen:80
2024-01-28_18:38:33.065 | silabs-otbr-agent[1661]: 1d.16:11:32.916 [D] TrelLink------: State: Transmit -> Receive
2024-01-28_18:38:33.066 | silabs-otbr-agent[1661]: 1d.16:11:32.916 [D] Platform------: Received spinel frame, flg:0x2, iid:1, tid:12, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
2024-01-28_18:38:33.066 | silabs-otbr-agent[1661]: 1d.16:11:32.917 [D] Platform------: Discarding spinel message with IID=1
2024-01-28_18:38:33.070 | silabs-otbr-agent[1661]: 1d.16:11:32.921 [D] Platform------: Received spinel frame, flg:0x2, iid:2, tid:12, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
2024-01-28_18:38:33.071 | silabs-otbr-agent[1661]: 1d.16:11:32.922 [D] Mac-----------: ==============[HandleTransmitDone: spinel buffer len=031]===============
2024-01-28_18:38:33.072 | silabs-otbr-agent[1661]: 1d.16:11:32.922 [D] Mac-----------: | 00 00 01 00 00 00 80 00 | 00 0A 00 00 00 00 00 00 | ................
2024-01-28_18:38:33.073 | silabs-otbr-agent[1661]: 1d.16:11:32.923 [D] Mac-----------: | 00 00 00 00 00 01 00 00 | 05 00 00 00 00 00 00 .. | ................
2024-01-28_18:38:33.074 | silabs-otbr-agent[1661]: 1d.16:11:32.924 [D] Mac-----------: ------------------------------------------------------------------------
2024-01-28_18:38:33.075 | silabs-otbr-agent[1661]: 1d.16:11:32.925 [D] Mac-----------: ==============[HandleTransmitDone: spinel buffer len=030]===============
2024-01-28_18:38:33.076 | silabs-otbr-agent[1661]: 1d.16:11:32.926 [D] Mac-----------: | 00 01 00 00 00 80 00 00 | 0A 00 00 00 00 00 00 00 | ................
2024-01-28_18:38:33.076 | silabs-otbr-agent[1661]: 1d.16:11:32.927 [D] Mac-----------: | 00 00 00 00 01 00 00 05 | 00 00 00 00 00 00 .. .. | ................
2024-01-28_18:38:33.077 | silabs-otbr-agent[1661]: 1d.16:11:32.927 [D] Mac-----------: ------------------------------------------------------------------------
2024-01-28_18:38:33.077 | silabs-otbr-agent[1661]: 1d.16:11:32.928 [D] Mac-----------: ==============[HandleTransmitDone: spinel buffer len=029]===============
2024-01-28_18:38:33.078 | silabs-otbr-agent[1661]: 1d.16:11:32.928 [D] Mac-----------: | 01 00 00 00 80 00 00 0A | 00 00 00 00 00 00 00 00 | ................
2024-01-28_18:38:33.078 | silabs-otbr-agent[1661]: 1d.16:11:32.929 [D] Mac-----------: | 00 00 00 01 00 00 05 00 | 00 00 00 00 00 .. .. .. | ................
2024-01-28_18:38:33.079 | silabs-otbr-agent[1661]: 1d.16:11:32.929 [D] Mac-----------: ------------------------------------------------------------------------
2024-01-28_18:38:33.079 | silabs-otbr-agent[1661]: 1d.16:11:32.930 [C] Platform------: HandleTransmitDone(): Could not parse keyId (0) and frameCounter (2123311720)
2024-01-28_18:38:33.080 | silabs-otbr-agent[1661]: 1d.16:11:32.930 [C] Platform------: HandleTransmitDone(): unpacked: -1
2024-01-28_18:38:33.080 | silabs-otbr-agent[1661]: 1d.16:11:32.931 [C] Mac-----------: ==============[HandleTransmitDone: spinel buffer len=000]===============
2024-01-28_18:38:33.081 | silabs-otbr-agent[1661]: 1d.16:11:32.931 [C] Mac-----------: ------------------------------------------------------------------------
2024-01-28_18:38:33.081 | silabs-otbr-agent[1661]: 1d.16:11:32.932 [W] Platform------: RCP failure detected

The SIGABRT can be addressed via the commit in openthread/openthread#9745. However, this doesn't explain the behavior around incorrectly encoded/decoded messages.

These failures are happening around 1-2 times a day on my setup, but I haven't been able to narrow down the exact failure in order to reproduce it. This is the corresponding code for the radio.

@abtink, what data would you recommend logging on the radio? I tried printing the entire buffer, but that looks like its 2048 bytes and I'm running into issues with RTT overwriting data.

@dsyx
Copy link

dsyx commented Feb 5, 2024

Hi @jdswensen ,

My Silabs-based equipment also fails an average of 1-2 times a day.

Under the default build of Silabs, this device will fail dozens of times a day, but after setting the log level to critical, the device will only fail 1-2 times a day. In addition, as the concurrency of the network increases, the number of device failures will also increase.

@abtink
Copy link
Member

abtink commented Feb 5, 2024

@jdswensen, some suggestions/questions:

  • What is the bus interface between RCP and host? (SPI/UART/etc).
  • Would recommend double-checking the platform specific code that implements the interface.
    • The issue is more likely on platform code. The OT (common) RCP code itself has been stress-tested on different platforms so less likely for it to be cause.
  • I noticed spinel frames using iid=1 and iid=2 from RPC which points to RCP operating as multi-PAN mode.
  • The issue may be due to multi-PAN related code. This functionality is specific to vendors and how they support it.

Some observation from the log snipper for things to be investigated:

Here the spinel frame requesting a "Tx" is sent to RCP. It is sent with iid:2 and has tid:12

2024-01-28_18:38:33.061 | silabs-otbr-agent[1661]: 1d.16:11:32.911 [D] Platform------: Sent spinel frame, flg:0x2, iid:2, tid:12, cmd:PROP_VALUE_SET, key:STREAM_RAW, len:82, channel:15, maxbackoffs:4, maxretries:15 ...
2024-01-28_18:38:33.061 | silabs-otbr-agent[1661]: 1d.16:11:32.912 [D] Platform------: ... csmaCaEnabled:1, isHeaderUpdated:1, isARetx:0, skipAes:1, txDelay:0, txDelayBase:0

Later we see this set of spinel messages received from RCP:

  • We see two message one for iid:1 and one iid:2 for same tid:12 (tid match indicates it is a response to the command above).
  • Why is RCP sending to iid:1 as well? The response should be using iid:2 same as the request.
  • This may be agood point to be checked further.
    • I am not myself familiar with multi-PAN code but this behavior does not seem correct to me.
    • I recall vendors wanted some logic in multi-PAN for RCP to send some info on all IIDs, acting like a broadcast of events from RCP to all PANs? This code may be cuprit here? May be worth checking this.
2024-01-28_18:38:33.066 | silabs-otbr-agent[1661]: 1d.16:11:32.916 [D] Platform------: Received spinel frame, flg:0x2, iid:1, tid:12, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK
2024-01-28_18:38:33.066 | silabs-otbr-agent[1661]: 1d.16:11:32.917 [D] Platform------: Discarding spinel message with IID=1
2024-01-28_18:38:33.070 | silabs-otbr-agent[1661]: 1d.16:11:32.921 [D] Platform------: Received spinel frame, flg:0x2, iid:2, tid:12, cmd:PROP_VALUE_IS, key:LAST_STATUS, status:OK

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

5 participants