* Remy Bohmer (l.pinguin@xxxxxxxxx) wrote: > Hello, > > I am looking for some tool/kernel machanism that enables me to track > every schedule change on the CFS scheduler of the RT-kernel for some > period of time. > Thus a tool that gives me an overview after some time which task got > "scheduled in/out" at "which timestamp" and at "which CPU". ( I need > the raw data) > > In a far past (on Montavista kernels) I used LTT for this to log for > some time with only the SCHED_CHANGE filter and text output. But, I > cannot find any LTT(ng) support for any RT-kernel, and support for the > new CFS (like in 2.6.22.1-rt4) is even harder. > > So I was wondering if anybody knows some tool/kernel mechanism which > can do this? > If not, I will build a kernel extension for it myself (new extension > to 'latency_trace' ?) > In that case can anybody with in depth CFS scheduler knowledge please > point me which hooks are safe to use for this? Hi Remy, Due to popular demand, I just ported LTTng 0.9.10 to 2.6.22.1-rt4. It may deserve some more testing, but it runs fine on my x86_32. Please note that I ported my last stable LTTng version, so some code is not as shiny as the new one (work in progress), but it works. Please refer to http://ltt.polymtl.ca, mostly the QUICKSTART GUIDE and the compatibility list. On X86, everything should work fine. Just make sure that your architecture has a stable and coherent TSC across CPUs. See ltt/ltt-test-tsc.c (it printk a message at boot time) to see if yours is ok. See my documentation on my website on how to tweak different Intel/AMD if needed. For your ARM needs, you may have to tweak include/asm-arm/ltt.h so it reads a time base register (or the equivalent). Right now, it defaults to use a logical clock, which is clearly not what you need. I guess you'll want to disable the "userspace tracing", since I did not port ltt-usertrace, so it's not very userful then, and also disable the "locking instrumentation", which generates a _lot_ of output. I know Thomas and Steven were also interested in this port. Direct link to the patches: http://ltt.polymtl.ca/lttng/patch-2.6.22.1-rt4-lttng-0.9.10.tar.gz Mathieu P.S. : To give you an idea of the output: (you know the CPU id with processes_1 or processes_0) ./lttv -m textDump -e "event.name=sched_schedule" -t /tmp/trace2 (System at 250HZ with PREEMPT_RT) A little legend: group.event : time since boot, in s.ns (tracefile name, ending with cpu ID), Thread ID ("pid"), Thread group ID (posix pid), process name, thread name (need userspace instrumentation), Parent PID, Userspace function (need userspace instrumentation), execution mode (SYSCALL/USERMODE/TRAP/IRQ...) { event specific data } The event specific (raw) data for sched_schedule is: PID out PID in previous state : State of the process we are scheduling out : -1 unrunnable, 0 runnable, >0 stopped ----------------------------------------------------------------------------------------------------------------------------------------------- kernel.sched_schedule: 228.034115347 (/tmp/trace2/control/processes_1), 0, 0, swapper, UNBRANDED, 0, 0x0, SYSCALL { 3517, 0, 2 } kernel.sched_schedule: 228.034152186 (/tmp/trace2/control/processes_1), 3517, 3517, openbox, UNBRANDED, 3506, 0x0, SYSCALL { 0, 3517, 0 } kernel.sched_schedule: 228.034158271 (/tmp/trace2/control/processes_1), 0, 0, swapper, UNBRANDED, 0, 0x0, SYSCALL { 3517, 0, 2 } kernel.sched_schedule: 228.034195970 (/tmp/trace2/control/processes_1), 3517, 3517, openbox, UNBRANDED, 3506, 0x0, SYSCALL { 0, 3517, 0 } kernel.sched_schedule: 228.034286860 (/tmp/trace2/control/processes_1), 0, 0, swapper, UNBRANDED, 0, 0x0, SYSCALL { 3517, 0, 2 } kernel.sched_schedule: 228.034323741 (/tmp/trace2/control/processes_1), 3517, 3517, openbox, UNBRANDED, 3506, 0x0, SYSCALL { 0, 3517, 0 } kernel.sched_schedule: 228.034329641 (/tmp/trace2/control/processes_1), 0, 0, swapper, UNBRANDED, 0, 0x0, SYSCALL { 3517, 0, 2 } kernel.sched_schedule: 228.034431602 (/tmp/trace2/control/processes_1), 3517, 3517, openbox, UNBRANDED, 3506, 0x0, SYSCALL { 0, 3517, 0 } kernel.sched_schedule: 228.034522657 (/tmp/trace2/control/processes_1), 0, 0, swapper, UNBRANDED, 0, 0x0, SYSCALL { 3517, 0, 2 } kernel.sched_schedule: 228.034560416 (/tmp/trace2/control/processes_1), 3517, 3517, openbox, UNBRANDED, 3506, 0x0, SYSCALL { 0, 3517, 0 } kernel.sched_schedule: 228.034566830 (/tmp/trace2/control/processes_1), 0, 0, swapper, UNBRANDED, 0, 0x0, SYSCALL { 3517, 0, 2 } kernel.sched_schedule: 228.034603585 (/tmp/trace2/control/processes_1), 3517, 3517, openbox, UNBRANDED, 3506, 0x0, SYSCALL { 0, 3517, 0 } kernel.sched_schedule: 228.034694824 (/tmp/trace2/control/processes_1), 0, 0, swapper, UNBRANDED, 0, 0x0, SYSCALL { 3517, 0, 2 } kernel.sched_schedule: 228.034732186 (/tmp/trace2/control/processes_1), 3517, 3517, openbox, UNBRANDED, 3506, 0x0, SYSCALL { 0, 3517, 0 } kernel.sched_schedule: 228.034738403 (/tmp/trace2/control/processes_1), 0, 0, swapper, UNBRANDED, 0, 0x0, SYSCALL { 3517, 0, 2 } kernel.sched_schedule: 228.034844221 (/tmp/trace2/control/processes_1), 3517, 3517, openbox, UNBRANDED, 3506, 0x0, SYSCALL { 0, 3517, 0 } kernel.sched_schedule: 228.034934946 (/tmp/trace2/control/processes_1), 0, 0, swapper, UNBRANDED, 0, 0x0, SYSCALL { 3517, 0, 2 } kernel.sched_schedule: 228.034971955 (/tmp/trace2/control/processes_1), 3517, 3517, openbox, UNBRANDED, 3506, 0x0, SYSCALL { 0, 3517, 0 } kernel.sched_schedule: 228.034978030 (/tmp/trace2/control/processes_1), 0, 0, swapper, UNBRANDED, 0, 0x0, SYSCALL { 3517, 0, 2 } kernel.sched_schedule: 228.035015261 (/tmp/trace2/control/processes_1), 3517, 3517, openbox, UNBRANDED, 3506, 0x0, SYSCALL { 0, 3517, 0 } kernel.sched_schedule: 228.035106149 (/tmp/trace2/control/processes_1), 0, 0, swapper, UNBRANDED, 0, 0x0, SYSCALL { 3517, 0, 2 } kernel.sched_schedule: 228.035143190 (/tmp/trace2/control/processes_1), 3517, 3517, openbox, UNBRANDED, 3506, 0x0, SYSCALL { 0, 3517, 0 } kernel.sched_schedule: 228.035149302 (/tmp/trace2/control/processes_1), 0, 0, swapper, UNBRANDED, 0, 0x0, SYSCALL { 3517, 0, 2 } kernel.sched_schedule: 228.035257005 (/tmp/trace2/control/processes_1), 3517, 3517, openbox, UNBRANDED, 3506, 0x0, SYSCALL { 0, 3517, 0 } kernel.sched_schedule: 228.035347665 (/tmp/trace2/control/processes_1), 0, 0, swapper, UNBRANDED, 0, 0x0, SYSCALL { 3517, 0, 2 } kernel.sched_schedule: 228.035384087 (/tmp/trace2/control/processes_1), 3517, 3517, openbox, UNBRANDED, 3506, 0x0, SYSCALL { 0, 3517, 0 } kernel.sched_schedule: 228.035390224 (/tmp/trace2/control/processes_1), 0, 0, swapper, UNBRANDED, 0, 0x0, SYSCALL { 3517, 0, 2 } kernel.sched_schedule: 228.035427396 (/tmp/trace2/control/processes_1), 3517, 3517, openbox, UNBRANDED, 3506, 0x0, SYSCALL { 0, 3517, 0 } kernel.sched_schedule: 228.035517226 (/tmp/trace2/control/processes_1), 0, 0, swapper, UNBRANDED, 0, 0x0, SYSCALL { 3517, 0, 2 } kernel.sched_schedule: 228.035554700 (/tmp/trace2/control/processes_1), 3517, 3517, openbox, UNBRANDED, 3506, 0x0, SYSCALL { 0, 3517, 0 } kernel.sched_schedule: 228.035560842 (/tmp/trace2/control/processes_1), 0, 0, swapper, UNBRANDED, 0, 0x0, SYSCALL { 3517, 0, 2 } kernel.sched_schedule: 228.035669682 (/tmp/trace2/control/processes_1), 3517, 3517, openbox, UNBRANDED, 3506, 0x0, SYSCALL { 0, 3517, 0 } -- Mathieu Desnoyers Computer Engineering Ph.D. Student, Ecole Polytechnique de Montreal OpenPGP key fingerprint: 8CD5 52C3 8E3C 4140 715F BA06 3F25 A8FE 3BAE 9A68 - To unsubscribe from this list: send the line "unsubscribe linux-rt-users" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
