public inbox for linux-kernel@vger.kernel.org
 help / color / mirror / Atom feed
* [PATCH] tracing: Fix a race in function profile
@ 2010-08-23  8:50 Li Zefan
  2010-08-30 23:32 ` Steven Rostedt
  2010-08-31 21:11 ` [tip:perf/urgent] " tip-bot for Li Zefan
  0 siblings, 2 replies; 3+ messages in thread
From: Li Zefan @ 2010-08-23  8:50 UTC (permalink / raw)
  To: Steven Rostedt; +Cc: Frederic Weisbecker, LKML

While we are reading trace_stat/functionX and someone just
disabled function_profile at that time, we can trigger this:

	divide error: 0000 [#1] PREEMPT SMP
	...
	EIP is at function_stat_show+0x90/0x230
	...

This fix just takes the ftrace_profile_lock and checks if
rec->counter is 0. If it's 0, we know the profile buffer
has been reset.

Signed-off-by: Li Zefan <lizf@cn.fujitsu.com>
---
 kernel/trace/ftrace.c |   15 +++++++++++----
 1 files changed, 11 insertions(+), 4 deletions(-)

diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
index 0d88ce9..7cb1f45 100644
--- a/kernel/trace/ftrace.c
+++ b/kernel/trace/ftrace.c
@@ -381,12 +381,19 @@ static int function_stat_show(struct seq_file *m, void *v)
 {
 	struct ftrace_profile *rec = v;
 	char str[KSYM_SYMBOL_LEN];
+	int ret = 0;
 #ifdef CONFIG_FUNCTION_GRAPH_TRACER
-	static DEFINE_MUTEX(mutex);
 	static struct trace_seq s;
 	unsigned long long avg;
 	unsigned long long stddev;
 #endif
+	mutex_lock(&ftrace_profile_lock);
+
+	/* we raced with function_profile_reset() */
+	if (unlikely(rec->counter == 0)) {
+		ret = -EBUSY;
+		goto out;
+	}
 
 	kallsyms_lookup(rec->ip, NULL, NULL, NULL, str);
 	seq_printf(m, "  %-30.30s  %10lu", str, rec->counter);
@@ -408,7 +415,6 @@ static int function_stat_show(struct seq_file *m, void *v)
 		do_div(stddev, (rec->counter - 1) * 1000);
 	}
 
-	mutex_lock(&mutex);
 	trace_seq_init(&s);
 	trace_print_graph_duration(rec->time, &s);
 	trace_seq_puts(&s, "    ");
@@ -416,11 +422,12 @@ static int function_stat_show(struct seq_file *m, void *v)
 	trace_seq_puts(&s, "    ");
 	trace_print_graph_duration(stddev, &s);
 	trace_print_seq(m, &s);
-	mutex_unlock(&mutex);
 #endif
 	seq_putc(m, '\n');
+out:
+	mutex_unlock(&ftrace_profile_lock);
 
-	return 0;
+	return ret;
 }
 
 static void ftrace_profile_reset(struct ftrace_profile_stat *stat)
-- 
1.7.0.1


^ permalink raw reply related	[flat|nested] 3+ messages in thread

* Re: [PATCH] tracing: Fix a race in function profile
  2010-08-23  8:50 [PATCH] tracing: Fix a race in function profile Li Zefan
@ 2010-08-30 23:32 ` Steven Rostedt
  2010-08-31 21:11 ` [tip:perf/urgent] " tip-bot for Li Zefan
  1 sibling, 0 replies; 3+ messages in thread
From: Steven Rostedt @ 2010-08-30 23:32 UTC (permalink / raw)
  To: Li Zefan; +Cc: Frederic Weisbecker, LKML

On Mon, 2010-08-23 at 16:50 +0800, Li Zefan wrote:
> While we are reading trace_stat/functionX and someone just
> disabled function_profile at that time, we can trigger this:
> 
> 	divide error: 0000 [#1] PREEMPT SMP
> 	...
> 	EIP is at function_stat_show+0x90/0x230
> 	...
> 
> This fix just takes the ftrace_profile_lock and checks if
> rec->counter is 0. If it's 0, we know the profile buffer
> has been reset.
> 
> Signed-off-by: Li Zefan <lizf@cn.fujitsu.com>

Thanks Li!

I'll add this to my queue, test it, and then push it up as a -rc and
stable fix.

-- Steve

> ---
>  kernel/trace/ftrace.c |   15 +++++++++++----
>  1 files changed, 11 insertions(+), 4 deletions(-)
> 
> diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
> index 0d88ce9..7cb1f45 100644
> --- a/kernel/trace/ftrace.c
> +++ b/kernel/trace/ftrace.c
> @@ -381,12 +381,19 @@ static int function_stat_show(struct seq_file *m, void *v)
>  {
>  	struct ftrace_profile *rec = v;
>  	char str[KSYM_SYMBOL_LEN];
> +	int ret = 0;
>  #ifdef CONFIG_FUNCTION_GRAPH_TRACER
> -	static DEFINE_MUTEX(mutex);
>  	static struct trace_seq s;
>  	unsigned long long avg;
>  	unsigned long long stddev;
>  #endif
> +	mutex_lock(&ftrace_profile_lock);
> +
> +	/* we raced with function_profile_reset() */
> +	if (unlikely(rec->counter == 0)) {
> +		ret = -EBUSY;
> +		goto out;
> +	}
>  
>  	kallsyms_lookup(rec->ip, NULL, NULL, NULL, str);
>  	seq_printf(m, "  %-30.30s  %10lu", str, rec->counter);
> @@ -408,7 +415,6 @@ static int function_stat_show(struct seq_file *m, void *v)
>  		do_div(stddev, (rec->counter - 1) * 1000);
>  	}
>  
> -	mutex_lock(&mutex);
>  	trace_seq_init(&s);
>  	trace_print_graph_duration(rec->time, &s);
>  	trace_seq_puts(&s, "    ");
> @@ -416,11 +422,12 @@ static int function_stat_show(struct seq_file *m, void *v)
>  	trace_seq_puts(&s, "    ");
>  	trace_print_graph_duration(stddev, &s);
>  	trace_print_seq(m, &s);
> -	mutex_unlock(&mutex);
>  #endif
>  	seq_putc(m, '\n');
> +out:
> +	mutex_unlock(&ftrace_profile_lock);
>  
> -	return 0;
> +	return ret;
>  }
>  
>  static void ftrace_profile_reset(struct ftrace_profile_stat *stat)



^ permalink raw reply	[flat|nested] 3+ messages in thread

* [tip:perf/urgent] tracing: Fix a race in function profile
  2010-08-23  8:50 [PATCH] tracing: Fix a race in function profile Li Zefan
  2010-08-30 23:32 ` Steven Rostedt
@ 2010-08-31 21:11 ` tip-bot for Li Zefan
  1 sibling, 0 replies; 3+ messages in thread
From: tip-bot for Li Zefan @ 2010-08-31 21:11 UTC (permalink / raw)
  To: linux-tip-commits; +Cc: linux-kernel, hpa, mingo, rostedt, lizf, tglx

Commit-ID:  3aaba20f26f58843e8f20611e5c0b1c06954310f
Gitweb:     http://git.kernel.org/tip/3aaba20f26f58843e8f20611e5c0b1c06954310f
Author:     Li Zefan <lizf@cn.fujitsu.com>
AuthorDate: Mon, 23 Aug 2010 16:50:12 +0800
Committer:  Steven Rostedt <rostedt@goodmis.org>
CommitDate: Tue, 31 Aug 2010 16:46:23 -0400

tracing: Fix a race in function profile

While we are reading trace_stat/functionX and someone just
disabled function_profile at that time, we can trigger this:

	divide error: 0000 [#1] PREEMPT SMP
	...
	EIP is at function_stat_show+0x90/0x230
	...

This fix just takes the ftrace_profile_lock and checks if
rec->counter is 0. If it's 0, we know the profile buffer
has been reset.

Signed-off-by: Li Zefan <lizf@cn.fujitsu.com>
Cc: stable@kernel.org
LKML-Reference: <4C723644.4040708@cn.fujitsu.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/ftrace.c |   15 +++++++++++----
 1 files changed, 11 insertions(+), 4 deletions(-)

diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
index 0d88ce9..7cb1f45 100644
--- a/kernel/trace/ftrace.c
+++ b/kernel/trace/ftrace.c
@@ -381,12 +381,19 @@ static int function_stat_show(struct seq_file *m, void *v)
 {
 	struct ftrace_profile *rec = v;
 	char str[KSYM_SYMBOL_LEN];
+	int ret = 0;
 #ifdef CONFIG_FUNCTION_GRAPH_TRACER
-	static DEFINE_MUTEX(mutex);
 	static struct trace_seq s;
 	unsigned long long avg;
 	unsigned long long stddev;
 #endif
+	mutex_lock(&ftrace_profile_lock);
+
+	/* we raced with function_profile_reset() */
+	if (unlikely(rec->counter == 0)) {
+		ret = -EBUSY;
+		goto out;
+	}
 
 	kallsyms_lookup(rec->ip, NULL, NULL, NULL, str);
 	seq_printf(m, "  %-30.30s  %10lu", str, rec->counter);
@@ -408,7 +415,6 @@ static int function_stat_show(struct seq_file *m, void *v)
 		do_div(stddev, (rec->counter - 1) * 1000);
 	}
 
-	mutex_lock(&mutex);
 	trace_seq_init(&s);
 	trace_print_graph_duration(rec->time, &s);
 	trace_seq_puts(&s, "    ");
@@ -416,11 +422,12 @@ static int function_stat_show(struct seq_file *m, void *v)
 	trace_seq_puts(&s, "    ");
 	trace_print_graph_duration(stddev, &s);
 	trace_print_seq(m, &s);
-	mutex_unlock(&mutex);
 #endif
 	seq_putc(m, '\n');
+out:
+	mutex_unlock(&ftrace_profile_lock);
 
-	return 0;
+	return ret;
 }
 
 static void ftrace_profile_reset(struct ftrace_profile_stat *stat)

^ permalink raw reply related	[flat|nested] 3+ messages in thread

end of thread, other threads:[~2010-08-31 21:12 UTC | newest]

Thread overview: 3+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2010-08-23  8:50 [PATCH] tracing: Fix a race in function profile Li Zefan
2010-08-30 23:32 ` Steven Rostedt
2010-08-31 21:11 ` [tip:perf/urgent] " tip-bot for Li Zefan

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox