[lttng-dev] LTTng - Xenomai : different results between timestamp-lttng and rt_time_read()

[Norbert Lange]

Am Do., 20. Mai 2021 um 09:58 Uhr schrieb MONTET Julien via lttng-dev
<lttng-dev at lists.lttng.org>:
>
> Hi the developers !
>
> CONTEXT
> I am currently working on a Raspberry pi 3B with Xenomai and LTTng tools.
> Raspbian 10.9 Buster - kernel 4.19.85
> uname -a : Linux raspberrypi 4.19.85-v7+ #5 SMP PREEMPT Wed May 12 10:13:37
> Both tools are working, but I wonder about the accuracy of LTTng libraries.
>
>
> METHOD
> The code used is quite simple, it is written with the alchemy skin.
> A rt_task_spawn calls a function that has rt_task_set_periodic(NULL, TM_NOW, period) and rt_task_wait_period(NULL).
> ->The rt_task_set_periodic is based on 1ms.
> ->The  rt_task_wait_period(NULL) is of course inside a while loop (see below at the very end).
>
> My goal is to get accurate traces from Xenomai.
> I took two methods to do so :
> -> lttng
> -> basic calculation based on  rt_timer_read()
>
> What a surprise when I found both method have two different results.
> -> LTTng shows me traces [0.870;1.13] ms (or even less precise)
> -> rt_time_read shows me traces [0.980;1.020] ms
>
> Thing to note :
> -> The use of LTTng has no influence on rt_time_read(), you can use both methods at the same time.
>
> Then, I saved the output of rt_time_read inside a tracepoint.
> It appeared the LTTng is always called at the right time because the value got by rt_time_read () is really good.
>
>
> QUESTIONS
> These are now my questions :
> - What is the method I should trust ?
> - I have searched on the forum and I found LTTng uses a MONOTONIC clock for the timestamp. Can/Should I modify it ?
>
>
> CODE
> -----------------------------------------------------------------------
> A small part of my function called by rt_task_spawn :
> [...]
>     RTIME period = 1000*1000; // in ns
>     RTIME now;
>     RTIME previous = 0;
>     RTIME duration;
> [...]
>  while(1)
>     {
>         overruns = 0;
>         err = rt_task_wait_period(&overruns);
>         now = rt_timer_read();
>         tracepoint(tp_provider, tracepoint_tick_ms, now, "tick");
>
>         if (previous != 0)
>         {
>             duration=now-previous;
>             rt_printf("%llu\n \n", duration/1000);
>         }
>        previous=now;
>    [...]
> }

Are you using the Xenomai kernel ("Cobalt"), or just skins via
copperplate ("Mercury")?
You have some file /proc/xenomai/version?

The Xenomai kernel has his own clock, which in general is not
correlated to the linux monotonic clock.
(Under some circumstances it might be identical).

My plan is to use a clock plugin for Lttng, particularly because if
lttng uses the linux monotonic clock from a realtime thread
it might deadlock really good ;)

Norbert