Re: [patch 6/9] LTTng instrumentation - timer

[Ingo Molnar <mingo@elte.hu>]

* Mathieu Desnoyers <mathieu.desnoyers@polymtl.ca> wrote:

> Instrument timer activity (timer set, expired, current time 
> updates) to keep information about the "real time" flow within the 
> kernel. It can be used by a trace analysis tool to synchronize 
> information coming from various sources, e.g. to merge traces with 
> system logs.
> 
> Those tracepoints are used by LTTng.
> 
> About the performance impact of tracepoints (which is comparable 
> to markers), even without immediate values optimizations, tests 
> done by Hideo Aoki on ia64 show no regression. His test case was 
> using hackbench on a kernel where scheduler instrumentation (about 
> 5 events in code scheduler code) was added. See the "Tracepoints" 
> patch header for performance result detail.
> 
> Note : do_setitimer instrumentation could potentially be done with 
> a more generic system call instrumentation.
>
> CC: 'Steven Rostedt' <rostedt@goodmis.org>
> CC: Eduard - Gabriel Munteanu <eduard.munteanu@linux360.ro>
> ---
>  include/trace/timer.h |   24 ++++++++++++++++++++++++
>  kernel/itimer.c       |    8 ++++++++
>  kernel/timer.c        |   12 +++++++++++-
>  3 files changed, 43 insertions(+), 1 deletion(-)

For complete timer instrumentation, hrtimers should be instrumented 
as well.

>  	return HRTIMER_NORESTART;
> @@ -148,6 +154,8 @@ int do_setitimer(int which, struct itime
>  	    !timeval_valid(&value->it_interval))
>  		return -EINVAL;
>  
> +	trace_timer_itimer_set(which, value);

for consistency, i'd name the timer start tracepoints the following 
way:

  trace_timer_init()
  trace_itimer_init()
  trace_hrtimer_init()

  trace_timer_start()
  trace_itimer_start()
  trace_hrtimer_start()

  trace_timer_expire()
  trace_itimer_expire()
  trace_hrtimer_expire()

  trace_timer_cancel()
  trace_itimer_cancel()
  trace_hrtimer_cancel()

the init methods are missing from your patch entirely - and the rest 
is partially incomplete as well.

Instrumentation of the del_timer() variants is missing. For a 
complete lifetime analysis of timers this cannot be left out.

> +DEFINE_TRACE(timer_set);
> +DEFINE_TRACE(timer_timeout);

these two should be 'timer_start' and 'timer_expire'.

> +DEFINE_TRACE(timer_update_time);

This is a misnomer. This is in timer.c but is not a 'timer' 
tracepoint - this is a time of day tracepoint - and this should be 
reflected in its naming - so it should be: trace_gtod_update_xtime() 
or so.

> @@ -357,6 +363,7 @@ static void internal_add_timer(struct tv
>  		i = (expires >> (TVR_BITS + 3 * TVN_BITS)) & TVN_MASK;
>  		vec = base->tv5.vec + i;
>  	}
> +	trace_timer_set(timer);
>  	/*
>  	 * Timers are FIFO:
>  	 */

this should be trace_timer_start().

> @@ -1121,6 +1128,7 @@ void do_timer(unsigned long ticks)
>  {
>  	jiffies_64 += ticks;
>  	update_times(ticks);
> +	trace_timer_update_time(&xtime, &wall_to_monotonic);
>  }

gtod_update_xtime().

The GTOD instrumentation should move into a separate patch, and 
should probably be extended with NTP correction events as well.

>  #ifdef __ARCH_WANT_SYS_ALARM
> @@ -1202,7 +1210,9 @@ SYSCALL_DEFINE0(getegid)
>  
>  static void process_timeout(unsigned long __data)
>  {
> -	wake_up_process((struct task_struct *)__data);
> +	struct task_struct *task = (struct task_struct *)__data;
> +	trace_timer_timeout(task);
> +	wake_up_process(task);

[ nit: misssing new line after local variable declaration. ]

this should be trace_timer_expire().

> Index: linux-2.6-lttng/include/trace/timer.h
> ===================================================================
> --- /dev/null	1970-01-01 00:00:00.000000000 +0000
> +++ linux-2.6-lttng/include/trace/timer.h	2009-03-24 09:31:51.000000000 -0400
> @@ -0,0 +1,24 @@
> +#ifndef _TRACE_TIMER_H
> +#define _TRACE_TIMER_H
> +
> +#include <linux/tracepoint.h>
> +
> +DECLARE_TRACE(timer_itimer_expired,
> +	TPPROTO(struct signal_struct *sig),
> +		TPARGS(sig));
> +DECLARE_TRACE(timer_itimer_set,
> +	TPPROTO(int which, struct itimerval *value),
> +		TPARGS(which, value));
> +DECLARE_TRACE(timer_set,
> +	TPPROTO(struct timer_list *timer),
> +		TPARGS(timer));
> +/*
> + * xtime_lock is taken when kernel_timer_update_time tracepoint is reached.
> + */
> +DECLARE_TRACE(timer_update_time,
> +	TPPROTO(struct timespec *_xtime, struct timespec *_wall_to_monotonic),
> +		TPARGS(_xtime, _wall_to_monotonic));
> +DECLARE_TRACE(timer_timeout,
> +	TPPROTO(struct task_struct *p),
> +		TPARGS(p));
> +#endif

For completeness and consistency, trace_itimer_start() should be 
split into two cases:

	if (value)
		trace_itimer_start(which, value);
	else
		trace_itimer_cancel(which);

That extra branch does not matter much and the resulting 
instrumentaton is more consistent across all the timer types.

So this patch needs more work, but it's a good first step.

It would also be fantastic if you did them via the TRACE_EVENT() 
mechanism in the tracing tree. It would still be just as useful to 
LTTNG - but it would also be useful to ftrace that way.

Thanks,

	Ingo