lttng-instrumentation/lttng-instrumentation-irq

LTTng instrumentation - irq

Instrumentation of IRQ related events : irq_entry, irq_exit and
irq_next_handler.

It allows tracers to perform latency analysis on those various types of
interrupts and to detect interrupts with max/min/avg duration. It helps
detecting driver or hardware problems which cause an ISR to take ages to
execute. It has been shown to be the case with bogus hardware causing an mmio
read to take a few milliseconds.

Those tracepoints are used by LTTng.

About the performance impact of tracepoints (which is comparable to markers),
even without immediate values optimizations, tests done by Hideo Aoki on ia64
show no regression. His test case was using hackbench on a kernel where
scheduler instrumentation (about 5 events in code scheduler code) was added.
See the "Tracepoints" patch header for performance result detail.

irq_entry and irq_exit not declared static because they appear in x86 arch code.

The idea behind logging irq/softirq/tasklet/(and eventually syscall) entry and
exit events is to be able to recreate the kernel execution state at a given
point in time. Knowing which execution context is responsible for a given trace
event is _very_ valuable in trace data analysis.

The IRQ instrumentation instruments the IRQ handler entry and exit. Jason
instrumented the irq notifier chain calls (irq_handler_entry/exit). His approach
provides information about which handler is being called, but does not map
correctly to the fact that _multiple_ handlers are being called from within the
same interrupt handler. From an interrupt latency analysis POV, this is
incorrect.

I propose we save the "action" in the irq_entry, and use the irq exit "retval"
to know the return value of the last interrupt handler. So in common cases where
only one interrupt handler is connected to an interrupt line, we only have 2
events. Then we also add a irq_next_handler, which saves the previous interrupt
handler return value and the next handler action when there are more than 1
handler called. That would generate the minimum amount of traffic to save all
the information both Jason and I need.

Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@polymtl.ca>
CC: 'Ingo Molnar' <mingo@elte.hu>
CC: Frederic Weisbecker <fweisbec@gmail.com>
CC: Jason Baron <jbaron@redhat.com>
CC: 'Peter Zijlstra' <peterz@infradead.org>
CC: Thomas Gleixner <tglx@linutronix.de>
CC: Russell King <rmk+lkml@arm.linux.org.uk>
CC: Masami Hiramatsu <mhiramat@redhat.com>
CC: "Frank Ch. Eigler" <fche@redhat.com>
CC: 'Hideo AOKI' <haoki@redhat.com>
CC: Takashi Nishiie <t-nishiie@np.css.fujitsu.com>
CC: 'Steven Rostedt' <rostedt@goodmis.org>
CC: Eduard - Gabriel Munteanu <eduard.munteanu@linux360.ro>

1 files changed, 7 insertions, 0 deletions

diff --git a/kernel/irq/handle.c b/kernel/irq/handle.c
index 3540a719012..39acea9b366 100644
--- a/kernel/irq/handle.c
+++ b/kernel/irq/handle.c
@@ -51,6 +51,9 @@ static void warn_no_thread(unsigned int irq, struct irqaction *action)
 	       "but no thread function available.", irq, action->name);
 }
 
+DEFINE_TRACE(irq_entry);
+DEFINE_TRACE(irq_exit);
+
 /**
  * handle_IRQ_event - irq action chain handler
  * @irq:	the interrupt number
@@ -63,6 +66,8 @@ irqreturn_t handle_IRQ_event(unsigned int irq, struct irqaction *action)
 	irqreturn_t ret, retval = IRQ_NONE;
 	unsigned int status = 0;
 
+	trace_irq_entry(irq, NULL, action);
+
 	do {
 		trace_irq_handler_entry(irq, action);
 		ret = action->handler(irq, action->dev_id);
@@ -116,5 +121,7 @@ irqreturn_t handle_IRQ_event(unsigned int irq, struct irqaction *action)
 		add_interrupt_randomness(irq);
 	local_irq_disable();
 
+	trace_irq_exit(retval);
+
 	return retval;
 }