[LITMUS^RT] Questions about the time measurement in ft_trace

[Björn Brandenburg]

On 28 Jan 2014, at 22:33, Luo, Zheng <luozheng at wustl.edu> wrote:

> I have a question about the time measure measurement in ft_trace in Litmus.
> 
> I was wondering how does the ft_trace get the timestamp information, then I found that it used this function:
> 
> #include <asm/feather_trace.h>
> #include <asm/timex.h> /* for get_cycles() */
> static inline unsigned long long ft_timestamp(void)
> {
>     return get_cycles();
> }
> 
> This function will return the cycle of the CPU, I checked all the program in the ft_tool and the sched-trace-tool-master, I thought when you get_cycles of the CPU, should not you divide the current frequency of the CPU to get the time. I did not find the division, or the current get cycle did give you the time information?
> 
> When I run a small program, I get the output here, and I also send a picture as an attachment.
> 
> luozheng at luozheng-Ubuntu:~/Documents/Litmus/sched-trace-tools-master$ ./st_show st--6.bin 
> [         0] NAME            4420/0     on CPU  6 base_task
> [         0] PARAM           4420/0     on CPU  6 T=(cost:100.00ms, period:500.00ms, phase:  0.00ms), part=0
> [   2914923] SWITCH_FROM     4420/1     on CPU  6 
> [   2914923] SWITCH_TO       4420/1     on CPU  6 
> [   2914923] SWITCH_FROM     4420/1     on CPU  6 
> [   2914923] COMPLETION      4420/1     on CPU  6 
> [   2915423] RELEASE         4420/2     on CPU  6 2915923.27ms
> [   2915423] SWITCH_TO       4420/2     on CPU  6 
> [   2915774] SWITCH_FROM     4420/2     on CPU  6 
> [   2915774] COMPLETION      4420/2     on CPU  6 
> [   2915923] RELEASE         4420/3     on CPU  6 2916423.27ms
> [   2915923] SWITCH_TO       4420/3     on CPU  6 
> [   2916274] SWITCH_FROM     4420/3     on CPU  6 
> [   2916274] COMPLETION      4420/3     on CPU  6 
> [   2916423] RELEASE         4420/4     on CPU  6 2916923.27ms
> [   2916423] SWITCH_TO       4420/4     on CPU  6 
> [   2916774] COMPLETION      4420/4     on CPU  6 
> 
> I get a little confused here. Is number in the [] should be the cycles of the CPU? The number like 2915923.27ms is the actual time? Or how do we interpret this? I think I need some help here. Thank you very much.

Hi Zheng,

the overhead tracing uses raw processor cycles. You are looking at sched-trace-tools, which uses the same tracing infrastructure but a different time source.

	https://github.com/LITMUS-RT/litmus-rt/blob/master/litmus/sched_task_trace.c#L20

The time units in sched_trace traces are nanoseconds. The tool st_show does some rounding to display millisecond values (which for a human are easier to read).

Best regards,
Björn


-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.litmus-rt.org/pipermail/litmus-dev/attachments/20140129/181e186e/attachment.html>