* Tony Jones ([email protected]) wrote:
> Sam Liao wrote:
> > >> I'm trying to combine the kernel trace and userspace trace, and it
> > >> seems that the
> > >> the userspace events can not be recognized to the right process with the
> > >> kernel
> > >> events. I'm not sure if this is a problem of timestamp between kernel
> > >> and userspace.
>
> Mathieu Desnoyers wrote:
> > > should work. Make sure your architecture (on x86) has synchronized
> > > contant TSCs. LTTng complains about using a work-around in dmesg if it
> > > is not the case.
>
> Sam Liao wrote:
> > Thanks, after apply with the "rdtsc" clock source and set up the correct
> > clock frequency, the kernel trace and ust trace seems to be consistent
> > now.
>
> Hi.
>
> I'm not having much luck with this. First attempt at it, so I'm curious if
> it's user error?
Just so you know, we're about to release a clock_gettime vDSO in LTTng
for UST which will take care of all this automagically.
Meanwhile, it looks like you forgot to switch your UST from the generic
"clock_gettime MONOTONIC" clock source to rdtsc.
Thanks,
Mathieu
>
>
> New HP Proliant DL785 (16 core)
>
> To keep things simple I asserted maxcpus=1 on the cmdline so /proc/cpuinfo is:
>
> # cat /proc/cpuinfo
> processor : 0
> vendor_id : AuthenticAMD
> cpu family : 16
> model : 9
> model name : AMD Opteron(tm) Processor 6128
> stepping : 1
> cpu MHz : 800.000
> cache size : 512 KB
> physical id : 0
> siblings : 1
> core id : 0
> cpu cores : 1
> apicid : 16
> initial apicid : 0
> fpu : yes
> fpu_exception : yes
> cpuid level : 5
> wp : yes
> flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov
> pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt pdpe1gb
> rdtscp lm 3dnowext 3dnow constant_tsc up rep_good nonstop_tsc extd_apicid
> amd_dcm pni monitor cx16 popcnt lahf_lm cmp_legacy svm extapic cr8_legacy abm
> sse4a misalignsse 3dnowprefetch osvw ibs skinit wdt nodeid_msr npt lbrv
> svm_lock nrip_save
> bogomips : 4000.18
> TLB size : 1024 4K pages
> clflush size : 64
> cache_alignment : 64
> address sizes : 48 bits physical, 48 bits virtual
> power management: ts ttp tm stc 100mhzsteps hwpstate
>
>
> versions:
> kernel 2.6.34.7
> ust 0.9
> lttctl 0.88
> lttv 0.12.36
>
> # dmesg | egrep "tsc|LTT"
> [ 0.361042] Switching to clocksource tsc
> [ 1.722190] LTT : ltt-relay init
> [ 1868.196100] LTT: 14 events written in channel metadata (cpu 0, index 0)
> [ 1948.140099] LTT: 96 events written in channel metadata (cpu 0, index 0)
> [ 1948.140263] LTT: 12921 events written in channel kernel (cpu 0, index 0)
> [ 1982.495770] LTT: 96 events written in channel metadata (cpu 0, index 0)
> [ 1982.495779] LTT : unread channel metadata offset is 262144 and cons_off :
> 0 (cpu 0)
> [ 1982.495786] LTT : metadata : commit count : 262144, subbuf size 262144
> [ 1982.495850] LTT : unread channel swap_state offset is 65536 and cons_off :
> 0 (cpu 0)
> [ 1982.495857] LTT : swap_state : commit count : 65536, subbuf size 65536
> [ 1982.495884] LTT : unread channel module_state offset is 65536 and cons_off
> : 0 (cpu 0)
> [ 1982.495890] LTT : module_state : commit count : 65536, subbuf size 65536
> [ 1982.495915] LTT : unread channel softirq_state offset is 65536 and
> cons_off : 0 (cpu 0)
> [ 1982.495922] LTT : softirq_state : commit count : 65536, subbuf size 65536
> [ 1982.495947] LTT : unread channel syscall_state offset is 65536 and
> cons_off : 0 (cpu 0)
> [ 1982.495954] LTT : syscall_state : commit count : 65536, subbuf size 65536
> [ 1982.495979] LTT : unread channel irq_state offset is 65536 and cons_off :
> 0 (cpu 0)
> [ 1982.495985] LTT : irq_state : commit count : 65536, subbuf size 65536
> [ 1982.496055] LTT: 12657 events written in channel kernel (cpu 0, index 0)
> [ 1982.496062] LTT : unread channel kernel offset is 1048576 and cons_off : 0
> (cpu 0)
> [ 1982.496070] LTT : kernel : commit count : 1048576, subbuf size 1048576
>
>
> The last ust timestamp is before the first kernel trace timestamp.
>
> # rm -rf /tmp/trace? /root/.usttraces
> # lttctl -C -w /tmp/traceK traceK
> Linux Trace Toolkit Trace Control 0.88-09242010
>
> Controlling trace : traceK
>
> lttctl: Creating trace
> lttctl: Forking lttd
> Linux Trace Toolkit Trace Daemon 0.88-09242010
>
> Reading from debugfs directory : /sys/kernel/debug/ltt/traceK
> Writing to trace directory : /tmp/traceK
>
> lttctl: Starting trace
>
> # usttrace ./ust
> Waiting for ustd to shutdown...
> Trace was output in: /root/.usttraces/svr2-20101210050221043250710
>
> # lttctl -D traceK
> Linux Trace Toolkit Trace Control 0.88-09242010
>
> Controlling trace : traceK
>
> lttctl: Pausing trace
> lttctl: Destroying trace
>
> # mv /root/.usttraces/svr2-20101210050221043250710/3689_5549038222480296963
> /tmp/traceU
>
> # lttv -m textDump -t /tmp/traceK | head -3
> Trace set contains 1 traces
>
> metadata.core_marker_id: 2994.531659669 (/tmp/traceK/metadata_0), 0, 0, , ,
> 0, 0x0, MODE_UNKNOWN { channel = "kernel", name =
> "page_fault_get_user_entry", event_id = 0, int = 4, long = 8, pointer = 8,
> size_t = 8, alignment = 0 }
>
> # lttv -m textDump -t /tmp/traceU | head -3
> Trace set contains 1 traces
>
> metadata.core_marker_id: 2840.195433153 (/tmp/traceU/metadata_0), 0, 0, , ,
> 0, 0x0, MODE_UNKNOWN { channel = "ust", name = "potential_exec", event_id =
> 0, int = 4, long = 8, pointer = 8, size_t = 8, alignment = 0 }
>
> # lttv -m textDump -t /tmp/traceU | tail -3
> ust.time_end: 2840.198082665 (/tmp/traceU/ust_0), 0, 0, , , 0, 0x0,
> MODE_UNKNOWN
> End trace set
>
--
Mathieu Desnoyers
Operating System Efficiency R&D Consultant
EfficiOS Inc.
http://www.efficios.com
_______________________________________________
ltt-dev mailing list
[email protected]
http://lists.casi.polymtl.ca/cgi-bin/mailman/listinfo/ltt-dev
