linux-kernel - Re: [ANNOUNCE] New tools: lttngtrace and lttngreport

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Date:	Mon, 15 Nov 2010 11:07:45 -0500
From:	Mathieu Desnoyers <mathieu.desnoyers@...icios.com>
To:	Linus Torvalds <torvalds@...ux-foundation.org>,
	Ingo Molnar <mingo@...e.hu>,
	Thomas Gleixner <tglx@...utronix.de>,
	Arjan van de Ven <arjan@...ux.intel.com>,
	Andrew Morton <akpm@...ux-foundation.org>,
	Steven Rostedt <rostedt@...dmis.org>
Cc:	ltt-dev@...ts.casi.polymtl.ca, linux-kernel@...r.kernel.org
Subject: Re: [ANNOUNCE] New tools: lttngtrace and lttngreport

* Mathieu Desnoyers (mathieu.desnoyers@...icios.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
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/