Messages in this thread | | | Subject | Re: [PATCH v3 3/4] ftrace: add tracepoint for hrtimer | From | Peter Zijlstra <> | Date | Fri, 17 Jul 2009 12:50:01 +0200 |
| |
On Fri, 2009-07-17 at 18:18 +0800, Xiao Guangrong wrote: > Those tracepoints are wanted and useful: > 1: We can detect a hrtimer's delay > 2: We can monitor the lifecycle and behaviors of a hrtimer > > Thus they help in analysing and debuging. > > Great thanks to Thomas for giving me so many valuable advices. > > Example ftrace output: > insmod-5280 [000] 10798.356372: hrtimer_init: timer=d0b044c0 clockid=CLOCK_REALTIME mode=HRTIMER_MODE_ABS > insmod-5280 [000] 10798.356385: hrtimer_start: timer=d0b044c0 func=hrtimer_fun expires=1246242896000000000 ns softexpires=1246242896000000000 ns > <idle>-0 [000] 10807.982987: hrtimer_expire: timer=d0b044c0 now=1246242896000906503 ns > <idle>-0 [000] 10807.982989: hrtimer_cancel: timer=d0b044c0 > <idle>-0 [000] 10807.983562: hrtimer_callback_done: timer=d0b044c0 > > We expect the hrtimer expires at 1246242896000000000 ns, actually the > hrtimer expires at 1246242896000906503 ns, so it is delayed by > 1246242896000906503-1246242896000000000 = 906503 ns. > We also realize the hrtimer's callback started at 10807.982987, and it > finished at 10807.983562, so it's taking 10807.983562-10807.982987=0.6ms. > > Changelog: > v1->v2: > 1: Remove ktime_to_ns() in TP_fast_assign() > 2: Combine debugobjects and trace as Thomas's suggestion > v2->v3: > 1: Remove function address from hrtimer_expire and hrtimer_cancel > as Thomas's suggestion > 2: Remove debug_and_trace_hrtimer_expire() as Thomas's suggestion > 3: Rename trace_hrtimer_entry() and trace_hrtimer_exit() to match this patch > > Signed-off-by: Xiao Guangrong <xiaoguangrong@cn.fujitsu.com> > ---
> diff --git a/kernel/hrtimer.c b/kernel/hrtimer.c > index 33317e4..bd21c9b 100644 > --- a/kernel/hrtimer.c > +++ b/kernel/hrtimer.c > @@ -442,6 +442,26 @@ static inline void debug_hrtimer_activate(struct hrtimer *timer) { } > static inline void debug_hrtimer_deactivate(struct hrtimer *timer) { } > #endif > > +static inline void > +debug_and_trace_hrtimer_init(struct hrtimer *timer, clockid_t clockid, > + enum hrtimer_mode mode) > +{ > + debug_hrtimer_init(timer); > + trace_hrtimer_init(timer, clockid, mode); > +} > + > +static inline void debug_and_trace_hrtimer_activate(struct hrtimer *timer) > +{ > + debug_hrtimer_activate(timer); > + trace_hrtimer_start(timer); > +} > + > +static inline void debug_and_trace_hrtimer_deactivate(struct hrtimer *timer) > +{ > + debug_hrtimer_deactivate(timer); > + trace_hrtimer_cancel(timer); > +}
I would argue that tracing is a form of debugging and you shouldn't need to mangle these names like that, simply leave them debug_*().
> @@ -1162,9 +1182,8 @@ static void __run_hrtimer(struct hrtimer *timer) > * the timer base. > */ > spin_unlock(&cpu_base->lock); > - trace_hrtimer_entry(timer); > restart = fn(timer); > - trace_hrtimer_exit(timer, restart); > + trace_hrtimer_callback_done(timer); > spin_lock(&cpu_base->lock); > > /*
Why bother introducing these tracepoints if you're going to remove them in the same patch-set?
Also, the below:
> @@ -1275,6 +1294,7 @@ void hrtimer_interrupt(struct clock_event_device *dev) > break; > } > > + trace_hrtimer_expire(timer, basenow.tv64); > __run_hrtimer(timer); > } > base++; > @@ -1397,6 +1417,7 @@ void hrtimer_run_queues(void) > hrtimer_get_expires_tv64(timer)) > break; > > + trace_hrtimer_expire(timer, base->softirq_time.tv64); > __run_hrtimer(timer); > } > spin_unlock(&cpu_base->lock);
indicates you placed that tracepoint in the wrong place.
Furthermore, I don't get why you want it there and not on the old _entry() site, because this adds all kinds of extra overhead and you loose the exact callback timings.
| |