From mboxrd@z Thu Jan  1 00:00:00 1970
Return-Path: <linux-kernel-owner@vger.kernel.org>
Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
        id S1752587AbdBJOiA (ORCPT <rfc822;w@1wt.eu>);
        Fri, 10 Feb 2017 09:38:00 -0500
Received: from Galois.linutronix.de ([146.0.238.70]:60808 "EHLO
        Galois.linutronix.de" rhost-flags-OK-OK-OK-OK) by vger.kernel.org
        with ESMTP id S1751802AbdBJOhz (ORCPT
        <rfc822;linux-kernel@vger.kernel.org>);
        Fri, 10 Feb 2017 09:37:55 -0500
Date: Fri, 10 Feb 2017 15:37:11 +0100 (CET)
From: Thomas Gleixner <tglx@linutronix.de>
To: Steven Rostedt <rostedt@goodmis.org>
cc: LKML <linux-kernel@vger.kernel.org>,
        Peter Zijlstra <peterz@infradead.org>,
        Arjan van de Ven <arjan@linux.intel.com>
Subject: Re: timers: Make flags output in the timer_start tracepoint useful
In-Reply-To: <20170210091921.68f7ca19@gandalf.local.home>
Message-ID: <alpine.DEB.2.20.1702101536451.4036@nanos>
References: <alpine.DEB.2.20.1702101420450.4036@nanos> <20170210091921.68f7ca19@gandalf.local.home>
User-Agent: Alpine 2.20 (DEB 67 2015-01-07)
MIME-Version: 1.0
Content-Type: text/plain; charset=US-ASCII
Sender: linux-kernel-owner@vger.kernel.org
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org

On Fri, 10 Feb 2017, Steven Rostedt wrote:

> On Fri, 10 Feb 2017 14:25:03 +0100 (CET)
> Thomas Gleixner <tglx@linutronix.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@linux.intel.com>
> > Signed-off-by: Thomas Gleixner <tglx@linutronix.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?

-ENO_QUILT_REFRESH ....