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 <ar...@linux.intel.com>
Signed-off-by: Thomas Gleixner <t...@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))
);
/**
