[PATCH 0/2] ftrace: fixes for tip

[PATCH 0/2] ftrace: fixes for tip

[Steven Rostedt]

Ingo,

These two patches are fixes. The first cleans up the stack_trace
output to print 0's for the return_to_handler function.

The second is the nasty race we have been hitting. My patches must
have made the race window bigger for you since the bug was there
before. It is a nasty race in the fork code. More info in the change log
of that patch.

The following patches are in:

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

    branch: tip/devel


Steven Rostedt (2):
      trace: fix output of stack trace
      ftrace: fix race in function graph during fork

----
 kernel/fork.c              |    9 ++++++---
 kernel/trace/trace_stack.c |    5 ++++-
 2 files changed, 10 insertions(+), 4 deletions(-)

-- 

[PATCH 1/2] trace: fix output of stack trace

[Steven Rostedt]

[-- Attachment #1: 0001-trace-fix-output-of-stack-trace.patch --]
[-- Type: text/plain, Size: 1104 bytes --]

From: Steven Rostedt <srostedt@redhat.com>

Impact: fix to output of stack trace

If a function is not found in the stack of the stack tracer, the
number printed is quite strange. This fixes the algorithm to handle
missing functions better.

Signed-off-by: Steven Rostedt <srostedt@redhat.com>
---
 kernel/trace/trace_stack.c |    5 ++++-
 1 files changed, 4 insertions(+), 1 deletions(-)

diff --git a/kernel/trace/trace_stack.c b/kernel/trace/trace_stack.c
index 06a1611..0b863f2 100644
--- a/kernel/trace/trace_stack.c
+++ b/kernel/trace/trace_stack.c
@@ -78,6 +78,7 @@ static inline void check_stack(void)
 	 * on a new max, so it is far from a fast path.
 	 */
 	while (i < max_stack_trace.nr_entries) {
+		int found = 0;
 
 		stack_dump_index[i] = this_size;
 		p = start;
@@ -86,12 +87,14 @@ static inline void check_stack(void)
 			if (*p == stack_dump_trace[i]) {
 				this_size = stack_dump_index[i++] =
 					(top - p) * sizeof(unsigned long);
+				found = 1;
 				/* Start the search from here */
 				start = p + 1;
 			}
 		}
 
-		i++;
+		if (!found)
+			i++;
 	}
 
  out:
-- 
1.5.6.5

-- 

[PATCH 2/2] ftrace: fix race in function graph during fork

[Steven Rostedt]

[-- Attachment #1: 0002-ftrace-fix-race-in-function-graph-during-fork.patch --]
[-- Type: text/plain, Size: 2200 bytes --]

From: Steven Rostedt <srostedt@redhat.com>

Impact: fix

There is a nasy race in startup of a new process running the
function graph tracer. In fork.c:

	total_forks++;
	spin_unlock(&current->sighand->siglock);
	write_unlock_irq(&tasklist_lock);
	ftrace_graph_init_task(p);
	proc_fork_connector(p);
	cgroup_post_fork(p);
	return p;

The new task is free to run as soon as the tasklist_lock is released.
This is before the ftrace_graph_init_task. If the task does run
it will be using the same ret_stack and curr_ret_stack as the parent.
This will cause horrible crashes that are nasty to debug.

This patch moves the ftrace_graph_init_task to just after the alloc_pid
code. This fixes the above race.

Signed-off-by: Steven Rostedt <srostedt@redhat.com>
---
 kernel/fork.c |    9 ++++++---
 1 files changed, 6 insertions(+), 3 deletions(-)

diff --git a/kernel/fork.c b/kernel/fork.c
index afb376d..91cca76 100644
--- a/kernel/fork.c
+++ b/kernel/fork.c
@@ -1142,6 +1142,8 @@ static struct task_struct *copy_process(unsigned long clone_flags,
 		}
 	}
 
+	ftrace_graph_init_task(p);
+
 	p->pid = pid_nr(pid);
 	p->tgid = p->pid;
 	if (clone_flags & CLONE_THREAD)
@@ -1150,7 +1152,7 @@ static struct task_struct *copy_process(unsigned long clone_flags,
 	if (current->nsproxy != p->nsproxy) {
 		retval = ns_cgroup_clone(p, pid);
 		if (retval)
-			goto bad_fork_free_pid;
+			goto bad_fork_free_graph;
 	}
 
 	p->set_child_tid = (clone_flags & CLONE_CHILD_SETTID) ? child_tidptr : NULL;
@@ -1243,7 +1245,7 @@ static struct task_struct *copy_process(unsigned long clone_flags,
 		spin_unlock(&current->sighand->siglock);
 		write_unlock_irq(&tasklist_lock);
 		retval = -ERESTARTNOINTR;
-		goto bad_fork_free_pid;
+		goto bad_fork_free_graph;
 	}
 
 	if (clone_flags & CLONE_THREAD) {
@@ -1276,11 +1278,12 @@ static struct task_struct *copy_process(unsigned long clone_flags,
 	total_forks++;
 	spin_unlock(&current->sighand->siglock);
 	write_unlock_irq(&tasklist_lock);
-	ftrace_graph_init_task(p);
 	proc_fork_connector(p);
 	cgroup_post_fork(p);
 	return p;
 
+bad_fork_free_graph:
+	ftrace_graph_exit_task(p);
 bad_fork_free_pid:
 	if (pid != &init_struct_pid)
 		free_pid(pid);
-- 
1.5.6.5

-- 

Re: [PATCH 0/2] ftrace: fixes for tip

[Ingo Molnar]

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

> Ingo,
> 
> These two patches are fixes. The first cleans up the stack_trace
> output to print 0's for the return_to_handler function.
> 
> The second is the nasty race we have been hitting. My patches must
> have made the race window bigger for you since the bug was there
> before. It is a nasty race in the fork code. More info in the change log
> of that patch.
> 
> The following patches are in:
> 
>   git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-2.6-trace.git
> 
>     branch: tip/devel
> 
> 
> Steven Rostedt (2):
>       trace: fix output of stack trace
>       ftrace: fix race in function graph during fork
> 
> ----
>  kernel/fork.c              |    9 ++++++---
>  kernel/trace/trace_stack.c |    5 ++++-
>  2 files changed, 10 insertions(+), 4 deletions(-)

pulled, thanks Steve! I think this should explain the crash i was seeing.

	Ingo

Re: [PATCH 2/2] ftrace: fix race in function graph during fork

[Frédéric Weisbecker]

2008/12/3 Steven Rostedt <rostedt@goodmis.org>:
> From: Steven Rostedt <srostedt@redhat.com>
>
> Impact: fix
>
> There is a nasy race in startup of a new process running the
> function graph tracer. In fork.c:
>
>        total_forks++;
>        spin_unlock(&current->sighand->siglock);
>        write_unlock_irq(&tasklist_lock);
>        ftrace_graph_init_task(p);
>        proc_fork_connector(p);
>        cgroup_post_fork(p);
>        return p;
>
> The new task is free to run as soon as the tasklist_lock is released.
> This is before the ftrace_graph_init_task. If the task does run
> it will be using the same ret_stack and curr_ret_stack as the parent.
> This will cause horrible crashes that are nasty to debug.
>
> This patch moves the ftrace_graph_init_task to just after the alloc_pid
> code. This fixes the above race.
>
> Signed-off-by: Steven Rostedt <srostedt@redhat.com>
> ---
>  kernel/fork.c |    9 ++++++---
>  1 files changed, 6 insertions(+), 3 deletions(-)
>
> diff --git a/kernel/fork.c b/kernel/fork.c
> index afb376d..91cca76 100644
> --- a/kernel/fork.c
> +++ b/kernel/fork.c
> @@ -1142,6 +1142,8 @@ static struct task_struct *copy_process(unsigned long clone_flags,
>                }
>        }
>
> +       ftrace_graph_init_task(p);
> +
>        p->pid = pid_nr(pid);
>        p->tgid = p->pid;
>        if (clone_flags & CLONE_THREAD)
> @@ -1150,7 +1152,7 @@ static struct task_struct *copy_process(unsigned long clone_flags,
>        if (current->nsproxy != p->nsproxy) {
>                retval = ns_cgroup_clone(p, pid);
>                if (retval)
> -                       goto bad_fork_free_pid;
> +                       goto bad_fork_free_graph;
>        }
>
>        p->set_child_tid = (clone_flags & CLONE_CHILD_SETTID) ? child_tidptr : NULL;
> @@ -1243,7 +1245,7 @@ static struct task_struct *copy_process(unsigned long clone_flags,
>                spin_unlock(&current->sighand->siglock);
>                write_unlock_irq(&tasklist_lock);
>                retval = -ERESTARTNOINTR;
> -               goto bad_fork_free_pid;
> +               goto bad_fork_free_graph;
>        }
>
>        if (clone_flags & CLONE_THREAD) {
> @@ -1276,11 +1278,12 @@ static struct task_struct *copy_process(unsigned long clone_flags,
>        total_forks++;
>        spin_unlock(&current->sighand->siglock);
>        write_unlock_irq(&tasklist_lock);
> -       ftrace_graph_init_task(p);
>        proc_fork_connector(p);
>        cgroup_post_fork(p);
>        return p;
>
> +bad_fork_free_graph:
> +       ftrace_graph_exit_task(p);
>  bad_fork_free_pid:
>        if (pid != &init_struct_pid)
>                free_pid(pid);


Very nice catch! Thanks.