From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1752878AbdBJPfT (ORCPT ); Fri, 10 Feb 2017 10:35:19 -0500 Received: from Galois.linutronix.de ([146.0.238.70]:33086 "EHLO Galois.linutronix.de" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1752164AbdBJPfO (ORCPT ); Fri, 10 Feb 2017 10:35:14 -0500 Date: Fri, 10 Feb 2017 14:25:03 +0100 (CET) From: Thomas Gleixner To: LKML cc: Peter Zijlstra , Steven Rostedt , Arjan van de Ven Subject: timers: Make flags output in the timer_start tracepoint useful Message-ID: 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: X-Mailing-List: linux-kernel@vger.kernel.org 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 [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 Signed-off-by: Thomas Gleixner --- 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)) ); /**