[PATCH 0/3] [GIT PULL][2.6.37] tracing: fixes v2

[PATCH 0/3] [GIT PULL][2.6.37] tracing: fixes v2

[Steven Rostedt]

Ingo,

My last pull request, I had [PATCH] instead of [GIT PULL].
You may ignore it as this pull request includes those two patches.

Please pull the latest tip/perf/urgent-2 tree, which can be found at:

  git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-2.6-trace.git
tip/perf/urgent-2


Steven Rostedt (3):
      tracing: Fix module use of trace_bprintk()
      tracing: Force arch_local_irq_* notrace for paravirt
      tracing: Fix recursive user stack trace

----
 arch/x86/include/asm/paravirt.h |   10 +++++-----
 kernel/module.c                 |   12 ++++++++++++
 kernel/trace/trace.c            |   19 +++++++++++++++++++
 3 files changed, 36 insertions(+), 5 deletions(-)

[PATCH 1/3] tracing: Fix module use of trace_bprintk()

[Steven Rostedt]

[-- Attachment #1: 0001-tracing-Fix-module-use-of-trace_bprintk.patch --]
[-- Type: text/plain, Size: 2639 bytes --]

From: Steven Rostedt <srostedt@redhat.com>

On use of trace_printk() there's a macro that determines if the format
is static or a variable. If it is static, it defaults to __trace_bprintk()
otherwise it uses __trace_printk().

A while ago, Lai Jiangshan added __trace_bprintk(). In that patch, we
discussed a way to allow modules to use it. The difference between
__trace_bprintk() and __trace_printk() is that for faster processing,
just the format and args are stored in the trace instead of running
it through a sprintf function. In order to do this, the format used
by the __trace_bprintk() had to be persistent.

See commit 1ba28e02a18cbdbea123836f6c98efb09cbf59ec

The problem comes with trace_bprintk() where the module is unloaded.
The pointer left in the buffer is still pointing to the format.

To solve this issue, the formats in the module were copied into kernel
core. If the same format was used, they would use the same copy (to prevent
memory leak). This all worked well until we tried to merge everything.

At the time this was written, Lai Jiangshan, Frederic Weisbecker,
Ingo Molnar and myself were all touching the same code. When this was
merged, we lost the part of it that was in module.c. This kept out the
copying of the formats and unloading the module could cause bad pointers
left in the ring buffer.

This patch adds back (with updates required for current kernel) the
module code that sets up the necessary pointers.

Cc: Lai Jiangshan <laijs@cn.fujitsu.com>
Cc: Rusty Russell <rusty@rustcorp.com.au>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/module.c |   12 ++++++++++++
 1 files changed, 12 insertions(+), 0 deletions(-)

diff --git a/kernel/module.c b/kernel/module.c
index 437a74a..d190664 100644
--- a/kernel/module.c
+++ b/kernel/module.c
@@ -2326,6 +2326,18 @@ static void find_module_sections(struct module *mod, struct load_info *info)
 	kmemleak_scan_area(mod->trace_events, sizeof(*mod->trace_events) *
 			   mod->num_trace_events, GFP_KERNEL);
 #endif
+#ifdef CONFIG_TRACING
+	mod->trace_bprintk_fmt_start = section_objs(info, "__trace_printk_fmt",
+					 sizeof(*mod->trace_bprintk_fmt_start),
+					 &mod->num_trace_bprintk_fmt);
+	/*
+	 * This section contains pointers to allocated objects in the trace
+	 * code and not scanning it leads to false positives.
+	 */
+	kmemleak_scan_area(mod->trace_bprintk_fmt_start,
+			   sizeof(*mod->trace_bprintk_fmt_start) *
+			   mod->num_trace_bprintk_fmt, GFP_KERNEL);
+#endif
 #ifdef CONFIG_FTRACE_MCOUNT_RECORD
 	/* sechdrs[0].sh_size is always zero */
 	mod->ftrace_callsites = section_objs(info, "__mcount_loc",
-- 
1.7.1

[PATCH 2/3] tracing: Force arch_local_irq_* notrace for paravirt

[Steven Rostedt]

[-- Attachment #1: 0002-tracing-Force-arch_local_irq_-notrace-for-paravirt.patch --]
[-- Type: text/plain, Size: 3358 bytes --]

From: Steven Rostedt <srostedt@redhat.com>

When running ktest.pl randconfig tests, I would sometimes trigger
a lockdep annotation bug (possible reason: unannotated irqs-on).

This triggering happened right after function tracer self test was
executed. After doing a config bisect I found that this was caused with
having function tracer, paravirt guest, prove locking, and rcu torture
all enabled.

The rcu torture just enhanced the likelyhood of triggering the bug.
Prove locking was needed, since it was the thing that was bugging.
Function tracer would trace and disable interrupts in all sorts
of funny places.
paravirt guest would turn arch_local_irq_* into functions that would
be traced.

Besides the fact that tracing arch_local_irq_* is just a bad idea,
this is what is happening.

The bug happened simply in the local_irq_restore() code:

		if (raw_irqs_disabled_flags(flags)) {	\
			raw_local_irq_restore(flags);	\
			trace_hardirqs_off();		\
		} else {				\
			trace_hardirqs_on();		\
			raw_local_irq_restore(flags);	\
		}					\

The raw_local_irq_restore() was defined as arch_local_irq_restore().

Now imagine, we are about to enable interrupts. We go into the else
case and call trace_hardirqs_on() which tells lockdep that we are enabling
interrupts, so it sets the current->hardirqs_enabled = 1.

Then we call raw_local_irq_restore() which calls arch_local_irq_restore()
which gets traced!

Now in the function tracer we disable interrupts with local_irq_save().
This is fine, but flags is stored that we have interrupts disabled.

When the function tracer calls local_irq_restore() it does it, but this
time with flags set as disabled, so we go into the if () path.
This keeps interrupts disabled and calls trace_hardirqs_off() which
sets current->hardirqs_enabled = 0.

When the tracer is finished and proceeds with the original code,
we enable interrupts but leave current->hardirqs_enabled as 0. Which
now breaks lockdeps internal processing.

Cc: Thomas Gleixner <tglx@linutronix.de>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 arch/x86/include/asm/paravirt.h |   10 +++++-----
 1 files changed, 5 insertions(+), 5 deletions(-)

diff --git a/arch/x86/include/asm/paravirt.h b/arch/x86/include/asm/paravirt.h
index 18e3b8a..ef99758 100644
--- a/arch/x86/include/asm/paravirt.h
+++ b/arch/x86/include/asm/paravirt.h
@@ -824,27 +824,27 @@ static __always_inline void arch_spin_unlock(struct arch_spinlock *lock)
 #define __PV_IS_CALLEE_SAVE(func)			\
 	((struct paravirt_callee_save) { func })
 
-static inline unsigned long arch_local_save_flags(void)
+static inline notrace unsigned long arch_local_save_flags(void)
 {
 	return PVOP_CALLEE0(unsigned long, pv_irq_ops.save_fl);
 }
 
-static inline void arch_local_irq_restore(unsigned long f)
+static inline notrace void arch_local_irq_restore(unsigned long f)
 {
 	PVOP_VCALLEE1(pv_irq_ops.restore_fl, f);
 }
 
-static inline void arch_local_irq_disable(void)
+static inline notrace void arch_local_irq_disable(void)
 {
 	PVOP_VCALLEE0(pv_irq_ops.irq_disable);
 }
 
-static inline void arch_local_irq_enable(void)
+static inline notrace void arch_local_irq_enable(void)
 {
 	PVOP_VCALLEE0(pv_irq_ops.irq_enable);
 }
 
-static inline unsigned long arch_local_irq_save(void)
+static inline notrace unsigned long arch_local_irq_save(void)
 {
 	unsigned long f;
 
-- 
1.7.1

[PATCH 3/3] tracing: Fix recursive user stack trace

[Steven Rostedt]

[-- Attachment #1: 0003-tracing-Fix-recursive-user-stack-trace.patch --]
[-- Type: text/plain, Size: 1858 bytes --]

From: Steven Rostedt <srostedt@redhat.com>

The user stack trace can fault when examining the trace. Which
would call the do_page_fault handler, which would trace again,
which would do the user stack trace, which would fault and call
do_page_fault again ...

Thus this is causing a recursive bug. We need to have a recursion
detector here.

[ Resubmitted by Jiri Olsa ]
Signed-off-by: Jiri Olsa <jolsa@redhat.com>
LKML-Reference: <1289390172-9730-3-git-send-email-jolsa@redhat.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/trace.c |   19 +++++++++++++++++++
 1 files changed, 19 insertions(+), 0 deletions(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 82d9b81..0215e87 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -1284,6 +1284,8 @@ void trace_dump_stack(void)
 	__ftrace_trace_stack(global_trace.buffer, flags, 3, preempt_count());
 }
 
+static DEFINE_PER_CPU(int, user_stack_count);
+
 void
 ftrace_trace_userstack(struct ring_buffer *buffer, unsigned long flags, int pc)
 {
@@ -1302,6 +1304,18 @@ ftrace_trace_userstack(struct ring_buffer *buffer, unsigned long flags, int pc)
 	if (unlikely(in_nmi()))
 		return;
 
+	/*
+	 * prevent recursion, since the user stack tracing may
+	 * trigger other kernel events.
+	 */
+	preempt_disable();
+	if (__get_cpu_var(user_stack_count))
+		goto out;
+
+	__get_cpu_var(user_stack_count)++;
+
+
+
 	event = trace_buffer_lock_reserve(buffer, TRACE_USER_STACK,
 					  sizeof(*entry), flags, pc);
 	if (!event)
@@ -1319,6 +1333,11 @@ ftrace_trace_userstack(struct ring_buffer *buffer, unsigned long flags, int pc)
 	save_stack_trace_user(&trace);
 	if (!filter_check_discard(call, entry, buffer, event))
 		ring_buffer_unlock_commit(buffer, event);
+
+	__get_cpu_var(user_stack_count)--;
+
+ out:
+	preempt_enable();
 }
 
 #ifdef UNUSED
-- 
1.7.1

Re: [PATCH 3/3] tracing: Fix recursive user stack trace

[Eric Dumazet]

Le vendredi 12 novembre 2010 à 10:10 -0500, Steven Rostedt a écrit :
> pièce jointe document texte brut
> (0003-tracing-Fix-recursive-user-stack-trace.patch)
> From: Steven Rostedt <srostedt@redhat.com>
> 
> The user stack trace can fault when examining the trace. Which
> would call the do_page_fault handler, which would trace again,
> which would do the user stack trace, which would fault and call
> do_page_fault again ...
> 
> Thus this is causing a recursive bug. We need to have a recursion
> detector here.
> 
> [ Resubmitted by Jiri Olsa ]
> Signed-off-by: Jiri Olsa <jolsa@redhat.com>
> LKML-Reference: <1289390172-9730-3-git-send-email-jolsa@redhat.com>
> Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
> ---
>  kernel/trace/trace.c |   19 +++++++++++++++++++
>  1 files changed, 19 insertions(+), 0 deletions(-)
> 
> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> index 82d9b81..0215e87 100644
> --- a/kernel/trace/trace.c
> +++ b/kernel/trace/trace.c
> @@ -1284,6 +1284,8 @@ void trace_dump_stack(void)
>  	__ftrace_trace_stack(global_trace.buffer, flags, 3, preempt_count());
>  }
>  
> +static DEFINE_PER_CPU(int, user_stack_count);
> +
>  void
>  ftrace_trace_userstack(struct ring_buffer *buffer, unsigned long flags, int pc)
>  {
> @@ -1302,6 +1304,18 @@ ftrace_trace_userstack(struct ring_buffer *buffer, unsigned long flags, int pc)
>  	if (unlikely(in_nmi()))
>  		return;
>  
> +	/*
> +	 * prevent recursion, since the user stack tracing may
> +	 * trigger other kernel events.
> +	 */
> +	preempt_disable();
> +	if (__get_cpu_var(user_stack_count))
> +		goto out;
> +

	if (__this_cpu_read(user_stack_count))
		goto out;

> +	__get_cpu_var(user_stack_count)++;

	__this_cpu_inc(user_stack_count);

> +
> +
> +
>  	event = trace_buffer_lock_reserve(buffer, TRACE_USER_STACK,
>  					  sizeof(*entry), flags, pc);
>  	if (!event)
> @@ -1319,6 +1333,11 @@ ftrace_trace_userstack(struct ring_buffer *buffer, unsigned long flags, int pc)
>  	save_stack_trace_user(&trace);
>  	if (!filter_check_discard(call, entry, buffer, event))
>  		ring_buffer_unlock_commit(buffer, event);
> +
> +	__get_cpu_var(user_stack_count)--;
	__this_cpu_dec(user_stack_count);

> +
> + out:
> +	preempt_enable();
>  }
>  
>  #ifdef UNUSED

Re: [PATCH 3/3] tracing: Fix recursive user stack trace

[Steven Rostedt]

On Fri, 2010-11-12 at 16:21 +0100, Eric Dumazet wrote:
> Le vendredi 12 novembre 2010 à 10:10 -0500, Steven Rostedt a écrit :
> > pièce jointe document texte brut
> > (0003-tracing-Fix-recursive-user-stack-trace.patch)
> > From: Steven Rostedt <srostedt@redhat.com>
> > 
> > The user stack trace can fault when examining the trace. Which
> > would call the do_page_fault handler, which would trace again,
> > which would do the user stack trace, which would fault and call
> > do_page_fault again ...
> > 
> > Thus this is causing a recursive bug. We need to have a recursion
> > detector here.
> > 
> > [ Resubmitted by Jiri Olsa ]
> > Signed-off-by: Jiri Olsa <jolsa@redhat.com>
> > LKML-Reference: <1289390172-9730-3-git-send-email-jolsa@redhat.com>
> > Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
> > ---
> >  kernel/trace/trace.c |   19 +++++++++++++++++++
> >  1 files changed, 19 insertions(+), 0 deletions(-)
> > 
> > diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> > index 82d9b81..0215e87 100644
> > --- a/kernel/trace/trace.c
> > +++ b/kernel/trace/trace.c
> > @@ -1284,6 +1284,8 @@ void trace_dump_stack(void)
> >  	__ftrace_trace_stack(global_trace.buffer, flags, 3, preempt_count());
> >  }
> >  
> > +static DEFINE_PER_CPU(int, user_stack_count);
> > +
> >  void
> >  ftrace_trace_userstack(struct ring_buffer *buffer, unsigned long flags, int pc)
> >  {
> > @@ -1302,6 +1304,18 @@ ftrace_trace_userstack(struct ring_buffer *buffer, unsigned long flags, int pc)
> >  	if (unlikely(in_nmi()))
> >  		return;
> >  
> > +	/*
> > +	 * prevent recursion, since the user stack tracing may
> > +	 * trigger other kernel events.
> > +	 */
> > +	preempt_disable();
> > +	if (__get_cpu_var(user_stack_count))
> > +		goto out;
> > +
> 
> 	if (__this_cpu_read(user_stack_count))
> 		goto out;
> 
> > +	__get_cpu_var(user_stack_count)++;
> 
> 	__this_cpu_inc(user_stack_count);

Thanks, I'll update and resubmit.

-- Steve

> 
> > +
> > +
> > +
> >  	event = trace_buffer_lock_reserve(buffer, TRACE_USER_STACK,
> >  					  sizeof(*entry), flags, pc);
> >  	if (!event)
> > @@ -1319,6 +1333,11 @@ ftrace_trace_userstack(struct ring_buffer *buffer, unsigned long flags, int pc)
> >  	save_stack_trace_user(&trace);
> >  	if (!filter_check_discard(call, entry, buffer, event))
> >  		ring_buffer_unlock_commit(buffer, event);
> > +
> > +	__get_cpu_var(user_stack_count)--;
> 	__this_cpu_dec(user_stack_count);
> 
> > +
> > + out:
> > +	preempt_enable();
> >  }
> >  
> >  #ifdef UNUSED
>