lkml.org 
[lkml]   [2011]   [Jul]   [14]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    Patch in this message
    /
    From
    Subject[PATCH 2/6] trace: Add tracepoints to timer interrupt handlers
    Date
    Add tracepoints to generic kernel timer interrupt handlers to trace the
    hardware timer interrupts.

    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 | 156 ++++++++++++++++++++++++++++++++++++++++++
    kernel/hrtimer.c | 6 ++
    kernel/time/tick-broadcast.c | 16 ++++-
    kernel/time/tick-common.c | 8 ++-
    kernel/time/tick-sched.c | 4 +
    5 files changed, 187 insertions(+), 3 deletions(-)

    diff --git a/include/trace/events/irq.h b/include/trace/events/irq.h
    index 4b4c7d9..e6e72e0 100644
    --- a/include/trace/events/irq.h
    +++ b/include/trace/events/irq.h
    @@ -139,6 +139,162 @@ DEFINE_EVENT(softirq, softirq_raise,
    TP_ARGS(vec_nr)
    );

    +DECLARE_EVENT_CLASS(timer_interrupt,
    +
    + 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)
    +);
    +
    +/**
    + * hrtimer_interrupt_entry - called immediately after entering the hrtimer
    + * handler
    + *
    + * When used in combination with the hrtimer_interrupt_exit tracepoint
    + * we can determine the hrtimer handler runtime.
    + */
    +DEFINE_EVENT(timer_interrupt, hrtimer_interrupt_entry,
    +
    + TP_PROTO(unsigned int ignore),
    +
    + TP_ARGS(ignore)
    +);
    +
    +/**
    + * hrtimer_interrupt_exit - called just before the hrtimer handler returns
    + *
    + * When used in combination with the hrtimer_interrupt_entry tracepoint
    + * we can determine the hrtimer handler runtime.
    + */
    +DEFINE_EVENT(timer_interrupt, hrtimer_interrupt_exit,
    +
    + TP_PROTO(unsigned int ignore),
    +
    + TP_ARGS(ignore)
    +);
    +
    +/**
    + * timer_broadcast_entry - called immediately after entering the broadcast
    + * timer handler
    + *
    + * When used in combination with the timer_broadcast_exit tracepoint
    + * we can determine the broadcast timer handler runtime.
    + */
    +DEFINE_EVENT(timer_interrupt, timer_broadcast_entry,
    +
    + TP_PROTO(unsigned int ignore),
    +
    + TP_ARGS(ignore)
    +);
    +
    +/**
    + * timer_broadcast_exit - called just before the broadcast timer handler
    + * returns
    + *
    + * When used in combination with the timer_broadcast_entry tracepoint
    + * we can determine the broadcast timer handler runtime.
    + */
    +DEFINE_EVENT(timer_interrupt, timer_broadcast_exit,
    +
    + TP_PROTO(unsigned int ignore),
    +
    + TP_ARGS(ignore)
    +);
    +
    +/**
    + * timer_oneshot_entry - called immediately after entering the oneshot
    + * timer handler
    + *
    + * When used in combination with the timer_oneshot_exit tracepoint
    + * we can determine the oneshot timer handler runtime.
    + */
    +DEFINE_EVENT(timer_interrupt, timer_oneshot_entry,
    +
    + TP_PROTO(unsigned int ignore),
    +
    + TP_ARGS(ignore)
    +);
    +
    +/**
    + * timer_oneshot_exit - called just before the oneshot timer handler
    + * returns
    + *
    + * When used in combination with the timer_oneshot_entry tracepoint
    + * we can determine the oneshot timer handler runtime.
    + */
    +DEFINE_EVENT(timer_interrupt, timer_oneshot_exit,
    +
    + TP_PROTO(unsigned int ignore),
    +
    + TP_ARGS(ignore)
    +);
    +
    +/**
    + * timer_periodic_entry - called immediately after entering the periodic
    + * timer handler
    + *
    + * When used in combination with the timer_periodic_exit tracepoint
    + * we can determine the periodic timer handler runtime.
    + */
    +DEFINE_EVENT(timer_interrupt, timer_periodic_entry,
    +
    + TP_PROTO(unsigned int ignore),
    +
    + TP_ARGS(ignore)
    +);
    +
    +/**
    + * timer_periodic_exit - called just before the periodic timer handler
    + * returns
    + *
    + * When used in combination with the timer_periodic_entry tracepoint
    + * we can determine the periodic timer handler runtime.
    + */
    +DEFINE_EVENT(timer_interrupt, timer_periodic_exit,
    +
    + TP_PROTO(unsigned int ignore),
    +
    + TP_ARGS(ignore)
    +);
    +
    +/**
    + * timer_nohz_entry - called immediately after entering the nohz
    + * timer handler
    + *
    + * When used in combination with the timer_nohz_exit tracepoint
    + * we can determine the nohz timer handler runtime.
    + */
    +DEFINE_EVENT(timer_interrupt, timer_nohz_entry,
    +
    + TP_PROTO(unsigned int ignore),
    +
    + TP_ARGS(ignore)
    +);
    +
    +/**
    + * timer_nohz_exit - called just before the nohz timer handler
    + * returns
    + *
    + * When used in combination with the timer_nohz_entry tracepoint
    + * we can determine the nohz timer handler runtime.
    + */
    +DEFINE_EVENT(timer_interrupt, timer_nohz_exit,
    +
    + TP_PROTO(unsigned int ignore),
    +
    + TP_ARGS(ignore)
    +);
    +
    #endif /* _TRACE_IRQ_H */

    /* This part must be outside protection */
    diff --git a/kernel/hrtimer.c b/kernel/hrtimer.c
    index a9205e3..3bf83d5 100644
    --- a/kernel/hrtimer.c
    +++ b/kernel/hrtimer.c
    @@ -48,6 +48,7 @@

    #include <asm/uaccess.h>

    +#include <trace/events/irq.h>
    #include <trace/events/timer.h>

    /*
    @@ -1244,6 +1245,8 @@ void hrtimer_interrupt(struct clock_event_device *dev)
    ktime_t expires_next, now, entry_time, delta;
    int i, retries = 0;

    + trace_hrtimer_interrupt_entry(0);
    +
    BUG_ON(!cpu_base->hres_active);
    cpu_base->nr_events++;
    dev->next_event.tv64 = KTIME_MAX;
    @@ -1316,6 +1319,7 @@ retry:
    if (expires_next.tv64 == KTIME_MAX ||
    !tick_program_event(expires_next, 0)) {
    cpu_base->hang_detected = 0;
    + trace_hrtimer_interrupt_exit(0);
    return;
    }

    @@ -1355,6 +1359,8 @@ retry:
    tick_program_event(expires_next, 1);
    printk_once(KERN_WARNING "hrtimer: interrupt took %llu ns\n",
    ktime_to_ns(delta));
    +
    + trace_hrtimer_interrupt_exit(0);
    }

    /*
    diff --git a/kernel/time/tick-broadcast.c b/kernel/time/tick-broadcast.c
    index c7218d1..fc3b9d6 100644
    --- a/kernel/time/tick-broadcast.c
    +++ b/kernel/time/tick-broadcast.c
    @@ -20,6 +20,7 @@
    #include <linux/sched.h>

    #include "tick-internal.h"
    +#include <trace/events/irq.h>

    /*
    * Broadcast support for broken x86 hardware, where the local apic
    @@ -176,13 +177,17 @@ static void tick_handle_periodic_broadcast(struct clock_event_device *dev)
    {
    ktime_t next;

    + trace_timer_broadcast_entry(0);
    +
    tick_do_periodic_broadcast();

    /*
    * The device is in periodic mode. No reprogramming necessary:
    */
    - if (dev->mode == CLOCK_EVT_MODE_PERIODIC)
    + if (dev->mode == CLOCK_EVT_MODE_PERIODIC) {
    + trace_timer_broadcast_exit(0);
    return;
    + }

    /*
    * Setup the next period for devices, which do not have
    @@ -194,10 +199,13 @@ static void tick_handle_periodic_broadcast(struct clock_event_device *dev)
    for (next = dev->next_event; ;) {
    next = ktime_add(next, tick_period);

    - if (!clockevents_program_event(dev, next, ktime_get()))
    + if (!clockevents_program_event(dev, next, ktime_get())) {
    + trace_timer_broadcast_exit(0);
    return;
    + }
    tick_do_periodic_broadcast();
    }
    + trace_timer_broadcast_exit(0);
    }

    /*
    @@ -404,6 +412,8 @@ static void tick_handle_oneshot_broadcast(struct clock_event_device *dev)
    ktime_t now, next_event;
    int cpu;

    + trace_timer_oneshot_entry(0);
    +
    raw_spin_lock(&tick_broadcast_lock);
    again:
    dev->next_event.tv64 = KTIME_MAX;
    @@ -443,6 +453,8 @@ again:
    goto again;
    }
    raw_spin_unlock(&tick_broadcast_lock);
    +
    + trace_timer_oneshot_exit(0);
    }

    /*
    diff --git a/kernel/time/tick-common.c b/kernel/time/tick-common.c
    index 119528d..a7f81af 100644
    --- a/kernel/time/tick-common.c
    +++ b/kernel/time/tick-common.c
    @@ -18,6 +18,7 @@
    #include <linux/percpu.h>
    #include <linux/profile.h>
    #include <linux/sched.h>
    +#include <trace/events/irq.h>

    #include <asm/irq_regs.h>

    @@ -84,6 +85,8 @@ void tick_handle_periodic(struct clock_event_device *dev)
    int cpu = smp_processor_id();
    ktime_t next;

    + trace_timer_periodic_entry(0);
    +
    tick_periodic(cpu);

    if (dev->mode != CLOCK_EVT_MODE_ONESHOT)
    @@ -94,8 +97,10 @@ void tick_handle_periodic(struct clock_event_device *dev)
    */
    next = ktime_add(dev->next_event, tick_period);
    for (;;) {
    - if (!clockevents_program_event(dev, next, ktime_get()))
    + if (!clockevents_program_event(dev, next, ktime_get())) {
    + trace_timer_periodic_exit(0);
    return;
    + }
    /*
    * Have to be careful here. If we're in oneshot mode,
    * before we call tick_periodic() in a loop, we need
    @@ -109,6 +114,7 @@ void tick_handle_periodic(struct clock_event_device *dev)
    tick_periodic(cpu);
    next = ktime_add(next, tick_period);
    }
    + trace_timer_periodic_exit(0);
    }

    /*
    diff --git a/kernel/time/tick-sched.c b/kernel/time/tick-sched.c
    index d5097c4..54e7b07 100644
    --- a/kernel/time/tick-sched.c
    +++ b/kernel/time/tick-sched.c
    @@ -20,6 +20,7 @@
    #include <linux/profile.h>
    #include <linux/sched.h>
    #include <linux/module.h>
    +#include <trace/events/irq.h>

    #include <asm/irq_regs.h>

    @@ -568,6 +569,8 @@ static void tick_nohz_handler(struct clock_event_device *dev)
    int cpu = smp_processor_id();
    ktime_t now = ktime_get();

    + trace_timer_nohz_entry(0);
    +
    dev->next_event.tv64 = KTIME_MAX;

    /*
    @@ -604,6 +607,7 @@ static void tick_nohz_handler(struct clock_event_device *dev)
    now = ktime_get();
    tick_do_update_jiffies64(now);
    }
    + trace_timer_nohz_exit(0);
    }

    /**
    --
    1.7.3.1


    \
     
     \ /
      Last update: 2011-07-14 23:41    [W:0.042 / U:31.636 seconds]
    ©2003-2016 Jasper Spaans. hosted at Digital OceanAdvertise on this site