linux-kernel - Re: [PATCH] new irq tracer

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]

Message-ID: <20090219021302.GB5785@nowhere>
Date:	Thu, 19 Feb 2009 03:13:02 +0100
From:	Frederic Weisbecker <fweisbec@...il.com>
To:	Peter Zijlstra <peterz@...radead.org>
Cc:	Jason Baron <jbaron@...hat.com>, mingo@...e.hu,
	rostedt@...dmis.org, linux-kernel@...r.kernel.org,
	acme@...stprotocols.net, fche@...hat.com,
	compudj@...stal.dyndns.org
Subject: Re: [PATCH] new irq tracer

On Wed, Feb 18, 2009 at 10:46:20PM +0100, Peter Zijlstra wrote:
> On Wed, 2009-02-18 at 16:35 -0500, Jason Baron wrote:
> > On Wed, Feb 18, 2009 at 10:15:25PM +0100, Peter Zijlstra wrote:
> > > On Wed, 2009-02-18 at 14:53 -0500, Jason Baron wrote:
> > > > hi,
> > > > 
> > > > Using a copule of tracepoints i've implemented an 'irq tracer' which has
> > > > the following column format:
> > > > 
> > > > [time][irq][action][handled][cpu][length]
> > > > 
> > > > for example on my system:
> > > > 
> > > > [ 1038.927248381]     28     eth0      1        3     0.000002745
> > > > [ 1038.927544688]     28     eth0      1        3     0.000002520
> > > > [ 1038.927593609]     28     eth0      1        3     0.000002509
> > > > [ 1038.974087675]     29     ahci      1        1     0.000013135
> > > > [ 1038.974288475]     29     ahci      1        1     0.000005542
> > > > [ 1038.974414324]     29     ahci      1        1     0.000007953
> > > > 
> > > > I think this patch is useful in understanding irq system behavior, and
> > > > for tracking down irq driver handlers that are firing too often or
> > > > spending too much time handling an irq. This approach could be extended
> > > > to the timer irq and for softirqs...
> > > 
> > > The function graph tracer can already do this, it has a special section
> > > to recognize irq entry function, and already measures time spend.
> > > 
> > > I guess with Steve's new triggers (probes or whatever they ended up
> > > being called) you could limit it to just IRQ entry points.
> > > 
> > 
> > i did look at the graph tracer first. While it does measure irq related
> > functions, it does not give this level of detail concerning which irq #,
> > which irq handler is involved, and whether or not the irq was handled
> > successfully or not. So I believe this tracepoints add a level of detail
> > that the graph tracer does not have. Furthermore, this patch requires 2
> > tracepoints, not instrumentation for all kernel functions.
> 
> How useful is that return value?
> 
> Much of the other data is already available, /proc/interrupts will
> happily tell you the source of your interrupt storm. The irq-off latency
> tracer will tell you if stuff takes too much time, the graph tracer can
> tell you what is taking how much time.
> 
> I really am having a difficult time seeing the use in such narrow
> tracers.
> 

Well, something that could be done would be to use this irq tracing framework
to produce the average of time spent in each irq handler.

kernel/trace/trace_stat.c gives some infrastructure for that.

BTW, I have the project to build a function hashlist, based on the function list
provided by dynamic ftrace, to store the average of time spent for each traced
function, using the function graph tracer.

--
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/