[PATCH 0/2] [GIT PULL][for 2.6.31] function graph gcc issue

[PATCH 0/2] [GIT PULL][for 2.6.31] function graph gcc issue

[Steven Rostedt]

Ingo,

The bug I spent two days debugging that Jake found was due to gcc
making a copy of the return address into the stack frame and not
using it to actually return. The function graph tracer would modify
the copy and not the actual location that was used to return to.
Thus the accounting of the function graph tracer was corrupted and
a nasty crash followed.

I found that 32bit x86 when compiled with optimize for size caused
this issue in the latest gcc (4.4.0). The first patch makes the
function graph tracer depend on !X86_32 || !CC_OPTIMIZE_FOR_SIZE.
This way we keep from getting into trouble with a know configuration
that breaks.

Then next patch adds to x86 (both 32bit and 64bit) a test of the
frame pointer to make sure that the return actually goes to where
we expect it to.

When debugging Jakes bug, The first instance was easy to find. It was
the timer_stats_update_stats that had a forced cacheline struct as a local.
I changed that and it seemed to fix the boot up test. When I enabled
function graph at run time, the system crashed again, but this time the
crash was hard to find where the issue was. I wrote up this test (patch 2)
and I found the problem immediately. In case gcc changes, we want to be
able to detect it right away before the tracer does anything dangerous.


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

  git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-2.6-trace.git
tip/tracing/urgent-1


Steven Rostedt (2):
      function-graph: disable when both x86_32 and optimize for size are configured
      function-graph: add stack frame test

----
 arch/powerpc/kernel/ftrace.c         |    2 +-
 arch/s390/kernel/ftrace.c            |    2 +-
 arch/x86/Kconfig                     |    1 +
 arch/x86/kernel/entry_32.S           |    2 +
 arch/x86/kernel/entry_64.S           |    2 +
 arch/x86/kernel/ftrace.c             |    6 +++-
 include/linux/ftrace.h               |    4 ++-
 kernel/trace/Kconfig                 |    8 +++++++
 kernel/trace/trace_functions_graph.c |   36 ++++++++++++++++++++++++++++++---
 9 files changed, 54 insertions(+), 9 deletions(-)
-- 

[PATCH 1/2] function-graph: disable when both x86_32 and optimize for size are configured

[Steven Rostedt]

[-- Attachment #1: 0001-function-graph-disable-when-both-x86_32-and-optimize.patch --]
[-- Type: text/plain, Size: 2950 bytes --]

From: Steven Rostedt <srostedt@redhat.com>

On x86_32, when optimize for size is set, gcc may align the frame pointer
and make a copy of the the return address inside the stack frame.
The return address that is located in the stack frame may not be
the one used to return to the calling function. This will break the
function graph tracer.

The function graph tracer replaces the return address with a jump to a hook
function that can trace the exit of the function. If it only replaces
a copy, then the hook will not be called when the function returns.
Worse yet, when the parent function returns, the function graph tracer
will return back to the location of the child function which will
easily crash the kernel with weird results.

To see the problem, when i386 is compiled with -Os we get:

c106be03:       57                      push   %edi
c106be04:       8d 7c 24 08             lea    0x8(%esp),%edi
c106be08:       83 e4 e0                and    $0xffffffe0,%esp
c106be0b:       ff 77 fc                pushl  0xfffffffc(%edi)
c106be0e:       55                      push   %ebp
c106be0f:       89 e5                   mov    %esp,%ebp
c106be11:       57                      push   %edi
c106be12:       56                      push   %esi
c106be13:       53                      push   %ebx
c106be14:       81 ec 8c 00 00 00       sub    $0x8c,%esp
c106be1a:       e8 f5 57 fb ff          call   c1021614 <mcount>

When it is compiled with -O2 instead we get:

c10896f0:       55                      push   %ebp
c10896f1:       89 e5                   mov    %esp,%ebp
c10896f3:       83 ec 28                sub    $0x28,%esp
c10896f6:       89 5d f4                mov    %ebx,0xfffffff4(%ebp)
c10896f9:       89 75 f8                mov    %esi,0xfffffff8(%ebp)
c10896fc:       89 7d fc                mov    %edi,0xfffffffc(%ebp)
c10896ff:       e8 d0 08 fa ff          call   c1029fd4 <mcount>

The compile with -Os will align the stack pointer then set up the
frame pointer (%ebp), and it copies the return address back into
the stack frame. The change to the return address in mcount is done
to the copy and not the real place holder of the return address.

Then compile with -O2 sets up the frame pointer first, this makes
the change to the return address by mcount affect where the function
will jump on exit.

Reported-by: Jake Edge <jake@lwn.net>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/Kconfig |    1 +
 1 files changed, 1 insertions(+), 0 deletions(-)

diff --git a/kernel/trace/Kconfig b/kernel/trace/Kconfig
index 4a13e5a..1eac852 100644
--- a/kernel/trace/Kconfig
+++ b/kernel/trace/Kconfig
@@ -121,6 +121,7 @@ config FUNCTION_GRAPH_TRACER
 	bool "Kernel Function Graph Tracer"
 	depends on HAVE_FUNCTION_GRAPH_TRACER
 	depends on FUNCTION_TRACER
+	depends on !X86_32 || !CC_OPTIMIZE_FOR_SIZE
 	default y
 	help
 	  Enable the kernel to trace a function at both its return
-- 
1.6.3.1

-- 

[PATCH 2/2] function-graph: add stack frame test

[Steven Rostedt]

[-- Attachment #1: 0002-function-graph-add-stack-frame-test.patch --]
[-- Type: text/plain, Size: 9935 bytes --]

From: Steven Rostedt <srostedt@redhat.com>

In case gcc does something funny with the stack frames, or the return
from function code, we would like to detect that.

An arch may implement passing of a variable that is unique to the
function and can be saved on entering a function and can be tested
when exiting the function. Usually the frame pointer can be used for
this purpose.

This patch also implements this for x86. Where it passes in the stack
frame of the parent function, and will test that frame on exit.

There was a case in x86_32 with optimize for size (-Os) where, for a
few functions, gcc would align the stack frame and place a copy of the
return address into it. The function graph tracer modified the copy and
not the actual return address. On return from the funtion, it did not go
to the tracer hook, but returned to the parent. This broke the function
graph tracer, because the return of the parent (where gcc did not do
this funky manipulation) returned to the location that the child function
was suppose to. This caused strange kernel crashes.

This test detected the problem and pointed out where the issue was.

This modifies the parameters of one of the functions that the arch
specific code calls, so it includes changes to arch code to accommodate
the new prototype.

Note, I notice that the parsic arch implements its own push_return_trace.
This is now a generic function and the ftrace_push_return_trace should be
used instead. This patch does not touch that code.

Cc: Benjamin Herrenschmidt <benh@kernel.crashing.org>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Heiko Carstens <heiko.carstens@de.ibm.com>
Cc: Martin Schwidefsky <schwidefsky@de.ibm.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Helge Deller <deller@gmx.de>
Cc: Kyle McMartin <kyle@mcmartin.ca>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 arch/powerpc/kernel/ftrace.c         |    2 +-
 arch/s390/kernel/ftrace.c            |    2 +-
 arch/x86/Kconfig                     |    1 +
 arch/x86/kernel/entry_32.S           |    2 +
 arch/x86/kernel/entry_64.S           |    2 +
 arch/x86/kernel/ftrace.c             |    6 +++-
 include/linux/ftrace.h               |    4 ++-
 kernel/trace/Kconfig                 |    7 ++++++
 kernel/trace/trace_functions_graph.c |   36 ++++++++++++++++++++++++++++++---
 9 files changed, 53 insertions(+), 9 deletions(-)

diff --git a/arch/powerpc/kernel/ftrace.c b/arch/powerpc/kernel/ftrace.c
index 2d182f1..58d6a61 100644
--- a/arch/powerpc/kernel/ftrace.c
+++ b/arch/powerpc/kernel/ftrace.c
@@ -605,7 +605,7 @@ void prepare_ftrace_return(unsigned long *parent, unsigned long self_addr)
 		return;
 	}
 
-	if (ftrace_push_return_trace(old, self_addr, &trace.depth) == -EBUSY) {
+	if (ftrace_push_return_trace(old, self_addr, &trace.depth, 0) == -EBUSY) {
 		*parent = old;
 		return;
 	}
diff --git a/arch/s390/kernel/ftrace.c b/arch/s390/kernel/ftrace.c
index 82ddfd3..3e298e6 100644
--- a/arch/s390/kernel/ftrace.c
+++ b/arch/s390/kernel/ftrace.c
@@ -190,7 +190,7 @@ unsigned long prepare_ftrace_return(unsigned long ip, unsigned long parent)
 		goto out;
 	if (unlikely(atomic_read(&current->tracing_graph_pause)))
 		goto out;
-	if (ftrace_push_return_trace(parent, ip, &trace.depth) == -EBUSY)
+	if (ftrace_push_return_trace(parent, ip, &trace.depth, 0) == -EBUSY)
 		goto out;
 	trace.func = ftrace_mcount_call_adjust(ip) & PSW_ADDR_INSN;
 	/* Only trace if the calling function expects to. */
diff --git a/arch/x86/Kconfig b/arch/x86/Kconfig
index 356d2ec..fcf12af 100644
--- a/arch/x86/Kconfig
+++ b/arch/x86/Kconfig
@@ -33,6 +33,7 @@ config X86
 	select HAVE_DYNAMIC_FTRACE
 	select HAVE_FUNCTION_TRACER
 	select HAVE_FUNCTION_GRAPH_TRACER
+	select HAVE_FUNCTION_GRAPH_FP_TEST
 	select HAVE_FUNCTION_TRACE_MCOUNT_TEST
 	select HAVE_FTRACE_NMI_ENTER if DYNAMIC_FTRACE
 	select HAVE_FTRACE_SYSCALLS
diff --git a/arch/x86/kernel/entry_32.S b/arch/x86/kernel/entry_32.S
index c929add..0d4b285 100644
--- a/arch/x86/kernel/entry_32.S
+++ b/arch/x86/kernel/entry_32.S
@@ -1154,6 +1154,7 @@ ENTRY(ftrace_graph_caller)
 	pushl %edx
 	movl 0xc(%esp), %edx
 	lea 0x4(%ebp), %eax
+	movl (%ebp), %ecx
 	subl $MCOUNT_INSN_SIZE, %edx
 	call prepare_ftrace_return
 	popl %edx
@@ -1168,6 +1169,7 @@ return_to_handler:
 	pushl %eax
 	pushl %ecx
 	pushl %edx
+	movl %ebp, %eax
 	call ftrace_return_to_handler
 	movl %eax, 0xc(%esp)
 	popl %edx
diff --git a/arch/x86/kernel/entry_64.S b/arch/x86/kernel/entry_64.S
index de74f0a..c251be7 100644
--- a/arch/x86/kernel/entry_64.S
+++ b/arch/x86/kernel/entry_64.S
@@ -135,6 +135,7 @@ ENTRY(ftrace_graph_caller)
 
 	leaq 8(%rbp), %rdi
 	movq 0x38(%rsp), %rsi
+	movq (%rbp), %rdx
 	subq $MCOUNT_INSN_SIZE, %rsi
 
 	call	prepare_ftrace_return
@@ -150,6 +151,7 @@ GLOBAL(return_to_handler)
 	/* Save the return values */
 	movq %rax, (%rsp)
 	movq %rdx, 8(%rsp)
+	movq %rbp, %rdi
 
 	call ftrace_return_to_handler
 
diff --git a/arch/x86/kernel/ftrace.c b/arch/x86/kernel/ftrace.c
index b79c553..d94e1ea 100644
--- a/arch/x86/kernel/ftrace.c
+++ b/arch/x86/kernel/ftrace.c
@@ -408,7 +408,8 @@ int ftrace_disable_ftrace_graph_caller(void)
  * Hook the return address and push it in the stack of return addrs
  * in current thread info.
  */
-void prepare_ftrace_return(unsigned long *parent, unsigned long self_addr)
+void prepare_ftrace_return(unsigned long *parent, unsigned long self_addr,
+			   unsigned long frame_pointer)
 {
 	unsigned long old;
 	int faulted;
@@ -453,7 +454,8 @@ void prepare_ftrace_return(unsigned long *parent, unsigned long self_addr)
 		return;
 	}
 
-	if (ftrace_push_return_trace(old, self_addr, &trace.depth) == -EBUSY) {
+	if (ftrace_push_return_trace(old, self_addr, &trace.depth,
+		    frame_pointer) == -EBUSY) {
 		*parent = old;
 		return;
 	}
diff --git a/include/linux/ftrace.h b/include/linux/ftrace.h
index 39b95c5..dc3b132 100644
--- a/include/linux/ftrace.h
+++ b/include/linux/ftrace.h
@@ -362,6 +362,7 @@ struct ftrace_ret_stack {
 	unsigned long func;
 	unsigned long long calltime;
 	unsigned long long subtime;
+	unsigned long fp;
 };
 
 /*
@@ -372,7 +373,8 @@ struct ftrace_ret_stack {
 extern void return_to_handler(void);
 
 extern int
-ftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth);
+ftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth,
+			 unsigned long frame_pointer);
 
 /*
  * Sometimes we don't want to trace a function with the function
diff --git a/kernel/trace/Kconfig b/kernel/trace/Kconfig
index 1eac852..b17ed87 100644
--- a/kernel/trace/Kconfig
+++ b/kernel/trace/Kconfig
@@ -18,6 +18,13 @@ config HAVE_FUNCTION_TRACER
 config HAVE_FUNCTION_GRAPH_TRACER
 	bool
 
+config HAVE_FUNCTION_GRAPH_FP_TEST
+	bool
+	help
+	 An arch may pass in a unique value (frame pointer) to both the
+	 entering and exiting of a function. On exit, the value is compared
+	 and if it does not match, then it will panic the kernel.
+
 config HAVE_FUNCTION_TRACE_MCOUNT_TEST
 	bool
 	help
diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
index 8b59241..d2249ab 100644
--- a/kernel/trace/trace_functions_graph.c
+++ b/kernel/trace/trace_functions_graph.c
@@ -57,7 +57,8 @@ static struct tracer_flags tracer_flags = {
 
 /* Add a function return address to the trace stack on thread info.*/
 int
-ftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth)
+ftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth,
+			 unsigned long frame_pointer)
 {
 	unsigned long long calltime;
 	int index;
@@ -85,6 +86,7 @@ ftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth)
 	current->ret_stack[index].func = func;
 	current->ret_stack[index].calltime = calltime;
 	current->ret_stack[index].subtime = 0;
+	current->ret_stack[index].fp = frame_pointer;
 	*depth = index;
 
 	return 0;
@@ -92,7 +94,8 @@ ftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth)
 
 /* Retrieve a function return address to the trace stack on thread info.*/
 static void
-ftrace_pop_return_trace(struct ftrace_graph_ret *trace, unsigned long *ret)
+ftrace_pop_return_trace(struct ftrace_graph_ret *trace, unsigned long *ret,
+			unsigned long frame_pointer)
 {
 	int index;
 
@@ -106,6 +109,31 @@ ftrace_pop_return_trace(struct ftrace_graph_ret *trace, unsigned long *ret)
 		return;
 	}
 
+#ifdef CONFIG_HAVE_FUNCTION_GRAPH_FP_TEST
+	/*
+	 * The arch may choose to record the frame pointer used
+	 * and check it here to make sure that it is what we expect it
+	 * to be. If gcc does not set the place holder of the return
+	 * address in the frame pointer, and does a copy instead, then
+	 * the function graph trace will fail. This test detects this
+	 * case.
+	 *
+	 * Currently, x86_32 with optimize for size (-Os) makes the latest
+	 * gcc do the above.
+	 */
+	if (unlikely(current->ret_stack[index].fp != frame_pointer)) {
+		ftrace_graph_stop();
+		WARN(1, "Bad frame pointer: expected %lx, received %lx\n"
+		     "  from func %pF return to %lx\n",
+		     current->ret_stack[index].fp,
+		     frame_pointer,
+		     (void *)current->ret_stack[index].func,
+		     current->ret_stack[index].ret);
+		*ret = (unsigned long)panic;
+		return;
+	}
+#endif
+
 	*ret = current->ret_stack[index].ret;
 	trace->func = current->ret_stack[index].func;
 	trace->calltime = current->ret_stack[index].calltime;
@@ -117,12 +145,12 @@ ftrace_pop_return_trace(struct ftrace_graph_ret *trace, unsigned long *ret)
  * Send the trace to the ring-buffer.
  * @return the original return address.
  */
-unsigned long ftrace_return_to_handler(void)
+unsigned long ftrace_return_to_handler(unsigned long frame_pointer)
 {
 	struct ftrace_graph_ret trace;
 	unsigned long ret;
 
-	ftrace_pop_return_trace(&trace, &ret);
+	ftrace_pop_return_trace(&trace, &ret, frame_pointer);
 	trace.rettime = trace_clock_local();
 	ftrace_graph_return(&trace);
 	barrier();
-- 
1.6.3.1

-- 

Re: [PATCH 2/2] function-graph: add stack frame test

[Frederic Weisbecker]

On Thu, Jun 18, 2009 at 06:44:11PM -0400, Steven Rostedt wrote:
> From: Steven Rostedt <srostedt@redhat.com>
> 
> In case gcc does something funny with the stack frames, or the return
> from function code, we would like to detect that.
> 
> An arch may implement passing of a variable that is unique to the
> function and can be saved on entering a function and can be tested
> when exiting the function. Usually the frame pointer can be used for
> this purpose.
> 
> This patch also implements this for x86. Where it passes in the stack
> frame of the parent function, and will test that frame on exit.
> 
> There was a case in x86_32 with optimize for size (-Os) where, for a
> few functions, gcc would align the stack frame and place a copy of the
> return address into it. The function graph tracer modified the copy and
> not the actual return address. On return from the funtion, it did not go
> to the tracer hook, but returned to the parent. This broke the function
> graph tracer, because the return of the parent (where gcc did not do
> this funky manipulation) returned to the location that the child function
> was suppose to. This caused strange kernel crashes.
> 
> This test detected the problem and pointed out where the issue was.
> 
> This modifies the parameters of one of the functions that the arch
> specific code calls, so it includes changes to arch code to accommodate
> the new prototype.
> 
> Note, I notice that the parsic arch implements its own push_return_trace.
> This is now a generic function and the ftrace_push_return_trace should be
> used instead. This patch does not touch that code.
> 
> Cc: Benjamin Herrenschmidt <benh@kernel.crashing.org>
> Cc: Paul Mackerras <paulus@samba.org>
> Cc: Heiko Carstens <heiko.carstens@de.ibm.com>
> Cc: Martin Schwidefsky <schwidefsky@de.ibm.com>
> Cc: Frederic Weisbecker <fweisbec@gmail.com>
> Cc: Helge Deller <deller@gmx.de>
> Cc: Kyle McMartin <kyle@mcmartin.ca>
> Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
> ---
>  arch/powerpc/kernel/ftrace.c         |    2 +-
>  arch/s390/kernel/ftrace.c            |    2 +-
>  arch/x86/Kconfig                     |    1 +
>  arch/x86/kernel/entry_32.S           |    2 +
>  arch/x86/kernel/entry_64.S           |    2 +
>  arch/x86/kernel/ftrace.c             |    6 +++-
>  include/linux/ftrace.h               |    4 ++-
>  kernel/trace/Kconfig                 |    7 ++++++
>  kernel/trace/trace_functions_graph.c |   36 ++++++++++++++++++++++++++++++---
>  9 files changed, 53 insertions(+), 9 deletions(-)
> 
> diff --git a/arch/powerpc/kernel/ftrace.c b/arch/powerpc/kernel/ftrace.c
> index 2d182f1..58d6a61 100644
> --- a/arch/powerpc/kernel/ftrace.c
> +++ b/arch/powerpc/kernel/ftrace.c
> @@ -605,7 +605,7 @@ void prepare_ftrace_return(unsigned long *parent, unsigned long self_addr)
>  		return;
>  	}
>  
> -	if (ftrace_push_return_trace(old, self_addr, &trace.depth) == -EBUSY) {
> +	if (ftrace_push_return_trace(old, self_addr, &trace.depth, 0) == -EBUSY) {
>  		*parent = old;
>  		return;
>  	}
> diff --git a/arch/s390/kernel/ftrace.c b/arch/s390/kernel/ftrace.c
> index 82ddfd3..3e298e6 100644
> --- a/arch/s390/kernel/ftrace.c
> +++ b/arch/s390/kernel/ftrace.c
> @@ -190,7 +190,7 @@ unsigned long prepare_ftrace_return(unsigned long ip, unsigned long parent)
>  		goto out;
>  	if (unlikely(atomic_read(&current->tracing_graph_pause)))
>  		goto out;
> -	if (ftrace_push_return_trace(parent, ip, &trace.depth) == -EBUSY)
> +	if (ftrace_push_return_trace(parent, ip, &trace.depth, 0) == -EBUSY)
>  		goto out;
>  	trace.func = ftrace_mcount_call_adjust(ip) & PSW_ADDR_INSN;
>  	/* Only trace if the calling function expects to. */
> diff --git a/arch/x86/Kconfig b/arch/x86/Kconfig
> index 356d2ec..fcf12af 100644
> --- a/arch/x86/Kconfig
> +++ b/arch/x86/Kconfig
> @@ -33,6 +33,7 @@ config X86
>  	select HAVE_DYNAMIC_FTRACE
>  	select HAVE_FUNCTION_TRACER
>  	select HAVE_FUNCTION_GRAPH_TRACER
> +	select HAVE_FUNCTION_GRAPH_FP_TEST
>  	select HAVE_FUNCTION_TRACE_MCOUNT_TEST
>  	select HAVE_FTRACE_NMI_ENTER if DYNAMIC_FTRACE
>  	select HAVE_FTRACE_SYSCALLS
> diff --git a/arch/x86/kernel/entry_32.S b/arch/x86/kernel/entry_32.S
> index c929add..0d4b285 100644
> --- a/arch/x86/kernel/entry_32.S
> +++ b/arch/x86/kernel/entry_32.S
> @@ -1154,6 +1154,7 @@ ENTRY(ftrace_graph_caller)
>  	pushl %edx
>  	movl 0xc(%esp), %edx
>  	lea 0x4(%ebp), %eax
> +	movl (%ebp), %ecx
>  	subl $MCOUNT_INSN_SIZE, %edx
>  	call prepare_ftrace_return
>  	popl %edx
> @@ -1168,6 +1169,7 @@ return_to_handler:
>  	pushl %eax
>  	pushl %ecx
>  	pushl %edx
> +	movl %ebp, %eax


Ah, I see...



>  	call ftrace_return_to_handler
>  	movl %eax, 0xc(%esp)
>  	popl %edx
> diff --git a/arch/x86/kernel/entry_64.S b/arch/x86/kernel/entry_64.S
> index de74f0a..c251be7 100644
> --- a/arch/x86/kernel/entry_64.S
> +++ b/arch/x86/kernel/entry_64.S
> @@ -135,6 +135,7 @@ ENTRY(ftrace_graph_caller)
>  
>  	leaq 8(%rbp), %rdi
>  	movq 0x38(%rsp), %rsi
> +	movq (%rbp), %rdx
>  	subq $MCOUNT_INSN_SIZE, %rsi
>  
>  	call	prepare_ftrace_return
> @@ -150,6 +151,7 @@ GLOBAL(return_to_handler)
>  	/* Save the return values */
>  	movq %rax, (%rsp)
>  	movq %rdx, 8(%rsp)
> +	movq %rbp, %rdi
>  
>  	call ftrace_return_to_handler
>  
> diff --git a/arch/x86/kernel/ftrace.c b/arch/x86/kernel/ftrace.c
> index b79c553..d94e1ea 100644
> --- a/arch/x86/kernel/ftrace.c
> +++ b/arch/x86/kernel/ftrace.c
> @@ -408,7 +408,8 @@ int ftrace_disable_ftrace_graph_caller(void)
>   * Hook the return address and push it in the stack of return addrs
>   * in current thread info.
>   */
> -void prepare_ftrace_return(unsigned long *parent, unsigned long self_addr)
> +void prepare_ftrace_return(unsigned long *parent, unsigned long self_addr,
> +			   unsigned long frame_pointer)
>  {
>  	unsigned long old;
>  	int faulted;
> @@ -453,7 +454,8 @@ void prepare_ftrace_return(unsigned long *parent, unsigned long self_addr)
>  		return;
>  	}
>  
> -	if (ftrace_push_return_trace(old, self_addr, &trace.depth) == -EBUSY) {
> +	if (ftrace_push_return_trace(old, self_addr, &trace.depth,
> +		    frame_pointer) == -EBUSY) {
>  		*parent = old;
>  		return;
>  	}
> diff --git a/include/linux/ftrace.h b/include/linux/ftrace.h
> index 39b95c5..dc3b132 100644
> --- a/include/linux/ftrace.h
> +++ b/include/linux/ftrace.h
> @@ -362,6 +362,7 @@ struct ftrace_ret_stack {
>  	unsigned long func;
>  	unsigned long long calltime;
>  	unsigned long long subtime;
> +	unsigned long fp;
>  };
>  
>  /*
> @@ -372,7 +373,8 @@ struct ftrace_ret_stack {
>  extern void return_to_handler(void);
>  
>  extern int
> -ftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth);
> +ftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth,
> +			 unsigned long frame_pointer);
>  
>  /*
>   * Sometimes we don't want to trace a function with the function
> diff --git a/kernel/trace/Kconfig b/kernel/trace/Kconfig
> index 1eac852..b17ed87 100644
> --- a/kernel/trace/Kconfig
> +++ b/kernel/trace/Kconfig
> @@ -18,6 +18,13 @@ config HAVE_FUNCTION_TRACER
>  config HAVE_FUNCTION_GRAPH_TRACER
>  	bool
>  
> +config HAVE_FUNCTION_GRAPH_FP_TEST
> +	bool
> +	help
> +	 An arch may pass in a unique value (frame pointer) to both the
> +	 entering and exiting of a function. On exit, the value is compared
> +	 and if it does not match, then it will panic the kernel.
> +
>  config HAVE_FUNCTION_TRACE_MCOUNT_TEST
>  	bool
>  	help
> diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
> index 8b59241..d2249ab 100644
> --- a/kernel/trace/trace_functions_graph.c
> +++ b/kernel/trace/trace_functions_graph.c
> @@ -57,7 +57,8 @@ static struct tracer_flags tracer_flags = {
>  
>  /* Add a function return address to the trace stack on thread info.*/
>  int
> -ftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth)
> +ftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth,
> +			 unsigned long frame_pointer)
>  {
>  	unsigned long long calltime;
>  	int index;
> @@ -85,6 +86,7 @@ ftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth)
>  	current->ret_stack[index].func = func;
>  	current->ret_stack[index].calltime = calltime;
>  	current->ret_stack[index].subtime = 0;
> +	current->ret_stack[index].fp = frame_pointer;
>  	*depth = index;
>  
>  	return 0;
> @@ -92,7 +94,8 @@ ftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth)
>  
>  /* Retrieve a function return address to the trace stack on thread info.*/
>  static void
> -ftrace_pop_return_trace(struct ftrace_graph_ret *trace, unsigned long *ret)
> +ftrace_pop_return_trace(struct ftrace_graph_ret *trace, unsigned long *ret,
> +			unsigned long frame_pointer)
>  {
>  	int index;
>  
> @@ -106,6 +109,31 @@ ftrace_pop_return_trace(struct ftrace_graph_ret *trace, unsigned long *ret)
>  		return;
>  	}
>  
> +#ifdef CONFIG_HAVE_FUNCTION_GRAPH_FP_TEST
> +	/*
> +	 * The arch may choose to record the frame pointer used
> +	 * and check it here to make sure that it is what we expect it
> +	 * to be. If gcc does not set the place holder of the return
> +	 * address in the frame pointer, and does a copy instead, then
> +	 * the function graph trace will fail. This test detects this
> +	 * case.
> +	 *
> +	 * Currently, x86_32 with optimize for size (-Os) makes the latest
> +	 * gcc do the above.
> +	 */
> +	if (unlikely(current->ret_stack[index].fp != frame_pointer)) {
> +		ftrace_graph_stop();
> +		WARN(1, "Bad frame pointer: expected %lx, received %lx\n"
> +		     "  from func %pF return to %lx\n",
> +		     current->ret_stack[index].fp,
> +		     frame_pointer,
> +		     (void *)current->ret_stack[index].func,
> +		     current->ret_stack[index].ret);
> +		*ret = (unsigned long)panic;
> +		return;
> +	}
> +#endif


Nice thing! I don't see another solution to detect this problem for
now.

BTW, does this weird copy of return address in the stack only occur
in few functions or most of them?

Acked-by: Frederic Weisbecker <fweisbec@gmail.com>



> +
>  	*ret = current->ret_stack[index].ret;
>  	trace->func = current->ret_stack[index].func;
>  	trace->calltime = current->ret_stack[index].calltime;
> @@ -117,12 +145,12 @@ ftrace_pop_return_trace(struct ftrace_graph_ret *trace, unsigned long *ret)
>   * Send the trace to the ring-buffer.
>   * @return the original return address.
>   */
> -unsigned long ftrace_return_to_handler(void)
> +unsigned long ftrace_return_to_handler(unsigned long frame_pointer)
>  {
>  	struct ftrace_graph_ret trace;
>  	unsigned long ret;
>  
> -	ftrace_pop_return_trace(&trace, &ret);
> +	ftrace_pop_return_trace(&trace, &ret, frame_pointer);
>  	trace.rettime = trace_clock_local();
>  	ftrace_graph_return(&trace);
>  	barrier();
> -- 
> 1.6.3.1
> 
> -- 

Re: [PATCH 1/2] function-graph: disable when both x86_32 and optimize for size are configured

[Ingo Molnar]

* Steven Rostedt <rostedt@goodmis.org> wrote:

> diff --git a/kernel/trace/Kconfig b/kernel/trace/Kconfig
> index 4a13e5a..1eac852 100644
> --- a/kernel/trace/Kconfig
> +++ b/kernel/trace/Kconfig
> @@ -121,6 +121,7 @@ config FUNCTION_GRAPH_TRACER
>  	bool "Kernel Function Graph Tracer"
>  	depends on HAVE_FUNCTION_GRAPH_TRACER
>  	depends on FUNCTION_TRACER
> +	depends on !X86_32 || !CC_OPTIMIZE_FOR_SIZE
>  	default y

Hm, nice fix, but this is a quite nasty constraint - distros like to 
enable CC_OPTIMIZE_FOR_SIZE as it neatly trims the kernel's size by 
about 30%.

Just in case you have not checked yet: is there no way to turn off 
the specific gcc optimization that causes this? Or is it -Os itself 
that does this optimization?

	Ingo

Re: [PATCH 0/2] [GIT PULL][for 2.6.31] function graph gcc issue

[Ingo Molnar]

* Steven Rostedt <rostedt@goodmis.org> wrote:

> Ingo,
> 
> The bug I spent two days debugging that Jake found was due to gcc 
> making a copy of the return address into the stack frame and not 
> using it to actually return. The function graph tracer would 
> modify the copy and not the actual location that was used to 
> return to. Thus the accounting of the function graph tracer was 
> corrupted and a nasty crash followed.
> 
> I found that 32bit x86 when compiled with optimize for size caused 
> this issue in the latest gcc (4.4.0). The first patch makes the 
> function graph tracer depend on !X86_32 || !CC_OPTIMIZE_FOR_SIZE. 
> This way we keep from getting into trouble with a know 
> configuration that breaks.
> 
> Then next patch adds to x86 (both 32bit and 64bit) a test of the 
> frame pointer to make sure that the return actually goes to where 
> we expect it to.
> 
> When debugging Jakes bug, The first instance was easy to find. It was
> the timer_stats_update_stats that had a forced cacheline struct as a local.
> I changed that and it seemed to fix the boot up test. When I enabled
> function graph at run time, the system crashed again, but this time the
> crash was hard to find where the issue was. I wrote up this test (patch 2)
> and I found the problem immediately. In case gcc changes, we want to be
> able to detect it right away before the tracer does anything dangerous.
> 
> 
> Please pull the latest tip/tracing/urgent-1 tree, which can be found at:
> 
>   git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-2.6-trace.git
> tip/tracing/urgent-1
> 
> 
> Steven Rostedt (2):
>       function-graph: disable when both x86_32 and optimize for size are configured
>       function-graph: add stack frame test
> 
> ----
>  arch/powerpc/kernel/ftrace.c         |    2 +-
>  arch/s390/kernel/ftrace.c            |    2 +-
>  arch/x86/Kconfig                     |    1 +
>  arch/x86/kernel/entry_32.S           |    2 +
>  arch/x86/kernel/entry_64.S           |    2 +
>  arch/x86/kernel/ftrace.c             |    6 +++-
>  include/linux/ftrace.h               |    4 ++-
>  kernel/trace/Kconfig                 |    8 +++++++
>  kernel/trace/trace_functions_graph.c |   36 ++++++++++++++++++++++++++++++---
>  9 files changed, 54 insertions(+), 9 deletions(-)
> -- 

Pulled, thanks Steve!

What a nasty bug ...

	Ingo

Re: [PATCH 1/2] function-graph: disable when both x86_32 and optimize for size are configured

[Steven Rostedt]

On Sat, 20 Jun 2009, Ingo Molnar wrote:

> 
> * Steven Rostedt <rostedt@goodmis.org> wrote:
> 
> > diff --git a/kernel/trace/Kconfig b/kernel/trace/Kconfig
> > index 4a13e5a..1eac852 100644
> > --- a/kernel/trace/Kconfig
> > +++ b/kernel/trace/Kconfig
> > @@ -121,6 +121,7 @@ config FUNCTION_GRAPH_TRACER
> >  	bool "Kernel Function Graph Tracer"
> >  	depends on HAVE_FUNCTION_GRAPH_TRACER
> >  	depends on FUNCTION_TRACER
> > +	depends on !X86_32 || !CC_OPTIMIZE_FOR_SIZE
> >  	default y
> 
> Hm, nice fix, but this is a quite nasty constraint - distros like to 
> enable CC_OPTIMIZE_FOR_SIZE as it neatly trims the kernel's size by 
> about 30%.
> 
> Just in case you have not checked yet: is there no way to turn off 
> the specific gcc optimization that causes this? Or is it -Os itself 
> that does this optimization?

It seems to me that -Os causes it for i386. I did a make V=1 to capture 
how the files in question were being compiled, and tried various disabling 
of flags. -Os was the only one to make a difference. :-(

-- Steve

Re: [PATCH 1/2] function-graph: disable when both x86_32 and optimize for size are configured

[Ingo Molnar]

* Steven Rostedt <rostedt@goodmis.org> wrote:

> On Sat, 20 Jun 2009, Ingo Molnar wrote:
> 
> > 
> > * Steven Rostedt <rostedt@goodmis.org> wrote:
> > 
> > > diff --git a/kernel/trace/Kconfig b/kernel/trace/Kconfig
> > > index 4a13e5a..1eac852 100644
> > > --- a/kernel/trace/Kconfig
> > > +++ b/kernel/trace/Kconfig
> > > @@ -121,6 +121,7 @@ config FUNCTION_GRAPH_TRACER
> > >  	bool "Kernel Function Graph Tracer"
> > >  	depends on HAVE_FUNCTION_GRAPH_TRACER
> > >  	depends on FUNCTION_TRACER
> > > +	depends on !X86_32 || !CC_OPTIMIZE_FOR_SIZE
> > >  	default y
> > 
> > Hm, nice fix, but this is a quite nasty constraint - distros like to 
> > enable CC_OPTIMIZE_FOR_SIZE as it neatly trims the kernel's size by 
> > about 30%.
> > 
> > Just in case you have not checked yet: is there no way to turn off 
> > the specific gcc optimization that causes this? Or is it -Os itself 
> > that does this optimization?
> 
> It seems to me that -Os causes it for i386. I did a make V=1 to 
> capture how the files in question were being compiled, and tried 
> various disabling of flags. -Os was the only one to make a 
> difference. :-(

oh well. I think GCC should be fixed/improved to not do this 
particular (rather narrow looking) optimization if -pg is specified 
too.

	Ingo