timers: Make flags output in the timer_start tracepoint useful

The timer flags in the timer_start trace event contain lots of useful
information, but the meaning is not clear in the trace output. Making tools
rely on the bit positions is bad as they might change over time.

Decode the flags in the print out. Tools can retrieve the bits and their
meaning from the trace format file.

Link: http://lkml.kernel.org/r/alpine.DEB.2.20.1702101639290.4036@nanos
Requested-by: Arjan van de Ven <arjan@linux.intel.com>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>

diff --git a/include/linux/timer.h b/include/linux/timer.h
index 51d601f192d421c6e3721c6621d7c3e08dc1a54d..a17f915f94569e805dbdc74bd856713299143b61 100644 (file)
--- a/include/linux/timer.h
+++ b/include/linux/timer.h
@@ -66,6 +66,8 @@ struct timer_list {
 #define TIMER_ARRAYSHIFT       22
 #define TIMER_ARRAYMASK                0xFFC00000
 
+#define TIMER_TRACE_FLAGMASK   (TIMER_MIGRATING | TIMER_DEFERRABLE | TIMER_PINNED | TIMER_IRQSAFE)
+
 #define __TIMER_INITIALIZER(_function, _expires, _data, _flags) { \
                .entry = { .next = TIMER_ENTRY_STATIC },        \
                .function = (_function),                        \

diff --git a/include/trace/events/timer.h b/include/trace/events/timer.h
index 1448637616d648475d5ccd28945df6fce617bca0..f6d8fea6df77b37fb53d23fe66344c60a2fcb17f 100644 (file)
--- 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))
 );
 
 /**