micros() returning inconsistent values when call from different tasks

[stickbreaker]

The cycle count that micros() is using to report timing is a PER Task value. When micros() or delayMicroseconds() is called from different Tasks, the lastCycleCount value may have no relationship to the current Task specific cycleCount. If the current cycleCount is less than the saved lastCycleCount a rollover condition is assumed. This erroneous conditions results in incorrect delays and reported microseconds. This fix creates thread local storage so that each Task will have accurate microsecond reporting and delays. The reported microseconds are not real time, they are microseconds of the current Task execution.

[tferrin]

Very nice, Chuck! I have looked at that code several times and thought it just was not enough in an RTOS environment. Also, is special register %0 a per core entity? And maybe you can also enlighten me as to what other process/event/hardware manipulate this register. The Tensilica LX6 documentation is a pretty heavy read.

I assume it's okay to do a malloc() inside an ISR, although I've never written code that did so. Not sure how you can avoid it here. But you should at least make sure the return value is not NULL or ptr[0] and ptr[1] will surely lead to doom.

[stickbreaker]

@tferrin I have no Idea how to decode the __asm() statement. I am just going by observation and Asumptions. I assumed the original code produced a valid microsecond count. I compared millis() and micro() both progressed at the same relative rates, when I only called them from the main loop. millis() uses a FreeRTOS call to get the PER task tick count. This tick count is independent for each task. So, I inferred the __asm() statement was obtaining a cycleCount because of the math being applied to it (ccount / CONFIG_ESP32_DEFAULT_CPU_FREQ_MHZ). I verified it with multiple tasks after I coded it.

This code has nothing to do with an interrupt, except that it has been declared IRAM. I assumed the IRAM declaration was from performance reasons. I don't see how I could identify if it was called from an interrupt or not. I personally haven't ever called micros() from a ISR. I try to minimize function calls from ISR's, and I assume only my ISR code or Specified OS functions are safe for ISR usage.

If the malloc() fails on an 8 byte allocation, I can see no recovery or continuation. The storage to 0x0 will generate a guru mediation fault. So that should be front and center, the stack trace should be self explanatory.

I have never found any reliable documentation, the Espressif hardware docs on readthedocs are almost useless. My reading through the hal layers has been the most beneficial. But, they are so sparse on comments that guesses must fill in for facts.

Chuck.

[me-no-dev]

very very nice :)

[igrr]

FYI: There is a function which returns consistent time since startup, in microseconds — esp_timer_get_time. It can be called from both cores, from tasks and ISRs. It is also much faster than accessing the thread local storage — it takes less than 1 us to complete. It returns a 64 bit wide result, so you can also implement uint64_t micros64() using it (similar to what is implemented in ESP8266 Arduino now).

[tferrin]

@igrr, if you stall the cores by calling esp_light_sleep_start(), does esp_timer_get_time() still accurately keep track of time since startup?

[igrr]

@tferrin, it does not do that yet (in the same way that CCOUNT method used here doesn't).

However we will roll out support for automatic light sleep into IDF soon, where RTOS will be able to put the system into light sleep when no tasks are expected to run for a few ticks. As part of that work, we are also fixing the interaction between light sleep and esp_timer timekeeping.

[Electrozest]

Will the roll out of automatic low power sleep still work if the WiFi is enabled and disabled periodically?

Currently, I find that low power sleep can only be used after:

WiFi.disconnect(true);
esp_wifi_stop();
esp_wifi_set_mode(WIFI_MODE_NULL);

If WiFi is enabled, delay() or vTaskDelay() or delayMicroseconds() work ok, but not low power sleep. I assume WiFi stack requires CPU running continuously.

As per espressif/esp-idf#1864 , esp_light_sleep_start() is enabling and disabling the hardware WDT, which means that any code which requires HW WDT can end up with WDT disabled after light sleep. The automatic light sleep mode will need to preserve the state of the HW WDT so that any application out in the field (i.e. at remote location) is not left unprotected from any FreeRTOS stall/blocking states.

[igrr]

@Electrozest automatic light sleep (while keeping WiFi connection) is now supported in ESP-IDF (master branch). Please check the updated wifi/power_save example.

@tferrin The changes also affect esp_timer_get_time — now the time is correctly updated after light sleep (subject to RTC timer accuracy).