[PATCH 0/8] ftrace: updates

[PATCH 0/8] ftrace: updates

[Steven Rostedt]

Working on the ftrace.txt file proved to show some bugs with ftrace.
These are a list of patches that I have accumulated for ftrace that solve
those bugs (as well as other things).

-- Steve

[PATCH 1/8] ftrace: move sched_switch enable after markers

[Steven Rostedt]

[-- Attachment #1: ftrace-sched-enable-marker-last.patch --]
[-- Type: text/plain, Size: 2173 bytes --]

We have two markers now that are enabled on sched_switch. One that records
the context switching and the other that records task wake ups. Currently
we enable the tracing first and then set the markers. This causes some
confusing traces:

# tracer: sched_switch
#
#           TASK-PID   CPU#    TIMESTAMP  FUNCTION
#              | |      |          |         |
       trace-cmd-3973  [00]   115.834817:   3973:120:R   +     3:  0:S
       trace-cmd-3973  [01]   115.834910:   3973:120:R   +     6:  0:S
       trace-cmd-3973  [02]   115.834910:   3973:120:R   +     9:  0:S
       trace-cmd-3973  [03]   115.834910:   3973:120:R   +    12:  0:S
       trace-cmd-3973  [02]   115.834910:   3973:120:R   +     9:  0:S
          <idle>-0     [02]   115.834910:      0:140:R ==>  3973:120:R


Here we see that trace-cmd with PID 3973 wakes up task 9 but the next line
shows the idle task doing a context switch to task 3973.

Enabling the tracing to _after_ the markers are set creates a much saner
output:

# tracer: sched_switch
#
#           TASK-PID   CPU#    TIMESTAMP  FUNCTION
#              | |      |          |         |
          <idle>-0     [02]  7922.634225:      0:140:R ==>  4790:120:R
       trace-cmd-4789  [03]  7922.634225:      0:140:R   +  4790:120:R


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

Index: linux-tip.git/kernel/trace/trace_sched_switch.c
===================================================================
--- linux-tip.git.orig/kernel/trace/trace_sched_switch.c	2008-06-30 20:56:38.000000000 -0400
+++ linux-tip.git/kernel/trace/trace_sched_switch.c	2008-06-30 20:57:09.000000000 -0400
@@ -227,14 +227,14 @@ void tracing_stop_cmdline_record(void)
 static void start_sched_trace(struct trace_array *tr)
 {
 	sched_switch_reset(tr);
-	tracer_enabled = 1;
 	tracing_start_cmdline_record();
+	tracer_enabled = 1;
 }
 
 static void stop_sched_trace(struct trace_array *tr)
 {
-	tracing_stop_cmdline_record();
 	tracer_enabled = 0;
+	tracing_stop_cmdline_record();
 }
 
 static void sched_switch_trace_init(struct trace_array *tr)

-- 

[PATCH 2/8] ftrace: define function trace nop

[Steven Rostedt]

[-- Attachment #1: ftrace-function-record-nop.patch --]
[-- Type: text/plain, Size: 1298 bytes --]

When CONFIG_FTRACE is not enabled, the tracing_start_functon_trace
and tracing_stop_function_trace should be nops.

Signed-off-by: Steven Rostedt <srostedt@redhat.com>
---
 kernel/trace/trace.h |   10 ++++++++--
 1 file changed, 8 insertions(+), 2 deletions(-)

Index: linux-tip.git/kernel/trace/trace.h
===================================================================
--- linux-tip.git.orig/kernel/trace/trace.h	2008-06-26 14:58:55.000000000 -0400
+++ linux-tip.git/kernel/trace/trace.h	2008-06-30 22:39:15.000000000 -0400
@@ -216,8 +216,6 @@ void trace_function(struct trace_array *
 		    unsigned long parent_ip,
 		    unsigned long flags);
 
-void tracing_start_function_trace(void);
-void tracing_stop_function_trace(void);
 void tracing_start_cmdline_record(void);
 void tracing_stop_cmdline_record(void);
 int register_tracer(struct tracer *type);
@@ -234,6 +232,14 @@ void update_max_tr_single(struct trace_a
 
 extern cycle_t ftrace_now(int cpu);
 
+#ifdef CONFIG_FTRACE
+void tracing_start_function_trace(void);
+void tracing_stop_function_trace(void);
+#else
+# define tracing_start_function_trace()		do { } while (0)
+# define tracing_stop_function_trace()		do { } while (0)
+#endif
+
 #ifdef CONFIG_CONTEXT_SWITCH_TRACER
 typedef void
 (*tracer_switch_func_t)(void *private,

-- 

[PATCH 3/8] ftrace: trace schedule

[Steven Rostedt]

[-- Attachment #1: ftrace-trace-sched.patch --]
[-- Type: text/plain, Size: 863 bytes --]

After the sched_clock code has been removed from sched.c we can now trace
the scheduler. The scheduler has a lot of functions that would be worth
tracing.

Signed-off-by: Steven Rostedt <srostedt@redhat.com>
---
 kernel/Makefile |    2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

Index: linux-tip.git/kernel/Makefile
===================================================================
--- linux-tip.git.orig/kernel/Makefile	2008-07-07 15:22:21.000000000 -0400
+++ linux-tip.git/kernel/Makefile	2008-07-07 16:32:48.000000000 -0400
@@ -11,7 +11,7 @@ obj-y     = sched.o fork.o exec_domain.o
 	    hrtimer.o rwsem.o nsproxy.o srcu.o semaphore.o \
 	    notifier.o ksysfs.o pm_qos_params.o sched_clock.o
 
-CFLAGS_REMOVE_sched.o = -pg -mno-spe
+CFLAGS_REMOVE_sched.o = -mno-spe
 
 ifdef CONFIG_FTRACE
 # Do not trace debug files and internal ftrace files

-- 

[PATCH 4/8] ftrace: check proper config for preempt type

[Steven Rostedt]

[-- Attachment #1: ftrace-update-preempt-output.patch --]
[-- Type: text/plain, Size: 728 bytes --]

There is no CONFIG_PREEMPT_DESKTOP. Use the proper entry CONFIG_PREEMPT.

Signed-off-by: Steven Rostedt <srostedt@redhat.com>
---
 kernel/trace/trace.c |    2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

Index: linux-tip.git/kernel/trace/trace.c
===================================================================
--- linux-tip.git.orig/kernel/trace/trace.c	2008-07-03 17:30:24.000000000 -0400
+++ linux-tip.git/kernel/trace/trace.c	2008-07-08 10:35:09.000000000 -0400
@@ -1341,7 +1341,7 @@ print_trace_header(struct seq_file *m, s
 		   "server",
 #elif defined(CONFIG_PREEMPT_VOLUNTARY)
 		   "desktop",
-#elif defined(CONFIG_PREEMPT_DESKTOP)
+#elif defined(CONFIG_PREEMPT)
 		   "preempt",
 #else
 		   "unknown",

-- 

[PATCH 5/8] ftrace: start wakeup tracing after setting function tracer

[Steven Rostedt]

[-- Attachment #1: ftrace-wakeup-enable-tracing-last-on-startup.patch --]
[-- Type: text/plain, Size: 857 bytes --]

Enabling the wakeup tracer before enabling the function tracing causes
some strange results due to the dynamic enabling of the functions.

Signed-off-by: Steven Rostedt <srostedt@redhat.com>
---
 kernel/trace/trace_sched_wakeup.c |    3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

Index: linux-tip.git/kernel/trace/trace_sched_wakeup.c
===================================================================
--- linux-tip.git.orig/kernel/trace/trace_sched_wakeup.c	2008-07-10 12:19:54.000000000 -0400
+++ linux-tip.git/kernel/trace/trace_sched_wakeup.c	2008-07-10 12:54:09.000000000 -0400
@@ -352,9 +352,10 @@ static void start_wakeup_tracer(struct t
 	 */
 	smp_wmb();
 
-	tracer_enabled = 1;
 	register_ftrace_function(&trace_ops);
 
+	tracer_enabled = 1;
+
 	return;
 fail_deprobe_wake_new:
 	marker_probe_unregister("kernel_sched_wakeup_new",

-- 

[PATCH 6/8] ftrace: use current CPU for function startup

[Steven Rostedt]

[-- Attachment #1: ftrace-function-use-this-cpu.patch --]
[-- Type: text/plain, Size: 932 bytes --]

This is more of a clean up. Currently the function tracer initializes the
tracer with which ever CPU was last used for tracing. This value isn't
realy useful for function tracing, but at least it should be something other
than a random number.

Signed-off-by: Steven Rostedt <srostedt@redhat.com>
---
 kernel/trace/trace_functions.c |    3 +++
 1 file changed, 3 insertions(+)

Index: linux-tip.git/kernel/trace/trace_functions.c
===================================================================
--- linux-tip.git.orig/kernel/trace/trace_functions.c	2008-07-10 12:19:54.000000000 -0400
+++ linux-tip.git/kernel/trace/trace_functions.c	2008-07-10 12:56:09.000000000 -0400
@@ -28,7 +28,10 @@ static void function_reset(struct trace_
 
 static void start_function_trace(struct trace_array *tr)
 {
+	tr->cpu = get_cpu();
 	function_reset(tr);
+	put_cpu();
+
 	tracing_start_cmdline_record();
 	tracing_start_function_trace();
 }

-- 

[PATCH 7/8] ftrace: add ftrace_kill_atomic

[Steven Rostedt]

[-- Attachment #1: ftrace-kill-atomic.patch --]
[-- Type: text/plain, Size: 1802 bytes --]

It has been suggested that I add a way to disable the function tracer
on an oops. This code adds a ftrace_kill_atomic. It is not meant to be
used in normal situations. It will disable the ftrace tracer, but will
not perform the nice shutdown that requires scheduling.

Signed-off-by: Steven Rostedt <srostedt@redhat.com>
---
 include/linux/ftrace.h |    1 +
 kernel/trace/ftrace.c  |   15 +++++++++++++++
 2 files changed, 16 insertions(+)

Index: linux-tip.git/include/linux/ftrace.h
===================================================================
--- linux-tip.git.orig/include/linux/ftrace.h	2008-07-03 17:30:24.000000000 -0400
+++ linux-tip.git/include/linux/ftrace.h	2008-07-10 11:55:15.000000000 -0400
@@ -89,6 +89,7 @@ void ftrace_enable_daemon(void);
 
 /* totally disable ftrace - can not re-enable after this */
 void ftrace_kill(void);
+void ftrace_kill_atomic(void);
 
 static inline void tracer_disable(void)
 {
Index: linux-tip.git/kernel/trace/ftrace.c
===================================================================
--- linux-tip.git.orig/kernel/trace/ftrace.c	2008-07-10 00:30:00.000000000 -0400
+++ linux-tip.git/kernel/trace/ftrace.c	2008-07-10 11:54:09.000000000 -0400
@@ -1602,6 +1602,21 @@ core_initcall(ftrace_dynamic_init);
 #endif /* CONFIG_DYNAMIC_FTRACE */
 
 /**
+ * ftrace_kill_atomic - kill ftrace from critical sections
+ *
+ * This function should be used by panic code. It stops ftrace
+ * but in a not so nice way. If you need to simply kill ftrace
+ * from a non-atomic section, use ftrace_kill.
+ */
+void ftrace_kill_atomic(void)
+{
+	ftrace_disabled = 1;
+	ftrace_enabled = 0;
+	ftraced_suspend = -1;
+	clear_ftrace_function();
+}
+
+/**
  * ftrace_kill - totally shutdown ftrace
  *
  * This is a safety measure. If something was detected that seems

-- 

[PATCH 8/8] ftrace: separate out the function enabled variable

[Steven Rostedt]

[-- Attachment #1: ftrace-stop-trace.patch --]
[-- Type: text/plain, Size: 2656 bytes --]

Currently the function tracer uses the global tracer_enabled variable that
is used to keep track if the tracer is enabled or not. The function tracing
startup needs to be separated out, otherwise the internal happenings of
the tracer startup is also recorded.

This patch creates a ftrace_function_enabled variable to all the starting
of the function traces to happen after everything has been started.

Signed-off-by: Steven Rostedt <srostedt@redhat.com>
---
 kernel/trace/trace.c |   22 +++++++++++++++++++---
 1 file changed, 19 insertions(+), 3 deletions(-)

Index: linux-tip.git/kernel/trace/trace.c
===================================================================
--- linux-tip.git.orig/kernel/trace/trace.c	2008-07-10 20:26:33.000000000 -0400
+++ linux-tip.git/kernel/trace/trace.c	2008-07-10 20:38:17.000000000 -0400
@@ -96,6 +96,9 @@ static DEFINE_PER_CPU(struct trace_array
 /* tracer_enabled is used to toggle activation of a tracer */
 static int			tracer_enabled = 1;
 
+/* function tracing enabled */
+int				ftrace_function_enabled;
+
 /*
  * trace_nr_entries is the number of entries that is allocated
  * for a buffer. Note, the number of entries is always rounded
@@ -134,6 +137,7 @@ static notrace void no_trace_init(struct
 {
 	int cpu;
 
+	ftrace_function_enabled = 0;
 	if(tr->ctrl)
 		for_each_online_cpu(cpu)
 			tracing_reset(tr->data[cpu]);
@@ -985,7 +989,7 @@ function_trace_call(unsigned long ip, un
 	long disabled;
 	int cpu;
 
-	if (unlikely(!tracer_enabled))
+	if (unlikely(!ftrace_function_enabled))
 		return;
 
 	if (skip_trace(ip))
@@ -1010,11 +1014,15 @@ static struct ftrace_ops trace_ops __rea
 
 void tracing_start_function_trace(void)
 {
+	ftrace_function_enabled = 0;
 	register_ftrace_function(&trace_ops);
+	if (tracer_enabled)
+		ftrace_function_enabled = 1;
 }
 
 void tracing_stop_function_trace(void)
 {
+	ftrace_function_enabled = 0;
 	unregister_ftrace_function(&trace_ops);
 }
 #endif
@@ -1850,8 +1858,10 @@ __tracing_open(struct inode *inode, stru
 		m->private = iter;
 
 		/* stop the trace while dumping */
-		if (iter->tr->ctrl)
+		if (iter->tr->ctrl) {
 			tracer_enabled = 0;
+			ftrace_function_enabled = 0;
+		}
 
 		if (iter->trace && iter->trace->open)
 			iter->trace->open(iter);
@@ -1884,8 +1894,14 @@ int tracing_release(struct inode *inode,
 		iter->trace->close(iter);
 
 	/* reenable tracing if it was previously enabled */
-	if (iter->tr->ctrl)
+	if (iter->tr->ctrl) {
 		tracer_enabled = 1;
+		/*
+		 * It is safe to enable function tracing even if it
+		 * isn't used
+		 */
+		ftrace_function_enabled = 1;
+	}
 	mutex_unlock(&trace_types_lock);
 
 	seq_release(inode, file);

-- 

Re: [PATCH 0/8] ftrace: updates

[Ingo Molnar]

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

> Working on the ftrace.txt file proved to show some bugs with ftrace. 
> These are a list of patches that I have accumulated for ftrace that 
> solve those bugs (as well as other things).

applied them to tip/tracing/ftrace:

 Steven Rostedt (8):
      ftrace: move sched_switch enable after markers
      ftrace: define function trace nop
      ftrace: trace schedule
      ftrace: check proper config for preempt type
      ftrace: start wakeup tracing after setting function tracer
      ftrace: use current CPU for function startup
      ftrace: add ftrace_kill_atomic
      ftrace: separate out the function enabled variable

thanks Steven!

	Ingo

Re: [PATCH 0/8] ftrace: updates

[Ingo Molnar]

* Ingo Molnar <mingo@elte.hu> wrote:

> * Steven Rostedt <rostedt@goodmis.org> wrote:
> 
> > Working on the ftrace.txt file proved to show some bugs with ftrace. 
> > These are a list of patches that I have accumulated for ftrace that 
> > solve those bugs (as well as other things).
> 
> applied them to tip/tracing/ftrace:
> 
>  Steven Rostedt (8):
>       ftrace: move sched_switch enable after markers
>       ftrace: define function trace nop
>       ftrace: trace schedule
>       ftrace: check proper config for preempt type
>       ftrace: start wakeup tracing after setting function tracer
>       ftrace: use current CPU for function startup
>       ftrace: add ftrace_kill_atomic
>       ftrace: separate out the function enabled variable

found a build bug in testing - find the fix below.

	Ingo

-------------->
commit b2613e370dbeb69edbff989382fa54f2395aa471
Author: Ingo Molnar <mingo@elte.hu>
Date:   Fri Jul 11 16:44:27 2008 +0200

    ftrace: build fix for ftraced_suspend
    
    fix:
    
     kernel/trace/ftrace.c:1615: error: 'ftraced_suspend' undeclared (first use in this function)
     kernel/trace/ftrace.c:1615: error: (Each undeclared identifier is reported only once
     kernel/trace/ftrace.c:1615: error: for each function it appears in.)
    
    Signed-off-by: Ingo Molnar <mingo@elte.hu>
---
 kernel/trace/ftrace.c |    2 ++
 1 files changed, 2 insertions(+), 0 deletions(-)

diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
index 1359632..4231a3d 100644
--- a/kernel/trace/ftrace.c
+++ b/kernel/trace/ftrace.c
@@ -1612,7 +1612,9 @@ void ftrace_kill_atomic(void)
 {
 	ftrace_disabled = 1;
 	ftrace_enabled = 0;
+#ifdef CONFIG_DYNAMIC_FTRACE
 	ftraced_suspend = -1;
+#endif
 	clear_ftrace_function();
 }
 

Re: [PATCH 0/8] ftrace: updates

[Steven Rostedt]

On Fri, 11 Jul 2008, Ingo Molnar wrote:
>
> found a build bug in testing - find the fix below.

Acked-by: Steven Rostedt <srostedt@redhat.com>

Thanks Ingo!

-- Steve