[ltt-dev] LTTng and Timestamps mismatch

[abhikaro@gmail.com (Abhishek Karoliya)]

Thanks Mathieu for the pointers...

I have got a half cooked third party kernel when it comes to lttng
patches which is making it harder than it has to get to the code. The
kernel has been applied with Lttng patches but no one knows which
version of the patch reside. Off target but it will be immense help is
you or anyone could give help me deduce what kernel patch version has
been applied. What files or strings I could search? It is a 2.6.34
kernel with pre-empt rt patch.

I am all for 2.0 but the program here hasn't progressed to 2.6.35 and
it will be some time before we will start using it.

On Tue, Nov 22, 2011 at 11:50 AM, Mathieu Desnoyers
<compudj at krystal.dyndns.org> wrote:
> * 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
>