IDF & FreeRTOS performance (IDF-224)

[michprev]

I think it makes sense to create an issue like this to care about performance problems that happen inside interrupt or exception vectors (or inside anything called by them).

From the beginning PRO core was ment to run all the necessary stuff while APP core should be free to use. This is why we should focus on APP core.

So far we know that there is "tiT" task (LWIP TCP/IP task) that can migrate between both cores.
What is maximum priority this task can run at?

I have created example project at https://github.com/michprev/idf_performance.

I have discovered there are some delays during wifi driver initialization. I am not sure this is a legit problem. https://github.com/michprev/idf_performance/tree/bb9c4331406d515ce1294a39b65cafcf4e4826e8

[michprev]

There are also delays while receiving UDP datagrams.

SSID: "test_ssid"
password: "test1234"
UDP port: 4789

Max datagram size is 1024 bytes. I have reproduced it while sending some data every 80 ms.
Example https://github.com/michprev/idf_performance/tree/95bb88b25c0e35cfd38fec3790c8d076f3c6bf33

[michprev]

I have been trying debugging this using uxTaskGetSystemState function but it returns really strange values.
Example https://github.com/michprev/idf_performance/tree/bcf3511d875cb8c89a1d7fef1fe813e5b672c2ac

EDIT:
Alright I did not notice that uxTaskGetSystemState does not print the tasks in the same order.

It seems that delays during wifi driver initialization are caused by "ipc1" task. Is it really necessary?

[michprev]

Ad UDP receiving:
I have configured watchdog to fire level 5 interrupt after 500 us. Inside level 5 vector I have inserted break instruction so that I am able to debug this via JTAG.

(gdb) i threads
  Id   Target Id         Frame 
  11   Thread 1073413628 (ipc0) 0x4008b275 in xQueueGenericReceive (xQueue=0x3ffafda8, pvBuffer=0x0, 
    xTicksToWait=1644638200, xJustPeeking=0)
    at /home/michal/git/esp-idf/components/freertos/queue.c:1591
  10   Thread 1073454188 (ipc1) 0x4008b275 in xQueueGenericReceive (xQueue=0x3ffaff64, pvBuffer=0x0, 
    xTicksToWait=1644638200, xJustPeeking=0)
    at /home/michal/git/esp-idf/components/freertos/queue.c:1591
  9    Thread 1073485172 (eventTask) 0x4008b275 in xQueueGenericReceive (xQueue=0x3ffc041c, 
    pvBuffer=0x3ffc14b0, xTicksToWait=1644638200, xJustPeeking=0)
    at /home/michal/git/esp-idf/components/freertos/queue.c:1591
  8    Thread 1073412744 (esp_timer) 0x4008b275 in xQueueGenericReceive (xQueue=0x3ffaea30, 
    pvBuffer=0x0, xTicksToWait=1644638200, xJustPeeking=0)
    at /home/michal/git/esp-idf/components/freertos/queue.c:1591
  7    Thread 1073466452 (Tmr Svc) 0x4008cf74 in prvProcessTimerOrBlockTask (
    xNextExpireTime=<optimized out>, xListWasEmpty=<optimized out>)
    at /home/michal/git/esp-idf/components/freertos/timers.c:588
  6    Thread 1073491072 (wifi : Running @CPU0) vPortCPUReleaseMutexIntsDisabledInternal (
    mux=0x3ffc2e84) at /home/michal/git/esp-idf/components/freertos/portmux_impl.inc.h:158
  5    Thread 1073455264 (testing task) app_task (args=0x0)
    at /home/michal/git/idf_performance/main/main.c:80
  4    Thread 1073476472 (wifi task) 0x4000bff0 in ?? ()
  3    Thread 1073461896 (IDLE) 0x4013175a in esp_vApplicationWaitiHook ()
    at /home/michal/git/esp-idf/components/esp32/freertos_hooks.c:66
  2    Thread 1073463796 (IDLE) 0x4013175a in esp_vApplicationWaitiHook ()
    at /home/michal/git/esp-idf/components/esp32/freertos_hooks.c:66
* 1    Thread 1073480204 (tiT : Running @CPU1) _Level5Vector ()
    at /home/michal/git/esp-idf/components/freertos/xtensa_vectors.S:1591

"tiT" task still preempts testing task running with 20 priority.

https://github.com/michprev/idf_performance/tree/cc853cccf9abd5c7f17a875746eb93963820a400

[projectgus]

Hi @michprev ,

Please open separate separate issues for the problems with UDP and the problems with uxTaskGetSystemState() function. This will keep the discussion easy to follow.

One note: when reporting issues with UDP, please remember that WiFi is not a hard real-time protocol and some delays will always be introduced at the protocol level, due to the vagaries of RF. I expect if you take a frame-level packet capture (you can get one if you have a WiFi interface that supports "monitor mode") then you'll see some delays/timeout/retries happening at the 802.11 MAC layer.

It seems that delays during wifi driver initialization are caused by "ipc1" task. Is it really necessary?

The WiFi driver will save some calibration data to NVS during initialization, which requires writing to flash. Writing to flash requires suspending task execution on both cores (ISRs marked as IRAM-safe will always continue to run). You can clear the nvs_enable flag in the wifi_init_config_t structure if you'd prefer that WiFi didn't store data in NVS.

For the other questions, it'll be easier to reply after they're split out into separate issues. Thanks.

[projectgus]

(I realised when you were talking about UDP you meant pauses in the higher priority app_task, not pauses in the UDP reception, and that you figured out uxTaskGetSystemState(), so please disregard the request for multiple issues.)

[michprev]

Basically the issue is that even when testing task runs with priority 20 it is being preempted by 18 priority LWIP task.

It would also make sense to make LWIP task core affinity configurable - the same way as wifi task (CONFIG_ESP32_WIFI_TASK_PINNED_TO_CORE).

[igrr]

Re making LwIP task affinity configurable — good point, this should be added soon.

[negativekelvin]

How does priority 18 task preempt priority 20 task that is in a busy loop?

[igrr]

One possibility (not confirmed at this point) is that somewhere the priority 18 task takes a mutex, and then gets preempted by the higher priority (23) wifi task, which tries to take the same mutex. Due to priority inheritance LwIP task starts to execute. It should start executing on CPU0 though, but maybe there is some bug in the logic.

[michprev]

Cannot reproduce the preemption issue in v3.1.3. Keeping open as 5d1ccb9 has not been merged into any of stable releases yet.

[projectgus]

The LWIP affinity fix is now in the v3.2 release. Please let us know if you find new steps to reproduce.