FreeRTOS ticks vs System ticks

[stefan.nagel]

Dear community,
I seem to lack some understanding of the ticks in an ESP system with FreeRTOS integrated.

I created a task in FreeRTOS and in that task I call the following code as an test-example:

Code: Select all

    
    xLastWakeTime = xTaskGetTickCount();

    while(counter < 10)
    {
        if(gpio_state != 0)
        {
            gpio_state = 0;
        }
        else
        {
            gpio_state = 1;
        }
        gpio_set_level(PIN_RESET_SAFETY_UC, gpio_state);
        ESP_LOGI("TEST_LOGGING", "This is round %d at tick %d Here comes just stuff X",counter, (int)xLastWakeTime);

        counter++;
        vTaskDelayUntil(&xLastWakeTime, 10);
    }
    

This gives me the follwing output:
I (12572) TEST_LOGGING: This is round 0 at tick 12258 Here comes just stuff
I (12582) TEST_LOGGING: This is round 1 at tick 12268 Here comes just stuff
I (12601) TEST_LOGGING: This is round 2 at tick 12278 Here comes just stuff
I (12620) TEST_LOGGING: This is round 3 at tick 12288 Here comes just stuff
I (12640) TEST_LOGGING: This is round 4 at tick 12298 Here comes just stuff
I (12660) TEST_LOGGING: This is round 5 at tick 12308 Here comes just stuff
I (12680) TEST_LOGGING: This is round 6 at tick 12318 Here comes just stuff
I (12700) TEST_LOGGING: This is round 7 at tick 12328 Here comes just stuff
I (12720) TEST_LOGGING: This is round 8 at tick 12338 Here comes just stuff
I (12740) TEST_LOGGING: This is round 9 at tick 12348 Here comes just stuff


Actually, I would assume that the tick time for the RTOS maches the time from the LOG Timestamp. At least that the difference between both times are matching. Do I understand here something wrong, or did I somewhere mess up with the FreeRTOS integration?

PS: FreeRTOS is configured to run at 1000 Hz --> I Tick 1ms

[bidrohini]

The tick count returned by xTaskGetTickCount() and the timestamps you see in the logs are both related to time, but they are different concepts and don't necessarily match each other.

FreeRTOS uses a tick count to keep track of time in the system. The tick count represents the number of ticks that have occurred since the system started. The length of a tick is determined by the FreeRTOS configuration, and in your case, it is 1 millisecond (1000 Hz tick rate). Each time vTaskDelayUntil() is called, it waits for a specific number of ticks, which you've set to 10 ticks (10 ms).

The log timestamps, on the other hand, are generated by the logging mechanism provided by ESP-IDF. These timestamps represent the time when the log message was processed and printed to the console.

The key difference here is that the tick count is continuously increasing in the background, regardless of whether any log message is being printed or not. The logging mechanism, on the other hand, might have some internal buffering or other processing delays before actually printing the log message. Therefore, the log timestamps can have some minor variations due to these factors.

[stefan.nagel]

The key difference here is that the tick count is continuously increasing in the background, regardless of whether any log message is being printed or not. The logging mechanism, on the other hand, might have some internal buffering or other processing delays before actually printing the log message. Therefore, the log timestamps can have some minor variations due to these factors.

--> Yes ... I thought so, too. But when I take a look at the osci:

MicrosoftTeams-image.jpg (742.28 KiB) Viewed 4637 times

I see that there is a time difference in toggling the GPIO of around 20ms ... which matches the LOG timestamp.
If I would just rely on the RTOS TickCount .. I would think there is a clear toggling with every 10ms.

It seems that the ESP_LOG or better the ESP_output kind of messes up the tick count for this example task.