[v9,05/32] tracing/timers: Add tracepoint for tracking timer base is_idle flag

Message ID 20231201092654.34614-6-anna-maria@linutronix.de
State New
Headers
Series timers: Move from a push remote at enqueue to a pull at expiry model |

Commit Message

Anna-Maria Behnsen Dec. 1, 2023, 9:26 a.m. UTC
  When debugging timer code the timer tracepoints are very important. There
is no tracepoint when the is_idle flag of the timer base changes. Instead
of always adding manually trace_printk(), add tracepoints which can be
easily enabled whenever required.

Signed-off-by: Anna-Maria Behnsen <anna-maria@linutronix.de>
---
v9: New in v9
---
 include/trace/events/timer.h | 20 ++++++++++++++++++++
 kernel/time/timer.c          |  2 ++
 2 files changed, 22 insertions(+)
  

Comments

Frederic Weisbecker Dec. 20, 2023, 1:43 p.m. UTC | #1
Le Fri, Dec 01, 2023 at 10:26:27AM +0100, Anna-Maria Behnsen a écrit :
> When debugging timer code the timer tracepoints are very important. There
> is no tracepoint when the is_idle flag of the timer base changes. Instead
> of always adding manually trace_printk(), add tracepoints which can be
> easily enabled whenever required.
> 
> Signed-off-by: Anna-Maria Behnsen <anna-maria@linutronix.de>

Reviewed-by: Frederic Weisbecker <frederic@kernel.org>

Just a detail below, again this can be posted as a delta patch or
edited before applying:

> ---
> v9: New in v9
> ---
>  include/trace/events/timer.h | 20 ++++++++++++++++++++
>  kernel/time/timer.c          |  2 ++
>  2 files changed, 22 insertions(+)
> 
> diff --git a/include/trace/events/timer.h b/include/trace/events/timer.h
> index 99ada928d445..1ef58a04fc57 100644
> --- a/include/trace/events/timer.h
> +++ b/include/trace/events/timer.h
> @@ -142,6 +142,26 @@ DEFINE_EVENT(timer_class, timer_cancel,
>  	TP_ARGS(timer)
>  );
>  
> +TRACE_EVENT(timer_base_idle,
> +
> +	TP_PROTO(bool is_idle, unsigned int cpu),
> +
> +	TP_ARGS(is_idle, cpu),
> +
> +	TP_STRUCT__entry(
> +		__field( bool,		is_idle	)
> +		__field( unsigned int,	cpu	)
> +	),
> +
> +	TP_fast_assign(
> +		__entry->is_idle	= is_idle;
> +		__entry->cpu		= cpu;
> +	),
> +
> +	TP_printk("is_idle=%d cpu=%d",
> +		  __entry->is_idle, __entry->cpu)
> +);
> +
>  #define decode_clockid(type)						\
>  	__print_symbolic(type,						\
>  		{ CLOCK_REALTIME,	"CLOCK_REALTIME"	},	\
> diff --git a/kernel/time/timer.c b/kernel/time/timer.c
> index a81d793a43d0..46a9b96a3976 100644
> --- a/kernel/time/timer.c
> +++ b/kernel/time/timer.c
> @@ -1964,6 +1964,7 @@ u64 get_next_timer_interrupt(unsigned long basej, u64 basem)
>  		if ((expires - basem) > TICK_NSEC)
>  			base->is_idle = true;
>  	}
> +	trace_timer_base_idle(base->is_idle, base->cpu);

This will trigger a trace everytime we loop into idle or remotely
compute the next timer. Can we move that to when base->is_idle is set
from false to true only?

>  	raw_spin_unlock(&base->lock);
>  
>  	return cmp_next_hrtimer_event(basem, expires);
> @@ -1985,6 +1986,7 @@ void timer_clear_idle(void)
>  	 * the lock in the exit from idle path.
>  	 */
>  	base->is_idle = false;
> +	trace_timer_base_idle(0, smp_processor_id());

Same here. If base->is_idle was already false, you could spare a noisy
trace.

Thanks.

>  }
>  #endif
>  
> -- 
> 2.39.2
>
  

Patch

diff --git a/include/trace/events/timer.h b/include/trace/events/timer.h
index 99ada928d445..1ef58a04fc57 100644
--- a/include/trace/events/timer.h
+++ b/include/trace/events/timer.h
@@ -142,6 +142,26 @@  DEFINE_EVENT(timer_class, timer_cancel,
 	TP_ARGS(timer)
 );
 
+TRACE_EVENT(timer_base_idle,
+
+	TP_PROTO(bool is_idle, unsigned int cpu),
+
+	TP_ARGS(is_idle, cpu),
+
+	TP_STRUCT__entry(
+		__field( bool,		is_idle	)
+		__field( unsigned int,	cpu	)
+	),
+
+	TP_fast_assign(
+		__entry->is_idle	= is_idle;
+		__entry->cpu		= cpu;
+	),
+
+	TP_printk("is_idle=%d cpu=%d",
+		  __entry->is_idle, __entry->cpu)
+);
+
 #define decode_clockid(type)						\
 	__print_symbolic(type,						\
 		{ CLOCK_REALTIME,	"CLOCK_REALTIME"	},	\
diff --git a/kernel/time/timer.c b/kernel/time/timer.c
index a81d793a43d0..46a9b96a3976 100644
--- a/kernel/time/timer.c
+++ b/kernel/time/timer.c
@@ -1964,6 +1964,7 @@  u64 get_next_timer_interrupt(unsigned long basej, u64 basem)
 		if ((expires - basem) > TICK_NSEC)
 			base->is_idle = true;
 	}
+	trace_timer_base_idle(base->is_idle, base->cpu);
 	raw_spin_unlock(&base->lock);
 
 	return cmp_next_hrtimer_event(basem, expires);
@@ -1985,6 +1986,7 @@  void timer_clear_idle(void)
 	 * the lock in the exit from idle path.
 	 */
 	base->is_idle = false;
+	trace_timer_base_idle(0, smp_processor_id());
 }
 #endif