Messages in this thread | | | Subject | Re: [PATCH v3 3/4] ftrace: add tracepoint for hrtimer | From | Peter Zijlstra <> | Date | Wed, 22 Jul 2009 12:13:18 +0200 |
| |
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?
| |