Re: [PATCH v3 3/4] ftrace: add tracepoint for hrtimer

[Xiao Guangrong <xiaoguangrong@cn.fujitsu.com>]

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.

Thanks, 
Xiao

> So I really don't see the use-case for this _expiry tracepoint, its just
> too ill-defined.
> 
> The _entry and _exit ones I can agree with, this stuff just doesn't make
> any sense.
> 
>