lkml.org 
[lkml]   [2010]   [Nov]   [15]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: [ANNOUNCE] New tools: lttngtrace and lttngreport
* Mathieu Desnoyers (mathieu.desnoyers@efficios.com) wrote:
> Hi everyone,
>
> Recently, Linus came up with a request: a "super-strace" based on kernel
> tracing. So I just came up with two bash scripts that perform exactly this within
> LTTng: lttngtrace starts tracing, runs a program, stops tracing. lttngreport
> generates a wakeup dependency report. I'm appending the script below (depends on
> LTTng kernel tree, LTTng modules package, ltt-control and lttv).
>
> It will report which interrupt/softirq and wakeup dependency chain caused each
> wakeup, along with the duration within each step of the wakeup chain. This
> includes I/O activity, traps, and syscalls.

Hi again,

I just enhanced the wakeup dependency chain output to make it more
understandable by humans. It's astonishing what we can do with a bit of ASCII
art. For instance, here I am showing piece of firefox start trace:

--> Blocked in RUNNING, SYSCALL 142 [sys_select+0x0/0xc0], ([...], dur: 0.029567)
| --> Blocked in RUNNING, SYSCALL 168 [sys_poll+0x0/0xc0], ([...], dur: 1.187935)
| --- Woken up by an IRQ: IRQ 0 [timer]
--- Woken up in context of 7401 [gnome-power-man] in high-level state RUNNING

As you see, firefox blocked for 29.5 microseconds on select() waiting for a file
descriptor, the wake up came from "gnome-power-manager" after the poll() timed
out (1 second timeout). (This specific scenario cannot be reproduced at every
firefox run, but it is still a good example of how these spurious delays can be
identified with the tool.)

Thanks,

Mathieu

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


\
 
 \ /
  Last update: 2010-11-15 17:11    [W:0.114 / U:0.016 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site