lkml.org 
[lkml]   [2009]   [Jul]   [22]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
SubjectRe: [PATCH v3 3/4] ftrace: add tracepoint for hrtimer
From
Date
On Wed, 2009-07-22 at 17:36 +0800, Xiao Guangrong wrote:
>
> Peter Zijlstra wrote:
>
> > Ah, but you don't get those anyway, I'd argue the whole expire thing is
> > broken. The only expiry you get is the hardware interrupt firing.
> > Anything after that is a free-for-all.
> >
> > Look at that loop in hrtimer_interrupt(), with your tracepoint, they'd
> > all expire at the same time, regardless of how long previous callback's
> > took to complete.
> >
> > Also, the whole loop can be re-tried, updating 'now' expiring a whole
> > new set of timers without expiry event.
> >
>
> Yes, the expire time that got by _expire() is incorrect and thanks for
> your point out.
>
> > The best you can get is a tracepoint when the hrtimer interrupt happens,
> > and the IRQ tracepoint already give you that.
> >
>
> I'm trying to fix it address your comment, but meet some problems,
> the time of ftrace output can't solve everything, because:
>
> 1: the time unit of ftrace output is microsecond, but hrtimer's unit
> is nanosecond, it's not exact for us
>
> 2: the time of ftrace ouput is the time after system boot, but we need
> xtime and wall_to_monotonic to calculate latency of hrtimer,
> for example:
> insmod-3821 [001] 3192.239335: hrtimer_start: timer=d08a1480 expires=1245162841000000000 ns
> <idle>-0 [001] 3201.506127: hrtimer_expire: timer=d08a1480
>
> we expect the timer expire at 1245162841000000000 ns, this is base on
> xtime, but we don't know the interval running that we are expect hrtimer
> to run if we don't know the xtime at hrtimer_start or hrtimer_expire.
>
> But it's hard for hrtime's TRACE_EVENT to get xtime and wall_to_monotonic
> since it's a fast patch, if we have to do this, the code maybe like below:
>
> TRACE_EVENT(hrtimer_expire,
>
> ......
>
> TP_STRUCT__entry(
> __field( void *, timer )
> __field( s64, now )
> __field( s64, offset )
> ),
>
> TP_fast_assign(
> __entry->timer = timer;
> __entry->now = ktime_get().tv64;
> __entry->wtom = timespec_to_ktime(wall_to_monotonic).tv64;
> ),
>
> TP_printk("timer=%p now=%llu ns wtom=%llu", __entry->timer,
> (unsigned long long)__entry->now, (unsigned long long)__entry->wtom)
> );
>
> We need cooperate with trace_hrtimer_init() to get hrtimer's clockid.
>
> That make trace_hrtimer_expire() slow.
>
> Though the original patch get expire time not exactly, but It harm system's
> performance very little.

OK, so what you want to measure is the time of the actual callback
happening (hrtimer_entry) vs that where you would have expected it to
happen (hrtimer_start + delay), right?

So what's wrong with printing the expected expiration time in the
hrtimer_start tracepoint in the cheap clock units?




\
 
 \ /
  Last update: 2009-07-22 12:21    [W:0.089 / U:0.272 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site