ot-br-posix
ot-br-posix copied to clipboard
Published
20 hours ago •
openthread
openthread
otbr-agent crash after around a week of uptime
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:
- Git commit id -> docker container
openthread/otbr@sha256:78543c07c08650044a35e6e938ae787f0bf48b059dd8a82883a14e97ce5c86cd - IEEE 802.15.4 hardware platform -> esp32-c6 with ot_rcp connected via UART to Raspberry Pi 4
- 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"
- 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.
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 ------------------
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.*.
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.
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.
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
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 https://github.com/openthread/openthread/pull/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.
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.
@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=1andiid=2from 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:1and oneiid:2for sametid:12(tidmatch indicates it is a response to the command above). - Why is RCP sending to
iid:1as well? The response should be usingiid:2same 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
