linux-kernel - Re: timers: Make flags output in the timer

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <20170210091921.68f7ca19@gandalf.local.home>
Date:   Fri, 10 Feb 2017 09:19:21 -0500
From:   Steven Rostedt <rostedt@...dmis.org>
To:     Thomas Gleixner <tglx@...utronix.de>
Cc:     LKML <linux-kernel@...r.kernel.org>,
        Peter Zijlstra <peterz@...radead.org>,
        Arjan van de Ven <arjan@...ux.intel.com>
Subject: Re: timers:  Make flags output in the timer_start tracepoint useful

On Fri, 10 Feb 2017 14:25:03 +0100 (CET)
Thomas Gleixner <tglx@...utronix.de> wrote:

> The timer flags in the timer_start trace event contain lots of useful
> information, but the meaning is not clear in the trace output because its
> just printed as a hex value. Making tools rely on the bit positions is bad
> as they might change over time.
> 
> Decode the flags in the printout. Tools can retrieve the bits and their
> meaning from the trace format file.
> 
> Example output:
> kworker/2:1-47    <SNIP> [timeout=592] cpu=2 idx=170 flags=D|I
> 
> So the timer is Deferrable and Interruptsafe, queued on CPU 2 into bucket
> 170.
> 
> Requested-by: Arjan van de Ven <arjan@...ux.intel.com>
> Signed-off-by: Thomas Gleixner <tglx@...utronix.de>
> ---
>  include/trace/events/timer.h |   14 ++++++++++++--
>  1 file changed, 12 insertions(+), 2 deletions(-)
> 
> --- a/include/trace/events/timer.h
> +++ b/include/trace/events/timer.h
> @@ -36,6 +36,13 @@ DEFINE_EVENT(timer_class, timer_init,
>  	TP_ARGS(timer)
>  );
>  
> +#define decode_timer_flags(flags)			\
> +	__print_flags(flags, "|",			\
> +		{  TIMER_MIGRATING,	"M" },		\
> +		{  TIMER_DEFERRABLE,	"D" },		\
> +		{  TIMER_PINNED,	"P" },		\
> +		{  TIMER_IRQSAFE,	"I" })
> +
>  /**
>   * timer_start - called when the timer is started
>   * @timer:	pointer to struct timer_list
> @@ -65,9 +72,12 @@ TRACE_EVENT(timer_start,
>  		__entry->flags		= flags;
>  	),
>  
> -	TP_printk("timer=%p function=%pf expires=%lu [timeout=%ld] flags=0x%08x",
> +	TP_printk("timer=%p function=%pf expires=%lu [timeout=%ld] cpu=%u idx=%u flags=%s",
>  		  __entry->timer, __entry->function, __entry->expires,
> -		  (long)__entry->expires - __entry->now, __entry->flags)
> +		  (long)__entry->expires - __entry->now,
> +		  __entry->flags & TIMER_CPUMASK,
> +		  __entry->flags >> TIMER_ARRAYSHIFT,
> +		  decode_timer_flags(__entry->flags & TIMER_TRACE_FLAGMASK))

Hi Thomas,

This all looks good, but I can't find TIMER_TRACE_FLAGMASK. Was that
added by another patch?

-- Steve

>  );
>  
>  /**