Thread crashing under heavy ping load (Thread -> Lan)

[hani-n]

We are testing a RTOS Thread Border Router on Thread 1.3.0 stack.
Using ESP32 as host processor and EFRMG21 in a RCP configuration.

We are experiencing crashes in the TBR when it is handling Tread -> LAN Pings at high rate.
Setup:

1. PC <--> TBR <-- FTD (nRF dongle)
2. Ping PC from FTD at 10ms interval, i.e on FTD we run ping fd84:89e0:f1e1:a6b1:b2d1:7fef:61bf:fe0d 56 65000 0.01
3. We are observing crashes in message.cpp (on the TBR) as follows

Guru Meditation Error: Core 0 panic'ed (StoreProhibited). Exception was unhandled.

Core 0 register dump: PC : 0x400e8c14 PS : 0x00060230 A0 : 0x80105c2e A1 : 0x3ffdd450 A2 : 0x3f908224 A3 : 0x3f904430 A4 : 0x0100de5b A5 : 0x00000001 A6 : 0x00000001 A7 : 0x00000001 A8 : 0x800e8c0c A9 : 0x3ffdd430 A10 : 0x3f904bb0 A11 : 0x00000001 A12 : 0x00000000 A13 : 0x3ffdd577 A14 : 0x00000081 A15 : 0x76d8cbdf SAR : 0x00000018 EXCCAUSE: 0x0000001d EXCVADDR: 0x0100de63 LBEG : 0x4008cce4 LEND : 0x4008ccf7 LCOUNT : 0x00000000

0x4008cce4: __memcpy_aux at /builds/idf/crosstool-NG/.build/xtensa-esp32-elf/src/newlib/newlib/libc/machine/xtensa/memcpy.S:73 0x4008ccf7: __memcpy_aux at /builds/idf/crosstool-NG/.build/xtensa-esp32-elf/src/newlib/newlib/libc/machine/xtensa/memcpy.S:88

Backtrace:0x400e8c11:0x3ffdd4500x40105c2b:0x3ffdd470 0x400f838f:0x3ffdd510 0x400f8887:0x3ffdd5b0 0x400e252a:0x3ffdd630 0x4011bd29:0x3ffdd650 0x4011bf81:0x3ffdd680 0x4011c1a1:0x3ffdd6a0 0x4011af80:0x3ffdd6d0 0x400d5ffa:0x3ffdd720 0x40097a16:0x3ffdd7b0

0x400e8c11: ot::PriorityQueue::Enqueue(ot::Message&) at /home/workspace/bayview/components/openthread/openthread/src/core/common/message.cpp:922 0x40105c2b: ot::MeshForwarder::SendMessage(ot::Message&) at /home/workspace/bayview/components/openthread/openthread/src/core/thread/mesh_forwarder_ftd.cpp:56 0x400f838f: ot::ThreadNetif::SendMessage(ot::Message&) at /home/workspace/bayview/components/openthread/openthread/src/core/thread/thread_netif.hpp:144 (inlined by) ot::Ip6::Ip6::HandleDatagram(ot::Message&, ot::Ip6::Netif*, void const*, bool) at /home/workspace/bayview/components/openthread/openthread/src/core/net/ip6.cpp:1306 0x400f8887: ot::Ip6::Ip6::SendRaw(ot::Message&, bool) at /home/workspace/bayview/components/openthread/openthread/src/core/net/ip6.cpp:1114 0x400e252a: otIp6Send at /home/workspace/bayview/components/openthread/openthread/src/core/api/ip6_api.cpp:135 0x4011bd29: process_thread_transmit at /home/workspace/bayview/components/openthread/port/esp_openthread_netif_glue.c:208 0x4011bf81: esp_openthread_netif_glue_process at /home//workspace/bayview/components/openthread/port/esp_openthread_netif_glue.c:485 0x4011c1a1: esp_openthread_platform_process at /home/workspace/bayview/components/openthread/port/esp_openthread_platform.cpp:109 0x4011af80: esp_openthread_launch_mainloop at /home/workspace/bayview/components/openthread/port/esp_openthread.cpp:116 0x400d5ffa: ot_task_worker at /home/workspace/bayview/main/esp_ot_br.c:291 (discriminator 2) 0x40097a16: vPortTaskWrapper at /home/workspace/bayview/env/esp-idf/components/freertos/port/xtensa/port.c:130

What I am wondering:

1. While trying to debug the issue I came across a OT_ASSERT(mSendMessage->IsDirectTransmission()) in MeshForwarder::UpdateSendMessage in (mesh_forwarder.cpp), curious as to why we would ASSERT instead of Exit here ?
2. Since I am experiencing the crash in message.cpp of type "Store prohibited" (sometimes I do also see Load prohibitied) Is there any OpenThread defense mechanism against heavy traffic (e.g. semaphore while processing messages, defense against writing out of bounds, defense against writing to a free'd message buffer)
3. Are there standard data rates Thread is tested against?

[Irving-cl]

Hi @hani-n,

For question 3, the data rate of 802.15.4 (2.4Ghz) is 250kbps. In practical (from our experience and test results), the L2 throughput on a device can reach around 80kbps.

With the ping configuration you used: payload 56 bytes (IIRC the Mac frame will happen to be 100 bytes), frequency is 0.01s. So the throughput will be 10kBytes/s = 80kbps. But there will be the same amount of ping reply. So that will double and become 160kbps. That exceeds Thread's capacity. So I suggest having the ping frequency.

[jwhui]

OpenThread should avoid crashes even when the offered load is higher than what Thread can support.

[Irving-cl]

For sure. I just mean to provide some reference values :)

[jwhui]

Thanks for raising this issue. What git commit are you using?

While trying to debug the issue I came across a OT_ASSERT(mSendMessage->IsDirectTransmission()) in MeshForwarder::UpdateSendMessage in (mesh_forwarder.cpp), curious as to why we would ASSERT instead of Exit here ?

We use asserts where an implementation expects a condition to be true, otherwise it is considered a bug and should be fixed. Is this assert triggering for you?

Since I am experiencing the crash in message.cpp of type "Store prohibited" (sometimes I do also see Load prohibitied) Is there any OpenThread defense mechanism against heavy traffic (e.g. semaphore while processing messages, defense against writing out of bounds, defense against writing to a free'd message buffer)

OpenThread uses a message pool to buffer received messages for processing. When the buffer pool is no longer able to provide messages, OpenThread will simply drop the messages.

"Store/Load prohibited" seems specific to the ESP platform.

Are there standard data rates Thread is tested against?

OpenThread has been tested on scenarios where the offered load is far above and below what it is capable of supporting. As mentioned above, if the offered load is high, OpenThread should start dropping messages.

[hani-n]

For question 3, the data rate of 802.15.4 (2.4Ghz) is 250kbps. In practical (from our experience and test results), the L2 throughput on a device can reach around 80kbps.

Thanks @Irving-cl for the reply, 80kbps does seem to align with what I am seeing, i.e pinging at 25ms, Thread seems to be able to manage without issue (stable ping TTL of around 20ms, very little packet loss).

Thanks for raising this issue. What git commit are you using?

We are using gecko sdk v4.1.0 which tracks OpenThread commit 8f92d2d

The issue I see is when I start to increase the rate at which I ping. What I am expecting is that Thread would run out of message buffers and start dropping packets as @jwhui is describing.

We were able to resolve the Load/Store prohibited crashes in message.cpp by implementing semaphores between Thread/LwIP tasks.
Currently we experiencing OT_ASSERT firing (albeit more infrequently) in message.cpp.

The following asserts have been observed when pinging at a 5ms rate nrf ->TBR->PC

OT_ASSERT(!aMessage.IsInAQueue())
OT_ASSERT(mSendMessage->IsDirectTransmission())
OT_ASSERT(aMessage->Next() == nullptr && aMessage->Prev() == nullptr)

[abtink]

Just want to point that:

• Generally OT public and platform APIs must be invoked from same OS context (e.g. from same RTOS task).
• Or (for advances users) the platform integration must ensure that every call to platform/public API finish before any other invocation (e.g. use whatever mechanism supported by platform and OS).

The asserts are checking the validity of MessageQueue linked list.
It can be messed up by not following the above rule (calling OT APIs from different RTOS tasks can create race situtaion messing up the linked list).

[hani-n]

Indeed this seems to have been the issue, we have a few different tasks calling OT API and not all of them are protected with esp_openthread_lock_acquire, guarding with locks goes a long way in stabilizing the platform during heavy traffic.
Thanks all for your inputs !