mismatch vTaskDelay and cycle count using XTHAL_GET_CCOUNT() ?

[pataga]

I just ran some test code to find out how much time elapsed after a call to vTaskDelay using the XTHAL_GET_CCOUNT() macro and am confused by the result.

FreeRTOS tickrate set to 250, CPU clock frequency set to 80MHZ in 'make menuconfig'

Code: Select all

#include "common.h"
#include "xtensa/core-macros.h"
#include "cct.h"
#include "sdkconfig.h"
#define  CCT_TICKS_PER_US 	CONFIG_ESP32_DEFAULT_CPU_FREQ_MHZ 

static uint32_t cctMarker;

void cct_SetMarker(void) {
  cctMarker = XTHAL_GET_CCOUNT();
}

uint32_t cct_ElapsedTimeUs(void) {
  uint32_t now = XTHAL_GET_CCOUNT();
  return  (cctMarker <= now ?
    ((now - cctMarker)+CCT_TICKS_PER_US/2)/CCT_TICKS_PER_US :
    (now + (0xFFFFFFFF - cctMarker) + CCT_TICKS_PER_US/2)/CCT_TICKS_PER_US);
}

I have a task pinned to core 0 using

Code: Select all

	xTaskCreatePinnedToCore(&imu_task, "imutask", 2048, NULL, 20, NULL, 0);

and in the initialization code for that task before the while loop, I run

Code: Select all

	ESP_LOGI(TAG, "imu task started");
	ESP_LOGI(TAG, "portTICK_PERIOD_MS = %d", portTICK_PERIOD_MS);
	ESP_LOGI(TAG, "CCT_TICKS_PER_US = %d", CCT_TICKS_PER_US);
	cct_SetMarker();
	vTaskDelay(4 / portTICK_PERIOD_MS);
	uint32_t eus = cct_ElapsedTimeUs();
	ESP_LOGI(TAG, "vTaskDelay(4ms) = cct %dus", eus);

and get the result

Code: Select all

I (1518) main: imu task started
I (1518) main: portTICK_PERIOD_MS = 4
I (1526) main: CCT_TICKS_PER_US = 80
I (1534) main: vTaskDelay(4ms) = cct 1710us

I could understand if it was a bit more than 4000us, but less ?

[ESP_Sprite]

I tracked it down in the FreeRTOS code; it seems to be an artifact of how FreeRTOS works. Essentially, calling vTaskDelay(xTicksToDelay) will mark the task as sleeping, to be woken up at (xTickCount + xTicksToDelay), and forces a yield. The task is eventually unblocked in the tick function, which will increase xTickCount, check if any sleeping tasks need to wake up, and if so activates them. So:

- vTaskDelay(0) will perform the same as a yield. In practice, this is a no-op: because FreeRTOS is configured as pre-emptive in esp-idf, normally the running task is the highest-priority un-blocked task, so execution of the task will immediately resume.
- vTaskDelay(1) will sleep for the remainder of the tick, then wake the task again.
- In general, vTaskDelay(x) will sleep for (x-1) ticks, plus whatever remains of the current tick.

In general, we don't advise using vTaskDelay() and friends for any high-precision timing purposes. (My guess is that the FreeRTOS people have the same idea, hence no specifics about precise timing behaviours are mentioned in the documentation for this function.) The ESP32 has a fair amount of hardware timers; we advise configuring one of these to interrupt at the required time, then in the interrupt handler use something like a queue, semaphore or task notification to wake up a task that does the actual work.

[pataga]

OK ESP_Sprite, thanks for the explanation.

[insanoff]

Sorry for hijacking the thread. But when I run the above code it gives me this result:

Code: Select all

⸮T⸮U⸮⸮⸮2-hal-cpu.c:178] setCpuFrequencyMhz(): PLL: 320 / 4 = 80 Mhz, APB: 80000000 Hz
[I][ESP32_timer_count.ino:48] setup(): imu task started
[I][ESP32_timer_count.ino:49] setup(): portTICK_PERIOD_MS = 1
[I][ESP32_timer_count.ino:50] setup(): CCT_TICKS_PER_US = 240
[I][ESP32_timer_count.ino:54] setup(): vTaskDelay(4ms) = cct 1542us

How CCT_TICKS_PER_US is 240? It seems it is running 3 times faster. Despite of the board being max 80Mhz, CONFIG_ESP32_DEFAULT_CPU_FREQ_MHZ returns 240.

P.S. I have programmed from Arduino IDE and the board is DOIT ESP32 DEVKIT V1.

[ESP_Sprite]

CONFIG_ESP32_DEFAULT_CPU_FREQ_MHZ is a compile-time constant; it indicates the *default* CPU frequency. If you change the frequency at run-time, obviously the value doesn't match your situation anymore.