lkml.org 
[lkml]   [2009]   [Feb]   [26]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    Patch in this message
    /
    Date
    From
    SubjectRe: [PATCH] new irq tracer
    On Wed, Feb 25, 2009 at 12:34:12PM -0500, Mathieu Desnoyers wrote:
    > * Jason Baron (jbaron@redhat.com) wrote:
    > > On Wed, Feb 25, 2009 at 11:48:28AM -0500, Masami Hiramatsu wrote:
    > > > KOSAKI Motohiro wrote:
    > > > >> /**
    > > > >> * handle_IRQ_event - irq action chain handler
    > > > >> * @irq: the interrupt number
    > > > >> @@ -354,7 +358,9 @@ irqreturn_t handle_IRQ_event(unsigned int irq, struct irqaction *action)
    > > > >> local_irq_enable_in_hardirq();
    > > > >>
    > > > >> do {
    > > > >> + trace_irq_entry(irq);
    > > > >> ret = action->handler(irq, action->dev_id);
    > > > >> + trace_irq_exit(irq, ret);
    > > > >> if (ret == IRQ_HANDLED)
    > > > >> status |= action->flags;
    > > > >> retval |= ret;
    > > > >
    > > > > Nobdy want unnecessary redundant tracepoint.
    > > > > Please discuss with mathieu, and merge his tracepoint.
    > > >
    > > > Hmm, from the viewpoint of trouble shooting, the place of LTTng's tracepoint
    > > > is enough. However, from the same viewpoint, it should pass irq-number
    > > > to irq-exit event too, because we may lost some previous events by buffer-overflow
    > > > etc.
    > > >
    > > > trace_irq_entry(irq, NULL);
    > > > ret = _handle_IRQ_event(irq, action);
    > > > trace_irq_exit(irq, ret);
    > > > ^^^^
    > > >
    > >
    > > the lttng tracepoints wrap the calls to _handle_IRQ_event in 3
    > > different places. So the above suggested irq tracepoint provides the
    > > same information with 4 less tracepoints in the code. So I believe its
    > > simpler - plus we can understand which action handlers are handling the
    > > interrupt.
    > >
    >
    > The main thing I dislike about only tracing action->handler() calls is
    > that you are not tracing an IRQ per se, but rather the invocation of a
    > given handler within the interrupt. For instance, it would be difficult
    > to calculate the maximum interrupt latency for a given interrupt line,
    > because you don't have the "real" irq entry/exit events, just the
    > individual handler() calls.
    >
    > But I agree that knowing which handler is called is important.
    >
    > How about this compromise :
    >
    > trace_irq_entry(irq, action)
    > _handle_IRQ_event()
    > for each action {
    > trace_irq_handler(action, ret);
    > ret = action->handler(irq, action->dev_id);
    > ...
    > }
    > trace_irq_exit(action_ret);
    >
    > Would that give you the information you need ?
    >
    > Here trace_irq_handler would be passed the _current_ action invoked and
    > the _previous_ action return value. Note that we should initialize
    > irqreturn_t ret to some initial value if we do this. That should keep
    > the tracing overhead minimal.
    >

    maybe...although that would require re-arranging the 'while' loop in
    'handle_IRQ_event' from a do..while loop to a 'while' loop, which will
    require an extra branch check, and then we still have to record the last 'ret'
    value. I'm not that keen on re-arranging this for trace data...

    Using Steve's new 'DEFINE_TRACE_FMT', I can get function graph trace
    as follows using the original two tracepoints (patch below):

    3) | handle_IRQ_event() {
    3) | /* (irq_handler_entry) irq=28 handler=eth0 */
    3) | e1000_intr_msi() {
    3) 2.460 us | __napi_schedule();
    3) 9.416 us | }
    3) | /* (irq_handler_exit) irq=28 handler=eth0 return=handled */
    3) + 22.935 us | }

    thanks,

    -Jason


    Signed-off-by: Jason Baron <jbaron@redhat.com>
    ---

    include/trace/irq.h | 9 +++++++++
    include/trace/irq_event_types.h | 17 +++++++++++++++++
    kernel/irq/handle.c | 6 ++++++
    kernel/trace/events.c | 2 ++
    4 files changed, 34 insertions(+), 0 deletions(-)
    create mode 100644 include/trace/irq.h
    create mode 100644 include/trace/irq_event_types.h


    diff --git a/include/trace/irq.h b/include/trace/irq.h
    new file mode 100644
    index 0000000..ff5d449
    --- /dev/null
    +++ b/include/trace/irq.h
    @@ -0,0 +1,9 @@
    +#ifndef _TRACE_IRQ_H
    +#define _TRACE_IRQ_H
    +
    +#include <linux/interrupt.h>
    +#include <linux/tracepoint.h>
    +
    +#include <trace/irq_event_types.h>
    +
    +#endif
    diff --git a/include/trace/irq_event_types.h b/include/trace/irq_event_types.h
    new file mode 100644
    index 0000000..5889bfd
    --- /dev/null
    +++ b/include/trace/irq_event_types.h
    @@ -0,0 +1,17 @@
    +
    +/* use <trace/irq.h> instead */
    +#ifndef DEFINE_TRACE_FMT
    +# error Do not include this file directly.
    +# error Unless you know what you are doing.
    +#endif
    +
    +DEFINE_TRACE_FMT(irq_handler_entry,
    + TPPROTO(int irq, struct irqaction *action),
    + TPARGS(irq, action),
    + TPFMT("irq=%d handler=%s", irq, action->name));
    +
    +DEFINE_TRACE_FMT(irq_handler_exit,
    + TPPROTO(int irq, struct irqaction *action, int ret),
    + TPARGS(irq, action, ret),
    + TPFMT("irq=%d handler=%s return=%s",
    + irq, action->name, ret ? "handled" : "unhandled"));
    diff --git a/kernel/irq/handle.c b/kernel/irq/handle.c
    index fdff380..bcebc2e 100644
    --- a/kernel/irq/handle.c
    +++ b/kernel/irq/handle.c
    @@ -18,6 +18,7 @@
    #include <linux/rculist.h>
    #include <linux/hash.h>
    #include <linux/bootmem.h>
    +#include <trace/irq.h>

    #include "internals.h"

    @@ -338,6 +339,9 @@ irqreturn_t no_action(int cpl, void *dev_id)
    return IRQ_NONE;
    }

    +DEFINE_TRACE(irq_handler_entry);
    +DEFINE_TRACE(irq_handler_exit);
    +
    /**
    * handle_IRQ_event - irq action chain handler
    * @irq: the interrupt number
    @@ -354,7 +358,9 @@ irqreturn_t handle_IRQ_event(unsigned int irq, struct irqaction *action)
    local_irq_enable_in_hardirq();

    do {
    + trace_irq_handler_entry(irq, action);
    ret = action->handler(irq, action->dev_id);
    + trace_irq_handler_exit(irq, action, ret);
    if (ret == IRQ_HANDLED)
    status |= action->flags;
    retval |= ret;
    diff --git a/kernel/trace/events.c b/kernel/trace/events.c
    index 38c89ee..3c75623 100644
    --- a/kernel/trace/events.c
    +++ b/kernel/trace/events.c
    @@ -6,8 +6,10 @@

    /* trace/<type>.h here */
    #include <trace/sched.h>
    +#include <trace/irq.h>

    #include "trace_events.h"

    /* trace/<type>_event_types.h here */
    #include <trace/sched_event_types.h>
    +#include <trace/irq_event_types.h>







    \
     
     \ /
      Last update: 2009-02-26 16:15    [W:2.197 / U:0.200 seconds]
    ©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site