[ltt-dev] LTTng and Timestamps mismatch

[compudj@krystal.dyndns.org (Mathieu Desnoyers)]

* Abhishek Karoliya (abhikaro at gmail.com) wrote:
> Hello People,
> 
> I am using LTTng to get around a scheduling and priority inheritance
> problem that we are observing on our system (powerpc e500v2 dual core,
> linux 2.6.34). However, I need map timestamps for events as seen in
> Lttng trace, kernel and application (I am using TSC divided by time
> base freq for application). I see that even though stop tracing
> (lttctl -D ) at 601.xxxxxx (/var/log/kernel )
> Nov 21 16:26:13 XRX9C93E4059FFD kernel: [ ?601.695548] LTT: 284 events
> written in channel metadata (cpu 1, index 0)
> Nov 21 16:26:13 XRX9C93E4059FFD kernel: [ ?601.710868] LTT: 40 events
> written in channel module_state (cpu 1, index 0)
> ...............................................
> Nov 21 16:26:13 XRX9C93E4059FFD kernel: [ ?601.710978] LTT: 32 events
> written in channel softirq_state (cpu 1, index 0)
> 
> When I look dump the trace using lttv, I can see events that are
> timestamped upto 670.xxxxxxxx.
> 
> I am wondering if this is due some timing offset? If yes, how could I
> match them?
> 
> My Setup
> ltt-control-0.89-05122011
> lttv-0.12.36-18112010
> linux-2.6.32 with pre-empt RT patch
> 
> Any pointers will be greatly appreciated.

The LTTng timestamps, on powerpc, are directly derived from the TB
register value, without offset. The timestamp used in printk logs is
based, if my memory serves me correctly, on the kernel monotonic clock.
You might want to check what offset they apply to this clock, or try to
record the data from userspace through the marker_event (was theat even
the exact name, not sure anymore) debugfs file exposed by lttng through
debugfs. It's also possible that the printk timestamps are based on the
current time of day, which is offset by the ntp-correction.

Or you can try lttng 2.0. It comes with kernel and user-level tracing.
For the moment, it uses the CLOCK_MONOTONIC clock source both both
kernel and user-level tracing (until we reimplement the trace clocks
into lttng 2.0 and the vDSOs for userspace LTTng-UST). We also have the
dynamic task priority and nice level that we can record along with
events (see lttng add-context), which will be tremendously useful to
debug the kind of priority inversion problem you are investigating.

However, you need a kernel version >= 2.6.35 to build the lttng-modules.
No kernel patches are required (it's just a module package).

For more info, see http://lttng.org/lttng2.0

Best regards,

Mathieu


> 
> Thanks
> Abhi
> 
> _______________________________________________
> ltt-dev mailing list
> ltt-dev at lists.casi.polymtl.ca
> http://lists.casi.polymtl.ca/cgi-bin/mailman/listinfo/ltt-dev
> 

-- 
Mathieu Desnoyers
Operating System Efficiency R&D Consultant
EfficiOS Inc.
http://www.efficios.com