[for-next][PATCH 0/2] tracing: Some last minute changes before I push for 4.6

[for-next][PATCH 0/2] tracing: Some last minute changes before I push for 4.6

[Steven Rostedt]

  git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git
for-next

Head SHA1: 7e6867bf831c71fe0e47438831ae3a94d4c7ab3c


Peter Zijlstra (1):
      tracing: Record and show NMI state

Steven Rostedt (Red Hat) (1):
      tracing: Fix trace_printk() to print when not using bprintk()

----
 include/linux/kernel.h      |  6 +++---
 kernel/trace/trace.c        |  1 +
 kernel/trace/trace.h        |  1 +
 kernel/trace/trace_output.c | 10 +++++++---
 kernel/trace/trace_printk.c |  3 +++
 5 files changed, 15 insertions(+), 6 deletions(-)

[for-next][PATCH 1/2] tracing: Fix trace_printk() to print when not using bprintk()

[Steven Rostedt]

[-- Attachment #1: 0001-tracing-Fix-trace_printk-to-print-when-not-using-bpr.patch --]
[-- Type: text/plain, Size: 2861 bytes --]

From: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org>

The trace_printk() code will allocate extra buffers if the compile detects
that a trace_printk() is used. To do this, the format of the trace_printk()
is saved to the __trace_printk_fmt section, and if that section is bigger
than zero, the buffers are allocated (along with a message that this has
happened).

If trace_printk() uses a format that is not a constant, and thus something
not guaranteed to be around when the print happens, the compiler optimizes
the fmt out, as it is not used, and the __trace_printk_fmt section is not
filled. This means the kernel will not allocate the special buffers needed
for the trace_printk() and the trace_printk() will not write anything to the
tracing buffer.

Adding a "__used" to the variable in the __trace_printk_fmt section will
keep it around, even though it is set to NULL. This will keep the string
from being printed in the debugfs/tracing/printk_formats section as it is
not needed.

Reported-by: Vlastimil Babka <vbabka@suse.cz>
Fixes: 07d777fe8c398 "tracing: Add percpu buffers for trace_printk()"
Cc: stable@vger.kernel.org # v3.5+
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 include/linux/kernel.h      | 6 +++---
 kernel/trace/trace_printk.c | 3 +++
 2 files changed, 6 insertions(+), 3 deletions(-)

diff --git a/include/linux/kernel.h b/include/linux/kernel.h
index f31638c6e873..95452f72349a 100644
--- a/include/linux/kernel.h
+++ b/include/linux/kernel.h
@@ -635,7 +635,7 @@ do {							\
 
 #define do_trace_printk(fmt, args...)					\
 do {									\
-	static const char *trace_printk_fmt				\
+	static const char *trace_printk_fmt __used			\
 		__attribute__((section("__trace_printk_fmt"))) =	\
 		__builtin_constant_p(fmt) ? fmt : NULL;			\
 									\
@@ -679,7 +679,7 @@ int __trace_printk(unsigned long ip, const char *fmt, ...);
  */
 
 #define trace_puts(str) ({						\
-	static const char *trace_printk_fmt				\
+	static const char *trace_printk_fmt __used			\
 		__attribute__((section("__trace_printk_fmt"))) =	\
 		__builtin_constant_p(str) ? str : NULL;			\
 									\
@@ -701,7 +701,7 @@ extern void trace_dump_stack(int skip);
 #define ftrace_vprintk(fmt, vargs)					\
 do {									\
 	if (__builtin_constant_p(fmt)) {				\
-		static const char *trace_printk_fmt			\
+		static const char *trace_printk_fmt __used		\
 		  __attribute__((section("__trace_printk_fmt"))) =	\
 			__builtin_constant_p(fmt) ? fmt : NULL;		\
 									\
diff --git a/kernel/trace/trace_printk.c b/kernel/trace/trace_printk.c
index 060df67dbdd1..f96f0383f6c6 100644
--- a/kernel/trace/trace_printk.c
+++ b/kernel/trace/trace_printk.c
@@ -296,6 +296,9 @@ static int t_show(struct seq_file *m, void *v)
 	const char *str = *fmt;
 	int i;
 
+	if (!*fmt)
+		return 0;
+
 	seq_printf(m, "0x%lx : \"", *(unsigned long *)fmt);
 
 	/*
-- 
2.7.0

[for-next][PATCH 2/2] tracing: Record and show NMI state

[Steven Rostedt]

[-- Attachment #1: 0002-tracing-Record-and-show-NMI-state.patch --]
[-- Type: text/plain, Size: 2406 bytes --]

From: Peter Zijlstra <peterz@infradead.org>

The latency tracer format has a nice column to indicate IRQ state, but
this is not able to tell us about NMI state.

When tracing perf interrupt handlers (which often run in NMI context)
it is very useful to see how the events nest.

Link: http://lkml.kernel.org/r/20160318153022.105068893@infradead.org

Signed-off-by: Peter Zijlstra (Intel) <peterz@infradead.org>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/trace.c        |  1 +
 kernel/trace/trace.h        |  1 +
 kernel/trace/trace_output.c | 10 +++++++---
 3 files changed, 9 insertions(+), 3 deletions(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index cb2b708e4ea7..7bdf8ba323ec 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -1664,6 +1664,7 @@ tracing_generic_entry_update(struct trace_entry *entry, unsigned long flags,
 #else
 		TRACE_FLAG_IRQS_NOSUPPORT |
 #endif
+		((pc & NMI_MASK    ) ? TRACE_FLAG_NMI     : 0) |
 		((pc & HARDIRQ_MASK) ? TRACE_FLAG_HARDIRQ : 0) |
 		((pc & SOFTIRQ_MASK) ? TRACE_FLAG_SOFTIRQ : 0) |
 		(tif_need_resched() ? TRACE_FLAG_NEED_RESCHED : 0) |
diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index 39588c23dd8b..3fff4adfd431 100644
--- a/kernel/trace/trace.h
+++ b/kernel/trace/trace.h
@@ -125,6 +125,7 @@ enum trace_flag_type {
 	TRACE_FLAG_HARDIRQ		= 0x08,
 	TRACE_FLAG_SOFTIRQ		= 0x10,
 	TRACE_FLAG_PREEMPT_RESCHED	= 0x20,
+	TRACE_FLAG_NMI			= 0x40,
 };
 
 #define TRACE_BUF_SIZE		1024
diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
index 282982195e09..0bb9cf2d53e6 100644
--- a/kernel/trace/trace_output.c
+++ b/kernel/trace/trace_output.c
@@ -389,7 +389,9 @@ int trace_print_lat_fmt(struct trace_seq *s, struct trace_entry *entry)
 	char irqs_off;
 	int hardirq;
 	int softirq;
+	int nmi;
 
+	nmi = entry->flags & TRACE_FLAG_NMI;
 	hardirq = entry->flags & TRACE_FLAG_HARDIRQ;
 	softirq = entry->flags & TRACE_FLAG_SOFTIRQ;
 
@@ -415,10 +417,12 @@ int trace_print_lat_fmt(struct trace_seq *s, struct trace_entry *entry)
 	}
 
 	hardsoft_irq =
+		(nmi && hardirq)     ? 'Z' :
+		nmi                  ? 'z' :
 		(hardirq && softirq) ? 'H' :
-		hardirq ? 'h' :
-		softirq ? 's' :
-		'.';
+		hardirq              ? 'h' :
+		softirq              ? 's' :
+		                       '.' ;
 
 	trace_seq_printf(s, "%c%c%c",
 			 irqs_off, need_resched, hardsoft_irq);
-- 
2.7.0

Re: [for-next][PATCH 1/2] tracing: Fix trace_printk() to print when not using bprintk()

[Vlastimil Babka]

On 03/23/2016 01:24 PM, Steven Rostedt wrote:
> From: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org>
>
> The trace_printk() code will allocate extra buffers if the compile detects
> that a trace_printk() is used. To do this, the format of the trace_printk()
> is saved to the __trace_printk_fmt section, and if that section is bigger
> than zero, the buffers are allocated (along with a message that this has
> happened).
>
> If trace_printk() uses a format that is not a constant, and thus something
> not guaranteed to be around when the print happens, the compiler optimizes
> the fmt out, as it is not used, and the __trace_printk_fmt section is not
> filled. This means the kernel will not allocate the special buffers needed
> for the trace_printk() and the trace_printk() will not write anything to the
> tracing buffer.
>
> Adding a "__used" to the variable in the __trace_printk_fmt section will
> keep it around, even though it is set to NULL. This will keep the string
> from being printed in the debugfs/tracing/printk_formats section as it is
> not needed.
>
> Reported-by: Vlastimil Babka <vbabka@suse.cz>
> Fixes: 07d777fe8c398 "tracing: Add percpu buffers for trace_printk()"
> Cc: stable@vger.kernel.org # v3.5+
> Signed-off-by: Steven Rostedt <rostedt@goodmis.org>

Tested-by: Vlastimil Babka <vbabka@suse.cz>

Thanks!