ftrace: fixes for tip

PATCH In review Steven Rostedt 3 participants 5 messages Dec 3, 2008

Subsystems (4)

MM core Tracing Scheduler exec and binfmt

lore

Share & tools

lore

Steven Rostedt

author maintainer

2008-12-03 16:05 UTC #0 lore raw

cover ftrace: fixes for tip

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(-)

Steven Rostedt

author maintainer

2008-12-03 16:06 UTC #1 lore raw

PATCH 1/2 trace: fix output of stack trace

From: Steven Rostedt <[email protected]>

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 <[email protected]>

---
 kernel/trace/trace_stack.c |    5 ++++-
 1 files changed, 4 insertions(+), 1 deletions(-)

kernel/trace/trace_stack.c +4 -1

index 06a1611..0b863f2 100644
@@ -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:

Signature · 3 lines

1.5.6.5

--

Steven Rostedt

author maintainer

2008-12-03 16:06 UTC #2 lore raw

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

In reply to Steven Rostedt

From: Steven Rostedt <[email protected]>

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 <[email protected]>

---
 kernel/fork.c |    9 ++++++---
 1 files changed, 6 insertions(+), 3 deletions(-)

kernel/fork.c +6 -3

index afb376d..91cca76 100644
@@ -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);

Signature · 3 lines

1.5.6.5

--

Frédéric Weisbecker

2008-12-03 16:27 UTC #3 lore raw

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

2008/12/3 Steven Rostedt <[email protected]>:

Quoted 63 lines

From: Steven Rostedt <[email protected]>

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;

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 <[email protected]>

---
 kernel/fork.c |    9 ++++++---
 1 files changed, 6 insertions(+), 3 deletions(-)

kernel/fork.c +4 -2

index afb376d..91cca76 100644
@@ -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);

kernel/fork.c static struct task_struct *copy_process(unsigned long clone_flags, · line 1289

Quoted 10 lines

kernel/fork.c +2 -1

-       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.

Ingo Molnar

2008-12-03 16:16 UTC #4 lore raw

In reply to Steven Rostedt

Quoted 17 lines · 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

Quoted 8 lines

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