xTaskGetTickCount() erroneously skips ahead

xTaskGetTickCount() erroneously skips ahead after every 65536 ticks. So when calculating timing using values returned by xTaskGetTickCount(), there are problems!

vTaskDelay() has no problems. The problem is with xTaskGetTickCount()!

For example:

Code:

TickType_t tickCount1, tickCount2;
while (1) {
tickCount1 = xTaskGetTickCount();
vTaskDelay(25);
tickCount2 = xTaskGetTickCount();
printf(“[%ld] %u ms have passed!\r\n”,
tickCount2, (tickCount2-tickCount1));
}

Output:

[64887] 25 ms have passed!
[64912] 25 ms have passed!
[64937] 25 ms have passed!
[64962] 25 ms have passed!
[66087] 1125 ms have passed!
[66112] 25 ms have passed!
[66137] 25 ms have passed!
[66162] 25 ms have passed!
[66187] 25 ms have passed!

Workaround is to use vTaskDelay() instead:

TickType_t tickCount = 0;
while (1) {
vTaskDelay(25);
tickCount += 25;
printf(“[%ld] %u ms have passed!\r\n”,
xTaskGetTickCount(), tickCount);
}

PLATFORM:
Microprocessor: STM32L496xx (ARM Cortex-M4)
GNU Tools for STM32 (11.3.rel1)
FreeRTOS API CMSIS v2
FreeRTOS version 10.3.1
CMSIS-RTOS version 2.00

Should I be reporting this defect here, on FreeRTOS’s GitHub, or to STMicroelectronics?

I would check if there is some task in your system that uses a lot of CPU on that sort of period. Remember, the tick counter is just counting Tick Interrupts, which is also what vTaskDelay is based on, so it is hard to imagine what could get them out of sync.

It is also possible that your code is somewhere (not likely here) overwriting the value in the tick counter.

One thing also to note, if this task started at startup, and never got delayed by other tasks, the values of the tick counter should have been all multiples of 25, but they aren’t, so there is signs that other tasks are involved here.

[64962] 25 ms have passed!
[66087] 1125 ms have passed!
[66112] 25 ms have passed!

Is there another task running, beside the task that prints the current time?
And would it be possible that the second task keeps the CPU busy for 1125 ms?

Another thing to look at, you seem to think the vTaskDelay is only delaying for 25 ms, but the Tick Counter is jumping, you could show that by setting up another timer in the system that is just free running and able to measure long times (that processor has some 32 bit timers, or the low power timers at 32k Hz to get the intervals) and see if the issue it the Tick Counter jumping, or (as we have said more likely) the task just doesn’t get to run for a while.

vTaskDelay() is certainly delaying the correct amount of time. I’ve verified this in many ways, even so far as to write to GPIO and measuring using oscilloscope.

I like your idea of checking if tick-count is being overwritten somehow…

Exactly 25 ms is passing between each of those prints. I am 100% certain.

One issue with the oscilloscope verification of timing is you don’t know which particular delay you are looking at, and the one in a thousand longer gap isn’t noticeable unless you are VERY careful how you trigger, and only see the longer pulse periods.

That is why independent verification with another time source would be important. NOT something that just looks at “most” of the delays.

Debugging very occasional happenings is hard.

Very good advice. But I insist that I’ve verified this, in many ways.

It’s not occasional. It happens everytime the tick-count crosses 65536, which in my system is circa every 10 seconds.

is the offending delta always 1125 or does it vary?

Which is still less than 1 time in a 1000 delays.

You may “insist” that you have, but not shown how, and shown that the verification was correct. As I pointed out, the one method you did quote has the problem that is shows the “normal” value and not the extra-ordinary. (If you did the special test to confirm NO wider periods, please indicate what you did).

Note, the interesting thing is that the jump occurs well BEFORE the counter would wrap, and makes it wrap, which is an unlikely spot to have such an error.

One thought, you say ~ 10 seconds is 65k ticks, which says the tick counter is much faster that 1 ms. One issue with tick rates about 1k Hz is that some of the helper macros don’t work. Also, is says your taking the difference and calling it ms is incorrect.

1 Like

I was incorrect, it’s roughly every minute.

I will collect more evidence, and present here.

Please also change your code to dump both the in and out tick counts along with the delta, it may be a subtle flaw in the printf() implementation.

1 Like

@asvatik, are you the person who submitted the issue/bug “xTaskGetTickCount() erroneously skips ahead #918”?

If you read carefully the above posts by @richard-damon and by @RAc , you will find unanswered questions.

Is there a LED on your testing board? Can you make it blink in every loop, like this:

TickType_t tickCount1, tickCount2;
BaseType_t xDoSet = pdFALSE;
while (1)
{
    tickCount1 = xTaskGetTickCount();
    vTaskDelay(25);
    tickCount2 = xTaskGetTickCount();
    printf(“[%ld] %u ms have passed!\r\n”,
        tickCount2,
        ( tickCount2 - tickCount1 ) );

    set_led( xDoSet );
    xDoSet = !xDoSet;
}

Can you run the program two times, once while calling printf(), and once while skipping the call printf()? I wonder if your printf() blocks on some condition.

Earlier you asked:

I think this forum is the best place.

I ran the same code on STM32H743ZI which uses the same FreeRTOS port and I got the following results:

[64960] 25 ms have passed!
[64987] 25 ms have passed!
[65014] 25 ms have passed!
[65041] 25 ms have passed!
[65068] 25 ms have passed!
[65095] 25 ms have passed!
[65122] 25 ms have passed!
[65149] 25 ms have passed!
[65176] 25 ms have passed!
[65203] 25 ms have passed!
[65230] 25 ms have passed!
[65257] 25 ms have passed!
[65284] 25 ms have passed!
[65311] 25 ms have passed!
[65338] 25 ms have passed!
[65365] 25 ms have passed!
[65392] 25 ms have passed!
[65419] 25 ms have passed!
[65446] 25 ms have passed!
[65473] 25 ms have passed!
[65500] 25 ms have passed!
[65527] 25 ms have passed!
[65554] 25 ms have passed!
[65581] 25 ms have passed!
[65608] 25 ms have passed!
[65635] 25 ms have passed!
[65662] 25 ms have passed!
[65689] 25 ms have passed!
[65716] 25 ms have passed!
[65743] 25 ms have passed!
[65770] 25 ms have passed!
[65797] 25 ms have passed!
[65824] 25 ms have passed!
[65851] 25 ms have passed!
[65878] 25 ms have passed!
[65905] 25 ms have passed!
[65932] 25 ms have passed!
[65959] 25 ms have passed!
[65986] 25 ms have passed!
[66013] 25 ms have passed!
[66040] 25 ms have passed!
[66067] 25 ms have passed!
[66094] 25 ms have passed!
[66121] 25 ms have passed!
[66148] 25 ms have passed!
[66175] 25 ms have passed!
[66202] 25 ms have passed!

Do you have other tasks in your system? Did you generate the project yourself or are you using any sample? Can you share your complete code?

Everyone’s suspicions were correct. If I move my test-code to a separate task with a high enough priority, I am unable to reproduce the problem. In the future, I will do such elementary testing prior to making a post here.

It’s a large project with many tasks and intermittent behavior, and I let myself jump to conclusions. My task at hand is to find which code in which task is blocking, and re-prioritize tasks and/or move code to a new task.

I thank everyone for the replies.

1 Like

Thank you for reporting back.

I thank everyone for the replies.

You are welcome.