Gripes on ESP32/ESP-IDF

[hassan789]

Also, the MPU9250 has the worst i2c... I have used it with an CortexM4F, and it has gotten the bus stuck (needing to power cycle the chip)... I would not be so quick to blame the ESP32. I have since shifted to SPI... its faster and does not get stuck.

[Vader_Mester]

So how do I calculate microsecond time interval

c0=xthal_get_ccount()

c1=(xthal_get_ccount()-c0) / ncyclesinmicrosec ???

Kind of.
The CCOUNT register is a register in the CPU. According to the Xtensa docs, it's supposed to increment each clock cycle. So if running the ESP32 on 240MHz, it will last for about 17.895 sec, and then the register wraps to 0.
So in this case, if you have a cycle count difference, then you can devide it with whatever MHz the ESP is running on to get the ellapsed microsecs.
So in this case if you run it with 240MHz, it's like:

c1=(xthal_get_ccount()-c0) / 240.

As far as I know, this is how the FreeRTOS TICK_MS and software timers work, since the CCOUNT register is free to read.
Also sometimes the CCOUNT register is overwritten, as mentioned in the topic I linked:

To the best of my knowledge, there is no way to reset / write to the register and it would be incredibly dangerous to do so.

Actually, we do...
https://github.com/espressif/esp-idf/bl ... clk.c#L726

It is also woth checking if you call gettimeofday() function, and see if it's down to a microsec resolution. I think that's probably the best.

[michprev]

The MPU9250 is quite old, I am surprised you are using it for a new project. The problem with it is, the MPL software is on your host processor, which means any missing gyro data can mess the whole algo. Also, it is VERY sensitive to mag calibration, if it is not calibrated correctly, your reading will be off. Have you tried running the MPL without mag?

I've been using MPU9250 just for a while - it is very sensitive to vibrations. Now I am working with MPU6000. I can read accel & gyro data at 20 MHz over SPI. Magnetometer is not needed that much. Yaw drifts a bit without it but it is quite ok.

I have some plans with ESP32 pico and ICM20689 but as I am still struggling with software I don't want to make more investments now. That is why I am using old sensors (many new flight controllers still use MPU6000).

There is my current problem with FreeRTOS / ESP-IDF:
I am measuring how long it takes to run this function https://pastebin.com/BsnfC0g8. For my needs it takes way too long to run it.
When I run this function inside a critical section it takes up to 200 us to run it. It is very strange without a critical section.
At the beggining it takes up to 500 us to run it but after a while it goes really crazy - up to 5 ms.

I tried to look deeper into it. Right after the function completes INTENABLE register contains 0x13000044. That means that interrupts 2, 6, 24, 25 and 28 are enabled on the current core. Critical sections disable only interrupts level 3 and below. So only interrupts 2 and 6 may cause that great delays. There is also a small chance that math functions use interrupts but I don't think this is the case.

Interrupt 6 is FreeRTOS tick interrupt. Interrupt 2 is bound to esp_crosscore_isr (I know that from _xt_interrupt_table https://github.com/espressif/esp-idf/bl ... .S#L78-L89).

I will keep trying getting more info about it. But in the meanwhile is it normal behavior that it takes so long?

EDIT:
I believe I can confirm that those delays are cause by FreeRTOS tick handler. I replaced critical section by XTOS_SET_INTLEVEL(1). That disables level 1 interrupts only. Using this there are no delays. But after changing FreeRTOS tick handler to level 3 interrupt in menuconfig the problem occurs again.

[ESP_Sprite]

That is absolutely crazy - there's no way the tick handler itself is eating up 5ms. The tick handler, however, does switch to higher priority scheduled tasks when they use e.g. as vTaskDelay to sleep. Do you have your sources available somewhere so we might be able to look through them or replicate the issue?

[ESP_Angus]

So how do I calculate microsecond time interval

It is also woth checking if you call gettimeofday() function, and see if it's down to a microsec resolution. I think that's probably the best.

This will work, but a lighter weight (non-portable) alternative is to call esp_timer_gettime(): https://esp-idf.readthedocs.io/en/lates ... _get_timev

Generally speaking, reading the CCOUNT register is ideal for measuring <10us (approx) timing when you know the code will only run on a single core. esp_timer_gettime() is ideal for everything else.

If the task may migrate between cores (ie is not pinned), CCOUNT will not give accurate results as each CPU has its own CCOUNT register. The timer behind esp_timer_gettime() is shared between both cores.

[michprev]

That is absolutely crazy - there's no way the tick handler itself is eating up 5ms. The tick handler, however, does switch to higher priority scheduled tasks when they use e.g. as vTaskDelay to sleep. Do you have your sources available somewhere so we might be able to look through them or replicate the issue?

Code: Select all

IMU task       	R	2	7168	16	1
WiFi task      	R	2	928	12	0
main           	R	1	2596	5	0
IDLE           	R	0	668	6	0
IDLE           	R	0	616	7	1
tiT            	B	18	1256	13	-1
Tmr Svc        	B	1	1656	8	0
ipc0           	B	24	628	2	0
esp_timer      	B	22	3972	1	0
wifi           	B	23	1556	15	0
eventTask      	B	20	3824	14	0
ipc1           	B	24	580	3	1

This is the list of tasks provided by vTaskList (with applied this PR to see core id - https://github.com/espressif/esp-idf/pull/2064) right after the issue occurs. My time critical code is running in "IMU task" task.

I have modified my code to be as simple as possible. It is available at https://github.com/michprev/flyhero-esp ... ong_delays. Critical code runs here https://github.com/michprev/flyhero-esp ... p#L92-L127.

imu.Data_Ready() calls https://github.com/michprev/flyhero-esp ... #L741-L749

imu.Read_Data(accel, gyro) calls https://github.com/michprev/flyhero-esp ... #L606-L734

And finally mahony_filter.Compute(accel, gyro, euler) calls https://github.com/michprev/flyhero-esp ... p#L28-L133

[ESP_Angus]

Hi michprev,

A few observations from reading the code:

• At the bottom of app_main() you call while (true);. this will peg Core 0 at priority 1 (main task priority), starving the idle task. I'm surprised you don't see a Task WDT warning from this. It's OK to return from app_main(), suggest removing this line entirely.
• imu_task is pinned to Core 1, so it's not going to be preempted by the WiFi management task or interrupts pinned to Core 0 (this is good!). However it has priority 2, which is lower than the LWIP TCP/IP task (priority 18, "TiT" in the task dump you showed)^^, and the TCP/IP task can migrate between cores (as shown in the task dump also, "core -1"). So the 5ms imu_task delays are probably explained by the TCP/IP task preempting the imu_task when something higher priority is running on Core 0. Setting the imu_task priority to something higher (say 19 or 20) will resolve this.
• I noticed the SPI master driver busy-waits in a while loop for a transaction to finish. In a multi-task RTOS environment this is usually bad for overall performance, as this CPU time can be used to do something else. If you use the SPI master driver in ESP-IDF then it will suspend the task until the SPI completion interrupt comes in, at which point the task will be immediately resumed. There is some overhead there due to interrupt latency, but I noticed the MPU6000 SPI bus is running at 1MHz so I don't think interrupt latency will be a significant fraction of any transaction.

ESP_Sprite may have some additional suggestions, too.

^^ I want to write a "performance tips" section for the docs with some "traps for new players" like this, but haven't found time yet.

[ESP_Sprite]

I think Angus got most of the important bits. I think in general, it's a good idea to work with the RTOS instead of against it; while it's not perfect, it provides some very good methods to get the most out of your CPUs while still having a very low latency. For instance, this would be a perfect candidate to see if a semaphore can also do the job. Perhaps the esp-idf documentation should have some text on that; I know from experience it can take some adjustment if you're not used to it.

[michprev]

Thank you for your responses.

I have changed IMU task priority to 20. It removes most of that delays but the problem still occurs. I would start with very simple example (C only code, without SPI, without floats) slowly moving towards my code. I believe it is better to start a github issue - https://github.com/espressif/esp-idf/issues/2233.

I noticed the SPI master driver busy-waits in a while loop for a transaction to finish. In a multi-task RTOS environment this is usually bad for overall performance, as this CPU time can be used to do something else. If you use the SPI master driver in ESP-IDF then it will suspend the task until the SPI completion interrupt comes in, at which point the task will be immediately resumed. There is some overhead there due to interrupt latency, but I noticed the MPU6000 SPI bus is running at 1MHz so I don't think interrupt latency will be a significant fraction of any transaction.

MPU6000 can transfer measured data at 20 MHz so first I initialize SPI driver with 1 MHz clock and then change it. My busy waiting driver performs slightly better when running at 20 MHz.

I have also measured some 3 ms delays while running ESP-IDF SPI driver but it is hard to say where it exactly happens.

[michprev]

As a conclusion all of this I believe people should know following things:

• ESP32 ADC is crap
• GDB/OpenOCD is pretty buggy, I would not say it is usable
• there are still critical bugs in ESP-IDF like this one in task scheduling
• to be honest hardware drivers are written really badly and it does not seem to change much in the future because of backward compatibility
• many hardware bugs are not mentioned in the ECO document
• lot of code located in ROM is not used because of bugs
• toolchain development will be always slow because Xtensa is not very popular
• FPU does not seem to be very optimised

Please feel free to correct me if you believe that I am wrong in some points.