ftrace: various updates

PATCH In review Steven Rostedt 3 participants 16 messages Nov 8, 2008

Subsystems (4)

Tracing ftrace Tracing OS noise / latency tracers Tracing MMIO accesses (mmiotrace)

lore

Share & tools

lore

Steven Rostedt

author maintainer

2008-11-08 03:48 UTC #0 lore raw

cover ftrace: various updates

Ingo,

The following patches are in:

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

branch: tip/devel

Matt Fleming (1):
ftrace: Align __mcount_loc sections

Steven Rostedt (9):
ftrace: fix set_ftrace_filter
ftrace: fix boot trace sched startup
ftrace: fix sched_switch API
ftrace: irqsoff tracer incorrect reset
ftrace: enable trace_printk by default
ftrace: remove ctrl_update method
ftrace: remove trace array ctrl
ftrace: force pass of preemptoff selftest
ftrace: display start of CPU buffer in trace output

----

 kernel/trace/ftrace.c             |    3 +
 kernel/trace/trace.c              |   43 +++++++++++--------
 kernel/trace/trace.h              |    8 ++-
 kernel/trace/trace_boot.c         |   22 ++++------
 kernel/trace/trace_functions.c    |   15 +------
 kernel/trace/trace_irqsoff.c      |   19 +--------
 kernel/trace/trace_mmiotrace.c    |   22 ++++------
 kernel/trace/trace_nop.c          |   16 +------
 kernel/trace/trace_sched_switch.c |   77 ++++++++++++++++++++++++----------
 kernel/trace/trace_sched_wakeup.c |   21 ++--------
 kernel/trace/trace_selftest.c     |   82 +++++++++++++++++++++++-------------
 kernel/trace/trace_sysprof.c      |   16 +------
 scripts/recordmcount.pl           |    4 ++
 13 files changed, 172 insertions(+), 176 deletions(-)

Steven Rostedt

author maintainer

2008-11-08 03:48 UTC #1 lore raw

PATCH 1/10 ftrace: fix set_ftrace_filter

Impact: fix of output of set_ftrace_filter

Commit ftrace: do not show freed records in available_filter_functions

Removed a bit too much from the set_ftrace_filter code, where we now see all functions in the set_ftrace_filter file even when we set a filter.

Signed-off-by Steven Rostedt <[email protected]>

---
 kernel/trace/ftrace.c |    3 +++
 1 files changed, 3 insertions(+), 0 deletions(-)

kernel/trace/ftrace.c +3 -0

index 896c71f..4d2e751 100644
@@ -765,6 +765,9 @@ t_next(struct seq_file *m, void *v, loff_t *pos)
 		    ((iter->flags & FTRACE_ITER_FAILURES) &&
 		     !(rec->flags & FTRACE_FL_FAILED)) ||
 
+		    ((iter->flags & FTRACE_ITER_FILTER) &&
+		     !(rec->flags & FTRACE_FL_FILTER)) ||
+
 		    ((iter->flags & FTRACE_ITER_NOTRACE) &&
 		     !(rec->flags & FTRACE_FL_NOTRACE))) {
 			rec = NULL;

Signature · 3 lines

1.5.6.5

--

Steven Rostedt

author maintainer

2008-11-08 03:48 UTC #2 lore raw

PATCH 2/10 ftrace: fix boot trace sched startup

In reply to Steven Rostedt

Impact: boot tracer startup modified

The boot tracer calls into some of the schedule tracing private functions that should not be exported. This patch cleans it up, and makes way for further changes in the ftrace infrastructure.

This patch adds a api to assign a tracer array to the schedule context switch tracer.

Signed-off-by Steven Rostedt <[email protected]>

CC Frederic Weisbecker <[email protected]>

---
 kernel/trace/trace.h              |    2 +-
 kernel/trace/trace_boot.c         |    9 +++++++--
 kernel/trace/trace_sched_switch.c |   15 ++++++++++++++-
 3 files changed, 22 insertions(+), 4 deletions(-)

kernel/trace/trace.h +1 -1

index 3422489..db12e16 100644
@@ -49,7 +49,6 @@ struct ftrace_entry {
 	unsigned long		parent_ip;
 };
 extern struct tracer boot_tracer;
-extern struct tracer sched_switch_trace; /* Used by the boot tracer */
 
 /*
  * Context switch trace entry - which task (and prio) we switched from/to:

@@ -325,6 +324,7 @@ void trace_function(struct trace_array *tr,
 
 void tracing_start_cmdline_record(void);
 void tracing_stop_cmdline_record(void);
+void tracing_cmdline_assign_trace(struct trace_array *tr);
 int register_tracer(struct tracer *type);
 void unregister_tracer(struct tracer *type);

kernel/trace/trace_boot.c +7 -2

index bd5046c..662cb91 100644
@@ -39,7 +39,12 @@ void disable_boot_trace(void)
 
 static void reset_boot_trace(struct trace_array *tr)
 {
-	sched_switch_trace.reset(tr);
+	int cpu;
+
+	tr->time_start = ftrace_now(tr->cpu);
+
+	for_each_online_cpu(cpu)
+		tracing_reset(tr, cpu);
 }
 
 static void boot_trace_init(struct trace_array *tr)

@@ -50,7 +55,7 @@ static void boot_trace_init(struct trace_array *tr)
 	for_each_cpu_mask(cpu, cpu_possible_map)
 		tracing_reset(tr, cpu);
 
-	sched_switch_trace.init(tr);
+	tracing_cmdline_assign_trace(tr);
 }
 
 static void boot_trace_ctrl_update(struct trace_array *tr)

kernel/trace/trace_sched_switch.c +14 -1

index 91c699b..fbf05df 100644
@@ -152,6 +152,19 @@ void tracing_stop_cmdline_record(void)
 	tracing_stop_sched_switch();
 }
 
+/**
+ * tracing_cmdline_assign_trace - assign a trace array for ctx switch
+ * @tr: trace array pointer to assign
+ *
+ * Some tracers might want to record the context switches in their
+ * trace. This function lets those tracers assign the trace array
+ * to use.
+ */
+void tracing_cmdline_assign_trace(struct trace_array *tr)
+{
+	ctx_trace = tr;
+}
+
 static void start_sched_trace(struct trace_array *tr)
 {
 	sched_switch_reset(tr);

@@ -197,7 +210,7 @@ static void sched_switch_trace_stop(struct trace_array *tr)
 	tracing_stop_sched_switch();
 }
 
-struct tracer sched_switch_trace __read_mostly =
+static struct tracer sched_switch_trace __read_mostly =
 {
 	.name		= "sched_switch",
 	.init		= sched_switch_trace_init,

Signature · 3 lines

1.5.6.5

--

Frédéric Weisbecker

Acked-by on v1 2/10

2008-11-08 04:12 UTC #3 lore raw

Re: [PATCH 02/10] ftrace: fix boot trace sched startup

2008/11/8 Steven Rostedt <[email protected]>:

Quoted 89 lines

Impact: boot tracer startup modified

The boot tracer calls into some of the schedule tracing private functions that should not be exported. This patch cleans it up, and makes way for further changes in the ftrace infrastructure.

This patch adds a api to assign a tracer array to the schedule context switch tracer.

Signed-off-by Steven Rostedt <[email protected]>

CC Frederic Weisbecker <[email protected]>

---
 kernel/trace/trace.h              |    2 +-
 kernel/trace/trace_boot.c         |    9 +++++++--
 kernel/trace/trace_sched_switch.c |   15 ++++++++++++++-
 3 files changed, 22 insertions(+), 4 deletions(-)

kernel/trace/trace.h +1 -1

index 3422489..db12e16 100644
@@ -49,7 +49,6 @@ struct ftrace_entry {
       unsigned long           parent_ip;
 };
 extern struct tracer boot_tracer;
-extern struct tracer sched_switch_trace; /* Used by the boot tracer */
 
 /*
 * Context switch trace entry - which task (and prio) we switched from/to:

@@ -325,6 +324,7 @@ void trace_function(struct trace_array *tr,
 
 void tracing_start_cmdline_record(void);
 void tracing_stop_cmdline_record(void);
+void tracing_cmdline_assign_trace(struct trace_array *tr);
 int register_tracer(struct tracer *type);
 void unregister_tracer(struct tracer *type);

kernel/trace/trace_boot.c +7 -2

index bd5046c..662cb91 100644
@@ -39,7 +39,12 @@ void disable_boot_trace(void)
 
 static void reset_boot_trace(struct trace_array *tr)
 {
-       sched_switch_trace.reset(tr);
+       int cpu;
+
+       tr->time_start = ftrace_now(tr->cpu);
+
+       for_each_online_cpu(cpu)
+               tracing_reset(tr, cpu);
 }
 
 static void boot_trace_init(struct trace_array *tr)

@@ -50,7 +55,7 @@ static void boot_trace_init(struct trace_array *tr)
       for_each_cpu_mask(cpu, cpu_possible_map)
               tracing_reset(tr, cpu);
 
-       sched_switch_trace.init(tr);
+       tracing_cmdline_assign_trace(tr);
 }
 
 static void boot_trace_ctrl_update(struct trace_array *tr)

kernel/trace/trace_sched_switch.c +13 -0

index 91c699b..fbf05df 100644
@@ -152,6 +152,19 @@ void tracing_stop_cmdline_record(void)
       tracing_stop_sched_switch();
 }
 
+/**
+ * tracing_cmdline_assign_trace - assign a trace array for ctx switch
+ * @tr: trace array pointer to assign
+ *
+ * Some tracers might want to record the context switches in their
+ * trace. This function lets those tracers assign the trace array
+ * to use.
+ */
+void tracing_cmdline_assign_trace(struct trace_array *tr)
+{
+       ctx_trace = tr;
+}
+
 static void start_sched_trace(struct trace_array *tr)
 {
       sched_switch_reset(tr);

kernel/trace/trace_sched_switch.c static void sched_switch_trace_stop(struct trace_array *tr) · line 216

Quoted 8 lines

kernel/trace/trace_sched_switch.c +1 -1

@@ -197,7 +210,7 @@ static void sched_switch_trace_stop(struct trace_array *tr)
       tracing_stop_sched_switch();
 }
 
-struct tracer sched_switch_trace __read_mostly =
+static struct tracer sched_switch_trace __read_mostly =
 {
       .name           = "sched_switch",
       .init           = sched_switch_trace_init,

Righ that's much proper.

BTW: I see that tracing_reset is called even on start and reset callback by the tracers. Wouldn't it better to do it only on reset? Perhaps it can even be done automatically by the tracing Api itself when reset is called on
every tracers. Or perhaps there could be special cases I don't see where one tracer wouldn't wish to erase is entries
on reset?

Acked-by Frederic Weisbecker <[email protected]>

Steven Rostedt

author maintainer

2008-11-08 12:17 UTC #4 lore raw

Re: [PATCH 02/10] ftrace: fix boot trace sched startup

Quoted 8 lines · Fr?d?ric Weisbecker

BTW: I see that tracing_reset is called even on start and reset callback by the tracers. Wouldn't it better to do it only on reset? Perhaps it can even be done automatically by the tracing Api itself when reset is called on
every tracers. Or perhaps there could be special cases I don't see where one tracer wouldn't wish to erase is entries
on reset?

I'm maintaining the original behaviour. We can discusss whether or not the start should also reset. I'm up for different ideas.

Quoted 2 lines

Acked-by Frederic Weisbecker <[email protected]>

Thanks,

-- Steve

Steven Rostedt

author maintainer

2008-11-08 03:49 UTC #5 lore raw

PATCH 3/10 ftrace: fix sched_switch API

In reply to Steven Rostedt

Impact: fix for sched_switch that broke dynamic ftrace startup

The commit: tracing/fastboot: use sched switch tracer from boot tracer broke the API of the sched_switch trace. The use of the tracing_start/stop_cmdline record is for only recording the cmdline, NOT recording the schedule switches themselves.

Seeing that the boot tracer broke the API to do something that it wanted, this patch adds a new interface for the API while puting back the original interface of the old API.

Signed-off-by Steven Rostedt <[email protected]>

CC Frederic Weisbecker <[email protected]>

---
 kernel/trace/trace.h              |    4 ++-
 kernel/trace/trace_boot.c         |    6 ++--
 kernel/trace/trace_sched_switch.c |   50 +++++++++++++++++++++++++++++-------
 3 files changed, 46 insertions(+), 14 deletions(-)

kernel/trace/trace.h +3 -1

index db12e16..25abfc4 100644
@@ -324,7 +324,9 @@ void trace_function(struct trace_array *tr,
 
 void tracing_start_cmdline_record(void);
 void tracing_stop_cmdline_record(void);
-void tracing_cmdline_assign_trace(struct trace_array *tr);
+void tracing_sched_switch_assign_trace(struct trace_array *tr);
+void tracing_stop_sched_switch_record(void);
+void tracing_start_sched_switch_record(void);
 int register_tracer(struct tracer *type);
 void unregister_tracer(struct tracer *type);

kernel/trace/trace_boot.c +3 -3

index 662cb91..0203c10 100644
@@ -28,13 +28,13 @@ void start_boot_trace(void)
 void enable_boot_trace(void)
 {
 	if (pre_initcalls_finished)
-		tracing_start_cmdline_record();
+		tracing_start_sched_switch_record();
 }
 
 void disable_boot_trace(void)
 {
 	if (pre_initcalls_finished)
-		tracing_stop_cmdline_record();
+		tracing_stop_sched_switch_record();
 }
 
 static void reset_boot_trace(struct trace_array *tr)

@@ -55,7 +55,7 @@ static void boot_trace_init(struct trace_array *tr)
 	for_each_cpu_mask(cpu, cpu_possible_map)
 		tracing_reset(tr, cpu);
 
-	tracing_cmdline_assign_trace(tr);
+	tracing_sched_switch_assign_trace(tr);
 }
 
 static void boot_trace_ctrl_update(struct trace_array *tr)

kernel/trace/trace_sched_switch.c +40 ~~-10~~

86 lines not on this page · raw message

Signature · 3 lines

1.5.6.5

--

Frédéric Weisbecker

Acked-by on v1 3/10

2008-11-08 04:20 UTC #6 lore raw

Re: [PATCH 03/10] ftrace: fix sched_switch API

2008/11/8 Steven Rostedt <[email protected]>:

Quoted 146 lines

Impact: fix for sched_switch that broke dynamic ftrace startup

Seeing that the boot tracer broke the API to do something that it wanted, this patch adds a new interface for the API while puting back the original interface of the old API.

Signed-off-by Steven Rostedt <[email protected]>

CC Frederic Weisbecker <[email protected]>

---
 kernel/trace/trace.h              |    4 ++-
 kernel/trace/trace_boot.c         |    6 ++--
 kernel/trace/trace_sched_switch.c |   50 +++++++++++++++++++++++++++++-------
 3 files changed, 46 insertions(+), 14 deletions(-)

kernel/trace/trace.h +3 -1

index db12e16..25abfc4 100644
@@ -324,7 +324,9 @@ void trace_function(struct trace_array *tr,
 
 void tracing_start_cmdline_record(void);
 void tracing_stop_cmdline_record(void);
-void tracing_cmdline_assign_trace(struct trace_array *tr);
+void tracing_sched_switch_assign_trace(struct trace_array *tr);
+void tracing_stop_sched_switch_record(void);
+void tracing_start_sched_switch_record(void);
 int register_tracer(struct tracer *type);
 void unregister_tracer(struct tracer *type);

kernel/trace/trace_boot.c +3 -3

index 662cb91..0203c10 100644
@@ -28,13 +28,13 @@ void start_boot_trace(void)
 void enable_boot_trace(void)
 {
       if (pre_initcalls_finished)
-               tracing_start_cmdline_record();
+               tracing_start_sched_switch_record();
 }
 
 void disable_boot_trace(void)
 {
       if (pre_initcalls_finished)
-               tracing_stop_cmdline_record();
+               tracing_stop_sched_switch_record();
 }
 
 static void reset_boot_trace(struct trace_array *tr)

@@ -55,7 +55,7 @@ static void boot_trace_init(struct trace_array *tr)
       for_each_cpu_mask(cpu, cpu_possible_map)
               tracing_reset(tr, cpu);
 
-       tracing_cmdline_assign_trace(tr);
+       tracing_sched_switch_assign_trace(tr);
 }
 
 static void boot_trace_ctrl_update(struct trace_array *tr)

kernel/trace/trace_sched_switch.c +38 -9

index fbf05df..79410db 100644
@@ -125,20 +125,16 @@ static void tracing_sched_unregister(void)
 static void tracing_start_sched_switch(void)
 {
       mutex_lock(&sched_register_mutex);
-       if (!(sched_ref++)) {
-               tracer_enabled = 1;
+       if (!(sched_ref++))
               tracing_sched_register();
-       }
       mutex_unlock(&sched_register_mutex);
 }
 
 static void tracing_stop_sched_switch(void)
 {
       mutex_lock(&sched_register_mutex);
-       if (!(--sched_ref)) {
+       if (!(--sched_ref))
               tracing_sched_unregister();
-               tracer_enabled = 0;
-       }
       mutex_unlock(&sched_register_mutex);
 }

@@ -153,14 +149,48 @@ void tracing_stop_cmdline_record(void)
 }
 
 /**
- * tracing_cmdline_assign_trace - assign a trace array for ctx switch
+ * tracing_start_sched_switch_record - start tracing context switches
+ *
+ * Turns on context switch tracing for a tracer.
+ */
+void tracing_start_sched_switch_record(void)
+{
+       if (unlikely(!ctx_trace)) {
+               WARN_ON(1);
+               return;
+       }
+
+       tracing_start_sched_switch();
+
+       mutex_lock(&sched_register_mutex);
+       tracer_enabled++;
+       mutex_unlock(&sched_register_mutex);
+}
+
+/**
+ * tracing_stop_sched_switch_record - start tracing context switches
+ *
+ * Turns off context switch tracing for a tracer.
+ */
+void tracing_stop_sched_switch_record(void)
+{
+       mutex_lock(&sched_register_mutex);
+       tracer_enabled--;
+       WARN_ON(tracer_enabled < 0);
+       mutex_unlock(&sched_register_mutex);
+
+       tracing_stop_sched_switch();
+}
+
+/**
+ * tracing_sched_switch_assign_trace - assign a trace array for ctx switch
 * @tr: trace array pointer to assign
 *
 * Some tracers might want to record the context switches in their
 * trace. This function lets those tracers assign the trace array
 * to use.
 */
-void tracing_cmdline_assign_trace(struct trace_array *tr)
+void tracing_sched_switch_assign_trace(struct trace_array *tr)
 {
       ctx_trace = tr;
 }

@@ -168,12 +198,12 @@ void tracing_cmdline_assign_trace(struct trace_array *tr)
 static void start_sched_trace(struct trace_array *tr)
 {
       sched_switch_reset(tr);
-       tracing_start_cmdline_record();

kernel/trace/trace_sched_switch.c void tracing_cmdline_assign_trace(struct trace_array *tr) · line 209

Quoted 10 lines

kernel/trace/trace_sched_switch.c +2 -1

+       tracing_start_sched_switch_record();
 }
 
 static void stop_sched_trace(struct trace_array *tr)
 {
-       tracing_stop_cmdline_record();
+       tracing_stop_sched_switch_record();
 }
 
 static void sched_switch_trace_init(struct trace_array *tr)

Sorry, I misunderstood the sense of these functions and then used them only for what they did: start/stop sched event capture.

Acked-by Frederic Weisbecker < [email protected]>

Steven Rostedt

author maintainer

2008-11-08 03:48 UTC #7 lore raw

PATCH 4/10 ftrace: irqsoff tracer incorrect reset

In reply to Steven Rostedt

Impact: fix to irqsoff tracer output

In converting to the new start / stop ftrace handling, the irqsoff tracer start called the irqsoff reset function. irqsoff tracer is not the same as the other traces, and it resets the buffers while searching for the longest latency.

The reset that the irqsoff stop method calls disables the function tracing. That means that, by starting the tracer, the function tracer is disabled incorrectly.

This patch simply removes the call to reset which keeps the function tracing enabled. Reset is not needed for the irqsoff stop method.

Signed-off-by Steven Rostedt <[email protected]>

---
 kernel/trace/trace_irqsoff.c |    1 -
 1 files changed, 0 insertions(+), 1 deletions(-)

kernel/trace/trace_irqsoff.c +0 -1

index a87a20f..3509086 100644
@@ -404,7 +404,6 @@ static void irqsoff_tracer_ctrl_update(struct trace_array *tr)
 
 static void irqsoff_tracer_start(struct trace_array *tr)
 {
-	irqsoff_tracer_reset(tr);
 	tracer_enabled = 1;
 	save_tracer_enabled = 1;
 }

Signature · 3 lines

1.5.6.5

--

Steven Rostedt

author maintainer

2008-11-08 03:49 UTC #8 lore raw

PATCH 5/10 ftrace: enable trace_printk by default

In reply to Steven Rostedt

Impact: have the ftrace_printk enabled on startup

It is confusing to have to "echo trace_printk > /debug/tracing/iter_ctrl" after adding ftrace_printk in the kernel.

Currently the trace_printk is set to off by default. ftrace_printk should only be in open kernel code when used for debugging, and thus it should be enabled by default.

It may also be used to record data within a tracer, but those ftrace_printks should be within wrappers that are either enabled by trace_points or have a variable protecting the code path from being entered when the tracer is disabled.

Signed-off-by Steven Rostedt <[email protected]>

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

kernel/trace/trace.c +1 -1

index d55ccfc..dbbdacf 100644
@@ -205,7 +205,7 @@ static DEFINE_MUTEX(trace_types_lock);
 static DECLARE_WAIT_QUEUE_HEAD(trace_wait);
 
 /* trace_flags holds iter_ctrl options */
-unsigned long trace_flags = TRACE_ITER_PRINT_PARENT;
+unsigned long trace_flags = TRACE_ITER_PRINT_PARENT | TRACE_ITER_PRINTK;
 
 /**
  * trace_wake_up - wake up tasks waiting for trace input

Signature · 3 lines

1.5.6.5

--

Steven Rostedt

author maintainer

2008-11-08 03:50 UTC #9 lore raw

PATCH 6/10 ftrace: remove ctrl_update method

In reply to Steven Rostedt

Impact: Remove the ctrl_update tracer method

With the new quick start/stop method of tracing, the ctrl_update method is out of date.

Signed-off-by Steven Rostedt <[email protected]>

---
 kernel/trace/trace.c              |    2 -
 kernel/trace/trace.h              |    1 -
 kernel/trace/trace_boot.c         |    9 -------
 kernel/trace/trace_functions.c    |    9 -------
 kernel/trace/trace_irqsoff.c      |   11 --------
 kernel/trace/trace_mmiotrace.c    |   11 ++------
 kernel/trace/trace_nop.c          |   10 -------
 kernel/trace/trace_sched_switch.c |   10 -------
 kernel/trace/trace_sched_wakeup.c |    9 -------
 kernel/trace/trace_selftest.c     |   48 ++++++++++++++++++++-----------------
 kernel/trace/trace_sysprof.c      |   10 -------
 11 files changed, 29 insertions(+), 101 deletions(-)

kernel/trace/trace.c +0 -2

index dbbdacf..9e83188 100644
@@ -3357,8 +3357,6 @@ __init static int tracer_alloc_buffers(void)
 
 	register_tracer(&nop_trace);
 #ifdef CONFIG_BOOT_TRACER
-	/* We don't want to launch sched_switch tracer yet */
-	global_trace.ctrl = 0;
 	register_tracer(&boot_tracer);
 	current_trace = &boot_tracer;
 	current_trace->init(&global_trace);

kernel/trace/trace.h +0 -1

index 25abfc4..e481eda 100644
@@ -244,7 +244,6 @@ struct tracer {
 	ssize_t			(*read)(struct trace_iterator *iter,
 					struct file *filp, char __user *ubuf,
 					size_t cnt, loff_t *ppos);
-	void			(*ctrl_update)(struct trace_array *tr);
 #ifdef CONFIG_FTRACE_STARTUP_TEST
 	int			(*selftest)(struct tracer *trace,
 					    struct trace_array *tr);

kernel/trace/trace_boot.c +0 -9

index 0203c10..8f71915 100644
@@ -58,14 +58,6 @@ static void boot_trace_init(struct trace_array *tr)
 	tracing_sched_switch_assign_trace(tr);
 }
 
-static void boot_trace_ctrl_update(struct trace_array *tr)
-{
-	if (tr->ctrl)
-		enable_boot_trace();
-	else
-		disable_boot_trace();
-}
-
 static enum print_line_t initcall_print_line(struct trace_iterator *iter)
 {
 	int ret;

@@ -102,7 +94,6 @@ struct tracer boot_tracer __read_mostly =
 	.name		= "initcall",
 	.init		= boot_trace_init,
 	.reset		= reset_boot_trace,
-	.ctrl_update	= boot_trace_ctrl_update,
 	.print_line	= initcall_print_line,
 };

kernel/trace/trace_functions.c +0 -9

index 9f1b0de..e980b87 100644
@@ -54,14 +54,6 @@ static void function_trace_reset(struct trace_array *tr)
 		stop_function_trace(tr);
 }
 
-static void function_trace_ctrl_update(struct trace_array *tr)
-{
-	if (tr->ctrl)
-		start_function_trace(tr);
-	else
-		stop_function_trace(tr);
-}
-
 static void function_trace_start(struct trace_array *tr)
 {
 	function_reset(tr);

@@ -73,7 +65,6 @@ static struct tracer function_trace __read_mostly =
 	.init	     = function_trace_init,
 	.reset	     = function_trace_reset,
 	.start	     = function_trace_start,
-	.ctrl_update = function_trace_ctrl_update,
 #ifdef CONFIG_FTRACE_SELFTEST
 	.selftest    = trace_selftest_startup_function,
 #endif

kernel/trace/trace_irqsoff.c +0 ~~-11~~

index 3509086..ffdf592 100644
@@ -394,14 +394,6 @@ static void irqsoff_tracer_reset(struct trace_array *tr)
 		stop_irqsoff_tracer(tr);
 }
 
-static void irqsoff_tracer_ctrl_update(struct trace_array *tr)
-{
-	if (tr->ctrl)
-		start_irqsoff_tracer(tr);
-	else
-		stop_irqsoff_tracer(tr);
-}
-
 static void irqsoff_tracer_start(struct trace_array *tr)
 {
 	tracer_enabled = 1;

@@ -442,7 +434,6 @@ static struct tracer irqsoff_tracer __read_mostly =
 	.stop		= irqsoff_tracer_stop,
 	.open		= irqsoff_tracer_open,
 	.close		= irqsoff_tracer_close,
-	.ctrl_update	= irqsoff_tracer_ctrl_update,
 	.print_max	= 1,
 #ifdef CONFIG_FTRACE_SELFTEST
 	.selftest    = trace_selftest_startup_irqsoff,

@@ -470,7 +461,6 @@ static struct tracer preemptoff_tracer __read_mostly =
 	.stop		= irqsoff_tracer_stop,
 	.open		= irqsoff_tracer_open,
 	.close		= irqsoff_tracer_close,
-	.ctrl_update	= irqsoff_tracer_ctrl_update,
 	.print_max	= 1,
 #ifdef CONFIG_FTRACE_SELFTEST
 	.selftest    = trace_selftest_startup_preemptoff,

@@ -500,7 +490,6 @@ static struct tracer preemptirqsoff_tracer __read_mostly =
 	.stop		= irqsoff_tracer_stop,
 	.open		= irqsoff_tracer_open,
 	.close		= irqsoff_tracer_close,
-	.ctrl_update	= irqsoff_tracer_ctrl_update,
 	.print_max	= 1,
 #ifdef CONFIG_FTRACE_SELFTEST
 	.selftest    = trace_selftest_startup_preemptirqsoff,

kernel/trace/trace_mmiotrace.c +3 -8

index f284846..fa9354e 100644
@@ -49,15 +49,10 @@ static void mmio_trace_reset(struct trace_array *tr)
 	mmio_trace_array = NULL;
 }
 
-static void mmio_trace_ctrl_update(struct trace_array *tr)
+static void mmio_trace_start(struct trace_array *tr)
 {
 	pr_debug("in %s\n", __func__);
-	if (tr->ctrl) {
-		mmio_reset_data(tr);
-		enable_mmiotrace();
-	} else {
-		disable_mmiotrace();
-	}
+	mmio_reset_data(tr);
 }
 
 static int mmio_print_pcidev(struct trace_seq *s, const struct pci_dev *dev)

@@ -298,10 +293,10 @@ static struct tracer mmio_tracer __read_mostly =
 	.name		= "mmiotrace",
 	.init		= mmio_trace_init,
 	.reset		= mmio_trace_reset,
+	.start		= mmio_trace_start,
 	.pipe_open	= mmio_pipe_open,
 	.close		= mmio_close,
 	.read		= mmio_read,
-	.ctrl_update	= mmio_trace_ctrl_update,
 	.print_line	= mmio_print_line,
 };

kernel/trace/trace_nop.c +0 ~~-10~~

index 4592b48..e3c5fbf 100644
@@ -42,21 +42,11 @@ static void nop_trace_reset(struct trace_array *tr)
 		stop_nop_trace(tr);
 }
 
-static void nop_trace_ctrl_update(struct trace_array *tr)
-{
-	/* When starting a new trace, reset the buffers */
-	if (tr->ctrl)
-		start_nop_trace(tr);
-	else
-		stop_nop_trace(tr);
-}
-
 struct tracer nop_trace __read_mostly =
 {
 	.name		= "nop",
 	.init		= nop_trace_init,
 	.reset		= nop_trace_reset,
-	.ctrl_update	= nop_trace_ctrl_update,
 #ifdef CONFIG_FTRACE_SELFTEST
 	.selftest	= trace_selftest_startup_nop,
 #endif

kernel/trace/trace_sched_switch.c +0 ~~-10~~

index 79410db..7b73fd1 100644
@@ -220,15 +220,6 @@ static void sched_switch_trace_reset(struct trace_array *tr)
 		stop_sched_trace(tr);
 }
 
-static void sched_switch_trace_ctrl_update(struct trace_array *tr)
-{
-	/* When starting a new trace, reset the buffers */
-	if (tr->ctrl)
-		start_sched_trace(tr);
-	else
-		stop_sched_trace(tr);
-}
-
 static void sched_switch_trace_start(struct trace_array *tr)
 {
 	sched_switch_reset(tr);

@@ -247,7 +238,6 @@ static struct tracer sched_switch_trace __read_mostly =
 	.reset		= sched_switch_trace_reset,
 	.start		= sched_switch_trace_start,
 	.stop		= sched_switch_trace_stop,
-	.ctrl_update	= sched_switch_trace_ctrl_update,
 #ifdef CONFIG_FTRACE_SELFTEST
 	.selftest    = trace_selftest_startup_sched_switch,
 #endif

kernel/trace/trace_sched_wakeup.c +0 -9

index 240577b..23e54d4 100644
@@ -348,14 +348,6 @@ static void wakeup_tracer_reset(struct trace_array *tr)
 	}
 }
 
-static void wakeup_tracer_ctrl_update(struct trace_array *tr)
-{
-	if (tr->ctrl)
-		start_wakeup_tracer(tr);
-	else
-		stop_wakeup_tracer(tr);
-}
-
 static void wakeup_tracer_start(struct trace_array *tr)
 {
 	wakeup_reset(tr);

@@ -393,7 +385,6 @@ static struct tracer wakeup_tracer __read_mostly =
 	.stop		= wakeup_tracer_stop,
 	.open		= wakeup_tracer_open,
 	.close		= wakeup_tracer_close,
-	.ctrl_update	= wakeup_tracer_ctrl_update,
 	.print_max	= 1,
 #ifdef CONFIG_FTRACE_SELFTEST
 	.selftest    = trace_selftest_startup_wakeup,

kernel/trace/trace_selftest.c +26 ~~-22~~

161 lines not on this page · raw message

kernel/trace/trace_sysprof.c +0 ~~-10~~

index 9587d3b..8097430 100644
@@ -275,21 +275,11 @@ static void stack_trace_reset(struct trace_array *tr)
 		stop_stack_trace(tr);
 }
 
-static void stack_trace_ctrl_update(struct trace_array *tr)
-{
-	/* When starting a new trace, reset the buffers */
-	if (tr->ctrl)
-		start_stack_trace(tr);
-	else
-		stop_stack_trace(tr);
-}
-
 static struct tracer stack_trace __read_mostly =
 {
 	.name		= "sysprof",
 	.init		= stack_trace_init,
 	.reset		= stack_trace_reset,
-	.ctrl_update	= stack_trace_ctrl_update,
 #ifdef CONFIG_FTRACE_SELFTEST
 	.selftest    = trace_selftest_startup_sysprof,
 #endif

Signature · 3 lines

1.5.6.5

--

Steven Rostedt

author maintainer

2008-11-08 03:51 UTC #10 lore raw

PATCH 7/10 ftrace: remove trace array ctrl

In reply to Steven Rostedt

Impact: remove obsolete variable in trace_array structure

With the new start / stop method of ftrace, the ctrl variable in the trace_array structure is now obsolete. Remove it.

Signed-off-by Steven Rostedt <[email protected]>

---
 kernel/trace/trace.c              |   20 +++++---------------
 kernel/trace/trace.h              |    1 -
 kernel/trace/trace_functions.c    |    6 ++----
 kernel/trace/trace_irqsoff.c      |    7 ++-----
 kernel/trace/trace_mmiotrace.c    |   11 +++++------
 kernel/trace/trace_nop.c          |    6 ++----
 kernel/trace/trace_sched_switch.c |    6 ++----
 kernel/trace/trace_sched_wakeup.c |   12 ++++--------
 kernel/trace/trace_selftest.c     |    8 --------
 kernel/trace/trace_sysprof.c      |    6 ++----
 10 files changed, 24 insertions(+), 59 deletions(-)

kernel/trace/trace.c +5 ~~-15~~

index 9e83188..5843541 100644
@@ -537,7 +537,6 @@ int register_tracer(struct tracer *type)
 	if (type->selftest) {
 		struct tracer *saved_tracer = current_trace;
 		struct trace_array *tr = &global_trace;
-		int saved_ctrl = tr->ctrl;
 		int i;
 		/*
 		 * Run a selftest on this tracer.

@@ -550,13 +549,11 @@ int register_tracer(struct tracer *type)
 			tracing_reset(tr, i);
 		}
 		current_trace = type;
-		tr->ctrl = 0;
 		/* the test is responsible for initializing and enabling */
 		pr_info("Testing tracer %s: ", type->name);
 		ret = type->selftest(type, tr);
 		/* the test is responsible for resetting too */
 		current_trace = saved_tracer;
-		tr->ctrl = saved_ctrl;
 		if (ret) {
 			printk(KERN_CONT "FAILED!\n");
 			goto out;

@@ -966,7 +963,7 @@ ftrace_special(unsigned long arg1, unsigned long arg2, unsigned long arg3)
 	int cpu;
 	int pc;
 
-	if (tracing_disabled || !tr->ctrl)
+	if (tracing_disabled)
 		return;
 
 	pc = preempt_count();

@@ -2820,7 +2817,6 @@ tracing_entries_write(struct file *filp, const char __user *ubuf,
 	unsigned long val;
 	char buf[64];
 	int ret;
-	struct trace_array *tr = filp->private_data;
 
 	if (cnt >= sizeof(buf))
 		return -EINVAL;

@@ -2840,12 +2836,7 @@ tracing_entries_write(struct file *filp, const char __user *ubuf,
 
 	mutex_lock(&trace_types_lock);
 
-	if (tr->ctrl) {
-		cnt = -EBUSY;
-		pr_info("ftrace: please disable tracing"
-			" before modifying buffer size\n");
-		goto out;
-	}
+	tracing_stop();
 
 	if (val != global_trace.entries) {
 		ret = ring_buffer_resize(global_trace.buffer, val);

@@ -2878,6 +2869,7 @@ tracing_entries_write(struct file *filp, const char __user *ubuf,
 	if (tracing_disabled)
 		cnt = -ENOMEM;
  out:
+	tracing_start();
 	max_tr.entries = global_trace.entries;
 	mutex_unlock(&trace_types_lock);

@@ -2900,9 +2892,8 @@ tracing_mark_write(struct file *filp, const char __user *ubuf,
 {
 	char *buf;
 	char *end;
-	struct trace_array *tr = &global_trace;
 
-	if (!tr->ctrl || tracing_disabled)
+	if (tracing_disabled)
 		return -EINVAL;
 
 	if (cnt > TRACE_BUF_SIZE)

@@ -3131,7 +3122,7 @@ int trace_vprintk(unsigned long ip, const char *fmt, va_list args)
 	unsigned long flags, irq_flags;
 	int cpu, len = 0, size, pc;
 
-	if (!tr->ctrl || tracing_disabled)
+	if (tracing_disabled)
 		return 0;
 
 	pc = preempt_count();

@@ -3365,7 +3356,6 @@ __init static int tracer_alloc_buffers(void)
 #endif
 
 	/* All seems OK, enable tracing */
-	global_trace.ctrl = 1;
 	tracing_disabled = 0;
 
 	atomic_notifier_chain_register(&panic_notifier_list,

kernel/trace/trace.h +0 -1

index e481eda..cfda9d2 100644
@@ -172,7 +172,6 @@ struct trace_iterator;
 struct trace_array {
 	struct ring_buffer	*buffer;
 	unsigned long		entries;
-	long			ctrl;
 	int			cpu;
 	cycle_t			time_start;
 	struct task_struct	*waiter;

kernel/trace/trace_functions.c +2 -4

index e980b87..8693b7a 100644
@@ -44,14 +44,12 @@ static void stop_function_trace(struct trace_array *tr)
 
 static void function_trace_init(struct trace_array *tr)
 {
-	if (tr->ctrl)
-		start_function_trace(tr);
+	start_function_trace(tr);
 }
 
 static void function_trace_reset(struct trace_array *tr)
 {
-	if (tr->ctrl)
-		stop_function_trace(tr);
+	stop_function_trace(tr);
 }
 
 static void function_trace_start(struct trace_array *tr)

kernel/trace/trace_irqsoff.c +2 -5

index ffdf592..d919d4e 100644
@@ -383,15 +383,12 @@ static void __irqsoff_tracer_init(struct trace_array *tr)
 	irqsoff_trace = tr;
 	/* make sure that the tracer is visible */
 	smp_wmb();
-
-	if (tr->ctrl)
-		start_irqsoff_tracer(tr);
+	start_irqsoff_tracer(tr);
 }
 
 static void irqsoff_tracer_reset(struct trace_array *tr)
 {
-	if (tr->ctrl)
-		stop_irqsoff_tracer(tr);
+	stop_irqsoff_tracer(tr);
 }
 
 static void irqsoff_tracer_start(struct trace_array *tr)

kernel/trace/trace_mmiotrace.c +5 -6

index fa9354e..51bcf37 100644
@@ -34,17 +34,16 @@ static void mmio_trace_init(struct trace_array *tr)
 {
 	pr_debug("in %s\n", __func__);
 	mmio_trace_array = tr;
-	if (tr->ctrl) {
-		mmio_reset_data(tr);
-		enable_mmiotrace();
-	}
+
+	mmio_reset_data(tr);
+	enable_mmiotrace();
 }
 
 static void mmio_trace_reset(struct trace_array *tr)
 {
 	pr_debug("in %s\n", __func__);
-	if (tr->ctrl)
-		disable_mmiotrace();
+
+	disable_mmiotrace();
 	mmio_reset_data(tr);
 	mmio_trace_array = NULL;
 }

kernel/trace/trace_nop.c +2 -4

index e3c5fbf..2ef1d22 100644
@@ -32,14 +32,12 @@ static void nop_trace_init(struct trace_array *tr)
 	for_each_online_cpu(cpu)
 		tracing_reset(tr, cpu);
 
-	if (tr->ctrl)
-		start_nop_trace(tr);
+	start_nop_trace(tr);
 }
 
 static void nop_trace_reset(struct trace_array *tr)
 {
-	if (tr->ctrl)
-		stop_nop_trace(tr);
+	stop_nop_trace(tr);
 }
 
 struct tracer nop_trace __read_mostly =

kernel/trace/trace_sched_switch.c +2 -4

index 7b73fd1..be35bdf 100644
@@ -209,14 +209,12 @@ static void stop_sched_trace(struct trace_array *tr)
 static void sched_switch_trace_init(struct trace_array *tr)
 {
 	ctx_trace = tr;
-
-	if (tr->ctrl)
-		start_sched_trace(tr);
+	start_sched_trace(tr);
 }
 
 static void sched_switch_trace_reset(struct trace_array *tr)
 {
-	if (tr->ctrl && sched_ref)
+	if (sched_ref)
 		stop_sched_trace(tr);
 }

kernel/trace/trace_sched_wakeup.c +4 -8

index 23e54d4..983f2b1 100644
@@ -334,18 +334,14 @@ static void stop_wakeup_tracer(struct trace_array *tr)
 static void wakeup_tracer_init(struct trace_array *tr)
 {
 	wakeup_trace = tr;
-
-	if (tr->ctrl)
-		start_wakeup_tracer(tr);
+	start_wakeup_tracer(tr);
 }
 
 static void wakeup_tracer_reset(struct trace_array *tr)
 {
-	if (tr->ctrl) {
-		stop_wakeup_tracer(tr);
-		/* make sure we put back any tasks we are tracing */
-		wakeup_reset(tr);
-	}
+	stop_wakeup_tracer(tr);
+	/* make sure we put back any tasks we are tracing */
+	wakeup_reset(tr);
 }
 
 static void wakeup_tracer_start(struct trace_array *tr)

kernel/trace/trace_selftest.c +0 -8

index 7469343..ea4e5d3 100644
@@ -110,7 +110,6 @@ int trace_selftest_startup_dynamic_tracing(struct tracer *trace,
 	ftrace_set_filter(func_name, strlen(func_name), 1);
 
 	/* enable tracing */
-	tr->ctrl = 1;
 	trace->init(tr);
 
 	/* Sleep for a 1/10 of a second */

@@ -181,7 +180,6 @@ trace_selftest_startup_function(struct tracer *trace, struct trace_array *tr)
 	ftrace_enabled = 1;
 	tracer_enabled = 1;
 
-	tr->ctrl = 1;
 	trace->init(tr);
 	/* Sleep for a 1/10 of a second */
 	msleep(100);

@@ -224,7 +222,6 @@ trace_selftest_startup_irqsoff(struct tracer *trace, struct trace_array *tr)
 	int ret;
 
 	/* start the tracing */
-	tr->ctrl = 1;
 	trace->init(tr);
 	/* reset the max latency */
 	tracing_max_latency = 0;

@@ -261,7 +258,6 @@ trace_selftest_startup_preemptoff(struct tracer *trace, struct trace_array *tr)
 	int ret;
 
 	/* start the tracing */
-	tr->ctrl = 1;
 	trace->init(tr);
 	/* reset the max latency */
 	tracing_max_latency = 0;

@@ -298,7 +294,6 @@ trace_selftest_startup_preemptirqsoff(struct tracer *trace, struct trace_array *
 	int ret;
 
 	/* start the tracing */
-	tr->ctrl = 1;
 	trace->init(tr);
 
 	/* reset the max latency */

@@ -427,7 +422,6 @@ trace_selftest_startup_wakeup(struct tracer *trace, struct trace_array *tr)
 	wait_for_completion(&isrt);
 
 	/* start the tracing */
-	tr->ctrl = 1;
 	trace->init(tr);
 	/* reset the max latency */
 	tracing_max_latency = 0;

@@ -484,7 +478,6 @@ trace_selftest_startup_sched_switch(struct tracer *trace, struct trace_array *tr
 	int ret;
 
 	/* start the tracing */
-	tr->ctrl = 1;
 	trace->init(tr);
 	/* Sleep for a 1/10 of a second */
 	msleep(100);

@@ -512,7 +505,6 @@ trace_selftest_startup_sysprof(struct tracer *trace, struct trace_array *tr)
 	int ret;
 
 	/* start the tracing */
-	tr->ctrl = 1;
 	trace->init(tr);
 	/* Sleep for a 1/10 of a second */
 	msleep(100);

kernel/trace/trace_sysprof.c +2 -4

index 8097430..05f7534 100644
@@ -265,14 +265,12 @@ static void stack_trace_init(struct trace_array *tr)
 {
 	sysprof_trace = tr;
 
-	if (tr->ctrl)
-		start_stack_trace(tr);
+	start_stack_trace(tr);
 }
 
 static void stack_trace_reset(struct trace_array *tr)
 {
-	if (tr->ctrl)
-		stop_stack_trace(tr);
+	stop_stack_trace(tr);
 }
 
 static struct tracer stack_trace __read_mostly =

Signature · 3 lines

1.5.6.5

--

Steven Rostedt

author maintainer

2008-11-08 03:50 UTC #11 lore raw

PATCH 8/10 ftrace: Align __mcount_loc sections

In reply to Steven Rostedt

Impact: alignment option for recordmcount.pl script

Align the __mcount_loc sections so that architectures with strict alignment requirements need not worry about performing unaligned accesses.

This fixes an issue where I was seeing unaligned accesses, which are not supported on our architecture (the results of an unaligned access are undefined).

Signed-off-by Matt Fleming <[email protected]>

Signed-off-by Steven Rostedt <[email protected]>

---
 scripts/recordmcount.pl |    4 ++++
 1 files changed, 4 insertions(+), 0 deletions(-)

scripts/recordmcount.pl +4 -0

index 6b9fe3e..eeac71c 100755
@@ -134,6 +134,7 @@ my $section_regex;	# Find the start of a section
 my $function_regex;	# Find the name of a function
 			#    (return offset and func name)
 my $mcount_regex;	# Find the call site to mcount (return offset)
+my $alignment;         # The .align value to use for $mcount_section
 
 if ($arch eq "x86") {
     if ($bits == 64) {

@@ -148,6 +149,7 @@ if ($arch eq "x86_64") {
     $function_regex = "^([0-9a-fA-F]+)\\s+<(.*?)>:";
     $mcount_regex = "^\\s*([0-9a-fA-F]+):.*\\smcount([+-]0x[0-9a-zA-Z]+)?\$";
     $type = ".quad";
+    $alignment = 8;
 
     # force flags for this arch
     $ld .= " -m elf_x86_64";

@@ -160,6 +162,7 @@ if ($arch eq "x86_64") {
     $function_regex = "^([0-9a-fA-F]+)\\s+<(.*?)>:";
     $mcount_regex = "^\\s*([0-9a-fA-F]+):.*\\smcount\$";
     $type = ".long";
+    $alignment = 4;
 
     # force flags for this arch
     $ld .= " -m elf_i386";

@@ -288,6 +291,7 @@ sub update_funcs
 	    open(FILE, ">$mcount_s") || die "can't create $mcount_s\n";
 	    $opened = 1;
 	    print FILE "\t.section $mcount_section,\"a\",\@progbits\n";
+	    print FILE "\t.align $alignment\n";
 	}
 	printf FILE "\t%s %s + %d\n", $type, $ref_func, $offsets[$i] - $offset;
     }

Signature · 3 lines

1.5.6.5

--

Steven Rostedt

author maintainer

2008-11-08 03:55 UTC #12 lore raw

Re: [PATCH 08/10] ftrace: Align __mcount_loc sections

Quoted 6 lines · Steven Rostedt

Impact: alignment option for recordmcount.pl script
Align the __mcount_loc sections so that architectures with strict alignment requirements need not worry about performing unaligned accesses.

Quoted 6 lines

This fixes an issue where I was seeing unaligned accesses, which are not supported on our architecture (the results of an unaligned access are undefined).
Signed-off-by Matt Fleming <[email protected]>
Signed-off-by Steven Rostedt <[email protected]>

Hmm, I have Matt as the Author in my git repository, but when I did the git format-patch and sent this off via quilt, it removed him as the author :-(

I may need to write a script to force the From line to be shown in the output files.

Here's the top of that file in my quilt tree that was produced:

-------------

Quoted 1 line

From 5c681e0fbbcecae2f446a5cce2d3556a536f9719 Mon Sep 17 00:00:00 2001

From: Matt Fleming <[email protected]>
Date: Fri, 7 Nov 2008 13:26:25 +0000
Subject: [PATCH] ftrace: Align __mcount_loc sections

Impact: alignment option for recordmcount.pl script
--------------

Ingo, If you pull this from my git tree, it will keep the authorship correct.

Thanks,

-- Steve

Steven Rostedt

author maintainer

2008-11-08 03:51 UTC #13 lore raw

PATCH 9/10 ftrace: force pass of preemptoff selftest

In reply to Steven Rostedt

Impact: preemptoff not tested in selftest

Due to the BKL not being preemptable anymore, the selftest of the preemptoff code can not be tested. It requires that it is called with preemption enabled, but since the BKL is held, that is no longer the case.

This patch simply skips those tests if it detects that the context is not preemptable. The following will now show up in the tests:

Testing tracer preemptoff: can not test ... force PASSED Testing tracer preemptirqsoff: can not test ... force PASSED

When the BKL is removed, or it becomes preemptable once again, then the tests will be performed.

Signed-off-by Steven Rostedt <[email protected]>

---
 kernel/trace/trace_selftest.c |   26 ++++++++++++++++++++++++++
 1 files changed, 26 insertions(+), 0 deletions(-)

kernel/trace/trace_selftest.c +26 -0

index ea4e5d3..0728a10 100644
@@ -257,6 +257,19 @@ trace_selftest_startup_preemptoff(struct tracer *trace, struct trace_array *tr)
 	unsigned long count;
 	int ret;
 
+	/*
+	 * Now that the big kernel lock is no longer preemptable,
+	 * and this is called with the BKL held, it will always
+	 * fail. If preemption is already disabled, simply
+	 * pass the test. When the BKL is removed, or becomes
+	 * preemptible again, we will once again test this,
+	 * so keep it in.
+	 */
+	if (preempt_count()) {
+		printk(KERN_CONT "can not test ... force ");
+		return 0;
+	}
+
 	/* start the tracing */
 	trace->init(tr);
 	/* reset the max latency */

@@ -293,6 +306,19 @@ trace_selftest_startup_preemptirqsoff(struct tracer *trace, struct trace_array *
 	unsigned long count;
 	int ret;
 
+	/*
+	 * Now that the big kernel lock is no longer preemptable,
+	 * and this is called with the BKL held, it will always
+	 * fail. If preemption is already disabled, simply
+	 * pass the test. When the BKL is removed, or becomes
+	 * preemptible again, we will once again test this,
+	 * so keep it in.
+	 */
+	if (preempt_count()) {
+		printk(KERN_CONT "can not test ... force ");
+		return 0;
+	}
+
 	/* start the tracing */
 	trace->init(tr);

Signature · 3 lines

1.5.6.5

--

Steven Rostedt

author maintainer

2008-11-08 03:50 UTC #14 lore raw

PATCH 10/10 ftrace: display start of CPU buffer in trace output

In reply to Steven Rostedt

Impact: change in trace output

Because the trace buffers are per cpu ring buffers, the start of the trace can be confusing. If one CPU is very active at the end of the trace, its history will not go as far back as the other CPU traces. This means that output for a particular CPU may not appear for the first part of a trace.

To help annotate what is happening, and to prevent any more confusion, this patch adds a line that annotates the start of a CPU buffer output.

For example:

# tracer: function
#
# TASK-PID CPU# TIMESTAMP FUNCTION
# | | | | |
##### CPU 1 buffer started ####

       automount-3495  [001]   184.596443: dnotify_parent <-vfs_write
[...]
       automount-3495  [001]   184.596449: dput <-path_put
##### CPU 2 buffer started ####
       automount-3496  [002]   184.596450: down_read_trylock <-do_page_fault
[...]
           sshd-3497  [001]   184.597069: up_read <-do_page_fault
##### CPU 0 buffer started ####
          <idle>-0     [000]   184.597074: __exit_idle <-exit_idle
[...]
       automount-3496  [002]   184.597257: filemap_fault <-__do_fault
##### CPU 3 buffer started ####
          <idle>-0     [003]   184.597261: exit_idle <-smp_apic_timer_interrupt

Note, parsers of a trace output should always ignore any lines that start with a '#'.

Signed-off-by Steven Rostedt <[email protected]>

CC Thomas Gleixner <[email protected]>

---
 kernel/trace/trace.c |   19 +++++++++++++++++++
 kernel/trace/trace.h |    2 ++
 2 files changed, 21 insertions(+), 0 deletions(-)

kernel/trace/trace.c +19 -0

index 5843541..f147f19 100644
@@ -1478,6 +1478,17 @@ void trace_seq_print_cont(struct trace_seq *s, struct trace_iterator *iter)
 		trace_seq_putc(s, '\n');
 }
 
+static void test_cpu_buff_start(struct trace_iterator *iter)
+{
+	struct trace_seq *s = &iter->seq;
+
+	if (cpu_isset(iter->cpu, iter->started))
+		return;
+
+	cpu_set(iter->cpu, iter->started);
+	trace_seq_printf(s, "##### CPU %u buffer started ####\n", iter->cpu);
+}
+
 static enum print_line_t
 print_lat_fmt(struct trace_iterator *iter, unsigned int trace_idx, int cpu)
 {

@@ -1497,6 +1508,8 @@ print_lat_fmt(struct trace_iterator *iter, unsigned int trace_idx, int cpu)
 	if (entry->type == TRACE_CONT)
 		return TRACE_TYPE_HANDLED;
 
+	test_cpu_buff_start(iter);
+
 	next_entry = find_next_entry(iter, NULL, &next_ts);
 	if (!next_entry)
 		next_ts = iter->ts;

@@ -1612,6 +1625,8 @@ static enum print_line_t print_trace_fmt(struct trace_iterator *iter)
 	if (entry->type == TRACE_CONT)
 		return TRACE_TYPE_HANDLED;
 
+	test_cpu_buff_start(iter);
+
 	comm = trace_find_cmdline(iter->ent->pid);
 
 	t = ns2usecs(iter->ts);

@@ -2631,6 +2646,10 @@ static int tracing_open_pipe(struct inode *inode, struct file *filp)
 		return -ENOMEM;
 
 	mutex_lock(&trace_types_lock);
+
+	/* trace pipe does not show start of buffer */
+	cpus_setall(iter->started);
+
 	iter->tr = &global_trace;
 	iter->trace = current_trace;
 	filp->private_data = iter;

kernel/trace/trace.h +2 -0

index cfda9d2..9781450 100644
@@ -277,6 +277,8 @@ struct trace_iterator {
 	unsigned long		iter_flags;
 	loff_t			pos;
 	long			idx;
+
+	cpumask_t		started;
 };
 
 int tracing_is_enabled(void);

Signature · 3 lines

1.5.6.5

--

Ingo Molnar

2008-11-08 08:42 UTC #15 lore raw

In reply to Steven Rostedt

Quoted 24 lines · Steven Rostedt

Ingo,
The following patches are in:
git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-2.6-trace.git
branch: tip/devel
Matt Fleming (1):
ftrace: Align __mcount_loc sections
Steven Rostedt (9):
ftrace: fix set_ftrace_filter
ftrace: fix boot trace sched startup
ftrace: fix sched_switch API
ftrace: irqsoff tracer incorrect reset
ftrace: enable trace_printk by default
ftrace: remove ctrl_update method
ftrace: remove trace array ctrl
ftrace: force pass of preemptoff selftest
ftrace: display start of CPU buffer in trace output
----

Quoted 14 lines

 kernel/trace/ftrace.c             |    3 +
 kernel/trace/trace.c              |   43 +++++++++++--------
 kernel/trace/trace.h              |    8 ++-
 kernel/trace/trace_boot.c         |   22 ++++------
 kernel/trace/trace_functions.c    |   15 +------
 kernel/trace/trace_irqsoff.c      |   19 +--------
 kernel/trace/trace_mmiotrace.c    |   22 ++++------
 kernel/trace/trace_nop.c          |   16 +------
 kernel/trace/trace_sched_switch.c |   77 ++++++++++++++++++++++++----------
 kernel/trace/trace_sched_wakeup.c |   21 ++--------
 kernel/trace/trace_selftest.c     |   82 +++++++++++++++++++++++-------------
 kernel/trace/trace_sysprof.c      |   16 +------
 scripts/recordmcount.pl           |    4 ++
 13 files changed, 172 insertions(+), 176 deletions(-)

pulled into tip/tracing/ftrace, thanks Steve!

Ingo