Re: [PATCH 3/6] trace: Add tracepoints to IRQ work run handler

[Frederic Weisbecker <fweisbec@gmail.com>]

On Thu, Jul 14, 2011 at 02:38:12PM -0700, Vaibhav Nagarnaik wrote:
> This is a part of overall effort to trace all the interrupts happening
> in a system to figure out what time is spent in kernel space versus user
> space.
> 
> Signed-off-by: Vaibhav Nagarnaik <vnagarnaik@google.com>
> ---
>  include/trace/events/irq.h |   44 ++++++++++++++++++++++++++++++++++++++++++++
>  kernel/irq_work.c          |    4 ++++
>  2 files changed, 48 insertions(+), 0 deletions(-)
> 
> diff --git a/include/trace/events/irq.h b/include/trace/events/irq.h
> index e6e72e0..d8fab89 100644
> --- a/include/trace/events/irq.h
> +++ b/include/trace/events/irq.h
> @@ -295,6 +295,50 @@ DEFINE_EVENT(timer_interrupt, timer_nohz_exit,
>  	TP_ARGS(ignore)
>  );
>  
> +DECLARE_EVENT_CLASS(irq_work,
> +
> +	TP_PROTO(unsigned int ignore),
> +
> +	TP_ARGS(ignore),
> +
> +	TP_STRUCT__entry(
> +		__field(	unsigned int,	ignore	)
> +	),
> +
> +	TP_fast_assign(
> +		__entry->ignore = ignore;
> +	),
> +
> +	TP_printk("%u", __entry->ignore)
> +);
> +
> +/**
> + * irq_work_run_entry - called immediately after entering the irq work
> + * handler
> + *
> + * When used in combination with the irq_work_run_exit tracepoint
> + * we can determine the irq work handler runtime.
> + */
> +DEFINE_EVENT(irq_work, irq_work_run_entry,
> +
> +	TP_PROTO(unsigned int ignore),
> +
> +	TP_ARGS(ignore)
> +);
> +
> +/**
> + * irq_work_run_exit - called just before the irq work handler returns
> + *
> + * When used in combination with the irq_work_run_entry tracepoint
> + * we can determine the irq work handler runtime.
> + */
> +DEFINE_EVENT(irq_work, irq_work_run_exit,
> +
> +	TP_PROTO(unsigned int ignore),
> +
> +	TP_ARGS(ignore)
> +);
> +
>  #endif /*  _TRACE_IRQ_H */
>  
>  /* This part must be outside protection */
> diff --git a/kernel/irq_work.c b/kernel/irq_work.c
> index c58fa7d..7e78122 100644
> --- a/kernel/irq_work.c
> +++ b/kernel/irq_work.c
> @@ -9,6 +9,7 @@
>  #include <linux/module.h>
>  #include <linux/irq_work.h>
>  #include <linux/hardirq.h>
> +#include <trace/events/irq.h>
>  
>  /*
>   * An entry can be in one of four states:
> @@ -125,6 +126,8 @@ void irq_work_run(void)
>  	if (this_cpu_read(irq_work_list) == NULL)
>  		return;

If you don't want to miss any of these interrupts, I suggest you
call trace_irq_work_run_entry(0) before the above check.

Also I'm adding Peter who maintains this.

>  
> +	trace_irq_work_run_entry(0);
> +
>  	BUG_ON(!in_irq());
>  	BUG_ON(!irqs_disabled());
>  
> @@ -149,6 +152,7 @@ void irq_work_run(void)
>  			      next_flags(NULL, IRQ_WORK_BUSY),
>  			      NULL);
>  	}
> +	trace_irq_work_run_exit(0);
>  }
>  EXPORT_SYMBOL_GPL(irq_work_run);
>  
> -- 
> 1.7.3.1
>