[PATCH 0/5] ftrace updates for tip

[PATCH 0/5] ftrace updates for tip

[Steven Rostedt]

Ingo,

Here's some more ftrace updates.

The first should help fix the bug in lockdep.

The next are changes to the ring buffer to get ready to have it
work with splice.

The last are some clean ups for function graph.


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 (5):
      ftrace: replace raw_local_irq_save with local_irq_save
      ring-buffer: move some metadata into buffer page
      ring-buffer: read page interface
      ftrace: clean up function graph asm
      ftrace: have function graph use mcount caller address

----
 arch/x86/kernel/entry_32.S  |    1 +
 arch/x86/kernel/entry_64.S  |    1 +
 arch/x86/kernel/ftrace.c    |   20 +---
 include/linux/ring_buffer.h |    5 +
 kernel/lockdep.c            |    1 +
 kernel/trace/ring_buffer.c  |  229 ++++++++++++++++++++++++++++++++++++++-----
 kernel/trace/trace.c        |   12 +-
 kernel/trace/trace_branch.c |    4 +-
 kernel/trace/trace_stack.c  |    8 +-
 9 files changed, 226 insertions(+), 55 deletions(-)
-- 

[PATCH 0/5] ftrace: updates for tip

[Steven Rostedt]

Ingo,

Most of thes patches are improvements to function graph. I'm
working on making a way to pick a function to trace, which the
patch function entry patch is needed.

The one ring buffer patch converts all variables called 'page' to
'bpage' as per Andrew's request.

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 (5):
      ftrace: add ftrace_graph_stop
      ring-buffer: change page variables to bpage
      ftrace: print real return in dumpstack for function graph
      ftrace: function graph return for function entry
      ftrace: add checks on ret stack in function graph

----
 arch/x86/kernel/dumpstack.c    |   34 ++++++++++-
 arch/x86/kernel/dumpstack.h    |    2 +-
 arch/x86/kernel/dumpstack_32.c |    5 +-
 arch/x86/kernel/dumpstack_64.c |    7 +-
 arch/x86/kernel/entry_32.S     |    3 +
 arch/x86/kernel/entry_64.S     |    3 +
 arch/x86/kernel/ftrace.c       |   34 +++++++++--
 include/linux/ftrace.h         |    4 +-
 kernel/trace/ftrace.c          |   15 ++++-
 kernel/trace/ring_buffer.c     |  130 ++++++++++++++++++++--------------------
 kernel/trace/trace.c           |    4 +-
 kernel/trace/trace.h           |    2 +-
 12 files changed, 161 insertions(+), 82 deletions(-)

-- 

Re: [PATCH 0/5] ftrace updates for tip

[Ingo Molnar]

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

> Ingo,
> 
> Here's some more ftrace updates.
> 
> The first should help fix the bug in lockdep.

ok.

> The next are changes to the ring buffer to get ready to have it
> work with splice.

great!

> The last are some clean ups for function graph.

ok. I'll also pull the followup cleanups that you did based on Andrew's 
suggestions.

> 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 (5):
>       ftrace: replace raw_local_irq_save with local_irq_save
>       ring-buffer: move some metadata into buffer page
>       ring-buffer: read page interface
>       ftrace: clean up function graph asm
>       ftrace: have function graph use mcount caller address
> 
> ----
>  arch/x86/kernel/entry_32.S  |    1 +
>  arch/x86/kernel/entry_64.S  |    1 +
>  arch/x86/kernel/ftrace.c    |   20 +---
>  include/linux/ring_buffer.h |    5 +
>  kernel/lockdep.c            |    1 +
>  kernel/trace/ring_buffer.c  |  229 ++++++++++++++++++++++++++++++++++++++-----
>  kernel/trace/trace.c        |   12 +-
>  kernel/trace/trace_branch.c |    4 +-
>  kernel/trace/trace_stack.c  |    8 +-
>  9 files changed, 226 insertions(+), 55 deletions(-)

pulled into tip/tracing/ftrace, thanks Steve!

	Ingo

Re: [PATCH 0/5] ftrace: updates for tip

[Ingo Molnar]

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

> Ingo,
> 
> Most of thes patches are improvements to function graph. I'm
> working on making a way to pick a function to trace, which the
> patch function entry patch is needed.
> 
> The one ring buffer patch converts all variables called 'page' to
> 'bpage' as per Andrew's request.
> 
> 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 (5):
>       ftrace: add ftrace_graph_stop
>       ring-buffer: change page variables to bpage
>       ftrace: print real return in dumpstack for function graph
>       ftrace: function graph return for function entry
>       ftrace: add checks on ret stack in function graph
> 
> ----
>  arch/x86/kernel/dumpstack.c    |   34 ++++++++++-
>  arch/x86/kernel/dumpstack.h    |    2 +-
>  arch/x86/kernel/dumpstack_32.c |    5 +-
>  arch/x86/kernel/dumpstack_64.c |    7 +-
>  arch/x86/kernel/entry_32.S     |    3 +
>  arch/x86/kernel/entry_64.S     |    3 +
>  arch/x86/kernel/ftrace.c       |   34 +++++++++--
>  include/linux/ftrace.h         |    4 +-
>  kernel/trace/ftrace.c          |   15 ++++-
>  kernel/trace/ring_buffer.c     |  130 ++++++++++++++++++++--------------------
>  kernel/trace/trace.c           |    4 +-
>  kernel/trace/trace.h           |    2 +-
>  12 files changed, 161 insertions(+), 82 deletions(-)

pulled into tip/tracing/ftrace, thanks Steve!

	Ingo

[PATCH 0/5] ftrace: updates for tip

[Steven Rostedt]

Ingo,

These patches are fixes for the wakeup tracer.

The first is a fix to the empty output you reported to me earlier.

The second is a fix for the ring buffer to not record updates
if it is disabled, otherwised you can get empty traces there too.

The third is the wakeup change to record all tasks and not just
realtime tasks. It adds a wakeup_rt tracer to record only rt tasks.

The forth is the addition of the scheduling wakeup and sched switch
output to the wakeup tracer. This is very helpful data.

The last is probably the most important, and should go into 29 as well.
I never reset the timestamps used to connect the trace stamps in
the buffers. This can cause stale stamps to appear and explains
some of the really bad timestamps in the buffer I've seen.

-- Steve


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 (5):
      trace: do not disable wake up tracer on output of trace
      ring-buffer: do not swap if recording is disabled
      trace: separate out rt tasks from wakeup tracer
      wakeup-tracer: show scheduling data in output
      ring-buffer: reset timestamps when ring buffer is reset

----
 kernel/trace/ring_buffer.c        |   18 ++++++++
 kernel/trace/trace.c              |    2 +-
 kernel/trace/trace_sched_wakeup.c |   78 ++++++++++++++++++++-----------------
 3 files changed, 61 insertions(+), 37 deletions(-)

-- 

[PATCH 1/5] trace: do not disable wake up tracer on output of trace

[Steven Rostedt]

[-- Attachment #1: 0001-trace-do-not-disable-wake-up-tracer-on-output-of-tr.patch --]
[-- Type: text/plain, Size: 3332 bytes --]

From: Steven Rostedt <srostedt@redhat.com>

Impact: fix to erased trace output

To try not to have the outputing of a trace interfere with the wakeup
tracer, it would disable tracing while the output was printing. But
if a trace had started when it was disabled, it can show a partial
trace. To try to solve this, on closing of the tracer, it would
clear the trace buffer.

The latency tracers (wakeup and irqsoff) have two buffers. One for
recording and one for holding the max trace that is printed. The
clearing of the trace above should only affect the recording buffer.
But for some reason it would move the erased trace to the print
buffer. Probably due to a race with the closing of the trace and
the saving ofhe max race.

The above is all pretty useless, and if the user does not want the
printing of the trace to be traced itself, then the user can manual
disable tracing. This patch removes all the code that tries to keep
the output of the tracer from modifying the trace.

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

diff --git a/kernel/trace/trace_sched_wakeup.c b/kernel/trace/trace_sched_wakeup.c
index 42ae1e7..e27adef 100644
--- a/kernel/trace/trace_sched_wakeup.c
+++ b/kernel/trace/trace_sched_wakeup.c
@@ -262,12 +262,6 @@ out:
 	atomic_dec(&wakeup_trace->data[cpu]->disabled);
 }
 
-/*
- * save_tracer_enabled is used to save the state of the tracer_enabled
- * variable when we disable it when we open a trace output file.
- */
-static int save_tracer_enabled;
-
 static void start_wakeup_tracer(struct trace_array *tr)
 {
 	int ret;
@@ -306,13 +300,10 @@ static void start_wakeup_tracer(struct trace_array *tr)
 
 	register_ftrace_function(&trace_ops);
 
-	if (tracing_is_enabled()) {
+	if (tracing_is_enabled())
 		tracer_enabled = 1;
-		save_tracer_enabled = 1;
-	} else {
+	else
 		tracer_enabled = 0;
-		save_tracer_enabled = 0;
-	}
 
 	return;
 fail_deprobe_wake_new:
@@ -324,7 +315,6 @@ fail_deprobe:
 static void stop_wakeup_tracer(struct trace_array *tr)
 {
 	tracer_enabled = 0;
-	save_tracer_enabled = 0;
 	unregister_ftrace_function(&trace_ops);
 	unregister_trace_sched_switch(probe_wakeup_sched_switch);
 	unregister_trace_sched_wakeup_new(probe_wakeup);
@@ -350,28 +340,11 @@ static void wakeup_tracer_start(struct trace_array *tr)
 {
 	wakeup_reset(tr);
 	tracer_enabled = 1;
-	save_tracer_enabled = 1;
 }
 
 static void wakeup_tracer_stop(struct trace_array *tr)
 {
 	tracer_enabled = 0;
-	save_tracer_enabled = 0;
-}
-
-static void wakeup_tracer_open(struct trace_iterator *iter)
-{
-	/* stop the trace while dumping */
-	tracer_enabled = 0;
-}
-
-static void wakeup_tracer_close(struct trace_iterator *iter)
-{
-	/* forget about any processes we were recording */
-	if (save_tracer_enabled) {
-		wakeup_reset(iter->tr);
-		tracer_enabled = 1;
-	}
 }
 
 static struct tracer wakeup_tracer __read_mostly =
@@ -381,8 +354,6 @@ static struct tracer wakeup_tracer __read_mostly =
 	.reset		= wakeup_tracer_reset,
 	.start		= wakeup_tracer_start,
 	.stop		= wakeup_tracer_stop,
-	.open		= wakeup_tracer_open,
-	.close		= wakeup_tracer_close,
 	.print_max	= 1,
 #ifdef CONFIG_FTRACE_SELFTEST
 	.selftest    = trace_selftest_startup_wakeup,
-- 
1.5.6.5

-- 

[PATCH 2/5] ring-buffer: do not swap if recording is disabled

[Steven Rostedt]

[-- Attachment #1: 0002-ring-buffer-do-not-swap-if-recording-is-disabled.patch --]
[-- Type: text/plain, Size: 1614 bytes --]

From: Steven Rostedt <srostedt@redhat.com>

If the ring buffer recording has been disabled. Do not let
swapping of ring buffers occur. Simply return -EAGAIN.

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

diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
index 8de026d..cb260dd 100644
--- a/kernel/trace/ring_buffer.c
+++ b/kernel/trace/ring_buffer.c
@@ -2266,9 +2266,24 @@ int ring_buffer_swap_cpu(struct ring_buffer *buffer_a,
 	if (buffer_a->pages != buffer_b->pages)
 		return -EINVAL;
 
+	if (ring_buffer_flags != RB_BUFFERS_ON)
+		return -EAGAIN;
+
+	if (atomic_read(&buffer_a->record_disabled))
+		return -EAGAIN;
+
+	if (atomic_read(&buffer_b->record_disabled))
+		return -EAGAIN;
+
 	cpu_buffer_a = buffer_a->buffers[cpu];
 	cpu_buffer_b = buffer_b->buffers[cpu];
 
+	if (atomic_read(&cpu_buffer_a->record_disabled))
+		return -EAGAIN;
+
+	if (atomic_read(&cpu_buffer_b->record_disabled))
+		return -EAGAIN;
+
 	/*
 	 * We can't do a synchronize_sched here because this
 	 * function can be called in atomic context.
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 220c264..757ae6f 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -415,7 +415,7 @@ update_max_tr_single(struct trace_array *tr, struct task_struct *tsk, int cpu)
 
 	ftrace_enable_cpu();
 
-	WARN_ON_ONCE(ret);
+	WARN_ON_ONCE(ret && ret != -EAGAIN);
 
 	__update_max_tr(tr, tsk, cpu);
 	__raw_spin_unlock(&ftrace_max_lock);
-- 
1.5.6.5

-- 

[PATCH 3/5] trace: separate out rt tasks from wakeup tracer

[Steven Rostedt]

[-- Attachment #1: 0003-trace-separate-out-rt-tasks-from-wakeup-tracer.patch --]
[-- Type: text/plain, Size: 2841 bytes --]

From: Steven Rostedt <srostedt@redhat.com>

Impact: add option to trace all tasks or just RT tasks

The current wakeup tracer only traces RT task wakeups. This is
fine for those interested in wake up timings of RT tasks, but
it is useless for those that are interested in the causes
of long wakeups for non RT tasks.

This patch creates a "wakeup_rt" to implement the tracing of just
RT tasks (as the current "wakeup" does). And makes "wakeup" now
trace all tasks as an average developer would expect.

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

diff --git a/kernel/trace/trace_sched_wakeup.c b/kernel/trace/trace_sched_wakeup.c
index e27adef..f489578 100644
--- a/kernel/trace/trace_sched_wakeup.c
+++ b/kernel/trace/trace_sched_wakeup.c
@@ -25,6 +25,7 @@ static int __read_mostly	tracer_enabled;
 static struct task_struct	*wakeup_task;
 static int			wakeup_cpu;
 static unsigned			wakeup_prio = -1;
+static int			wakeup_rt;
 
 static raw_spinlock_t wakeup_lock =
 	(raw_spinlock_t)__RAW_SPIN_LOCK_UNLOCKED;
@@ -224,7 +225,7 @@ probe_wakeup(struct rq *rq, struct task_struct *p, int success)
 	tracing_record_cmdline(p);
 	tracing_record_cmdline(current);
 
-	if (likely(!rt_task(p)) ||
+	if ((wakeup_rt && !rt_task(p)) ||
 			p->prio >= wakeup_prio ||
 			p->prio >= current->prio)
 		return;
@@ -321,7 +322,7 @@ static void stop_wakeup_tracer(struct trace_array *tr)
 	unregister_trace_sched_wakeup(probe_wakeup);
 }
 
-static int wakeup_tracer_init(struct trace_array *tr)
+static int __wakeup_tracer_init(struct trace_array *tr)
 {
 	tracing_max_latency = 0;
 	wakeup_trace = tr;
@@ -329,6 +330,18 @@ static int wakeup_tracer_init(struct trace_array *tr)
 	return 0;
 }
 
+static int wakeup_tracer_init(struct trace_array *tr)
+{
+	wakeup_rt = 0;
+	return __wakeup_tracer_init(tr);
+}
+
+static int wakeup_rt_tracer_init(struct trace_array *tr)
+{
+	wakeup_rt = 1;
+	return __wakeup_tracer_init(tr);
+}
+
 static void wakeup_tracer_reset(struct trace_array *tr)
 {
 	stop_wakeup_tracer(tr);
@@ -360,6 +373,19 @@ static struct tracer wakeup_tracer __read_mostly =
 #endif
 };
 
+static struct tracer wakeup_rt_tracer __read_mostly =
+{
+	.name		= "wakeup_rt",
+	.init		= wakeup_rt_tracer_init,
+	.reset		= wakeup_tracer_reset,
+	.start		= wakeup_tracer_start,
+	.stop		= wakeup_tracer_stop,
+	.print_max	= 1,
+#ifdef CONFIG_FTRACE_SELFTEST
+	.selftest    = trace_selftest_startup_wakeup,
+#endif
+};
+
 __init static int init_wakeup_tracer(void)
 {
 	int ret;
@@ -368,6 +394,10 @@ __init static int init_wakeup_tracer(void)
 	if (ret)
 		return ret;
 
+	ret = register_tracer(&wakeup_rt_tracer);
+	if (ret)
+		return ret;
+
 	return 0;
 }
 device_initcall(init_wakeup_tracer);
-- 
1.5.6.5

-- 

[PATCH 4/5] wakeup-tracer: show scheduling data in output

[Steven Rostedt]

[-- Attachment #1: 0004-wakeup-tracer-show-scheduling-data-in-output.patch --]
[-- Type: text/plain, Size: 1768 bytes --]

From: Steven Rostedt <srostedt@redhat.com>

Impact: better data for wakeup tracer

This patch adds the wakeup and schedule calls that are used by
the scheduler tracer to make the wakeup tracer more readable.

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

diff --git a/kernel/trace/trace_sched_wakeup.c b/kernel/trace/trace_sched_wakeup.c
index f489578..93cecda 100644
--- a/kernel/trace/trace_sched_wakeup.c
+++ b/kernel/trace/trace_sched_wakeup.c
@@ -153,6 +153,7 @@ probe_wakeup_sched_switch(struct rq *rq, struct task_struct *prev,
 		goto out_unlock;
 
 	trace_function(wakeup_trace, data, CALLER_ADDR1, CALLER_ADDR2, flags, pc);
+	tracing_sched_switch_trace(wakeup_trace, data, prev, next, flags, pc);
 
 	/*
 	 * usecs conversion is slow so we try to delay the conversion
@@ -214,6 +215,7 @@ static void wakeup_reset(struct trace_array *tr)
 static void
 probe_wakeup(struct rq *rq, struct task_struct *p, int success)
 {
+	struct trace_array_cpu *data;
 	int cpu = smp_processor_id();
 	unsigned long flags;
 	long disabled;
@@ -253,9 +255,12 @@ probe_wakeup(struct rq *rq, struct task_struct *p, int success)
 
 	local_save_flags(flags);
 
-	wakeup_trace->data[wakeup_cpu]->preempt_timestamp = ftrace_now(cpu);
-	trace_function(wakeup_trace, wakeup_trace->data[wakeup_cpu],
-		       CALLER_ADDR1, CALLER_ADDR2, flags, pc);
+	data = wakeup_trace->data[wakeup_cpu];
+	data->preempt_timestamp = ftrace_now(cpu);
+	tracing_sched_wakeup_trace(wakeup_trace, data, p, current,
+				   flags, pc);
+	trace_function(wakeup_trace, data, CALLER_ADDR1, CALLER_ADDR2,
+		       flags, pc);
 
 out_locked:
 	__raw_spin_unlock(&wakeup_lock);
-- 
1.5.6.5

-- 

[PATCH 5/5] ring-buffer: reset timestamps when ring buffer is reset

[Steven Rostedt]

[-- Attachment #1: 0005-ring-buffer-reset-timestamps-when-ring-buffer-is-re.patch --]
[-- Type: text/plain, Size: 814 bytes --]

From: Steven Rostedt <srostedt@redhat.com>

Impact: fix bad times of recent resets

The ring buffer needs to reset its timestamps when reseting of the
buffer, otherwise the timestamps are stale and might be used to
calculate times in the buffer causing funny timestamps to appear.

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

diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
index cb260dd..b36d737 100644
--- a/kernel/trace/ring_buffer.c
+++ b/kernel/trace/ring_buffer.c
@@ -2166,6 +2166,9 @@ rb_reset_cpu(struct ring_buffer_per_cpu *cpu_buffer)
 
 	cpu_buffer->overrun = 0;
 	cpu_buffer->entries = 0;
+
+	cpu_buffer->write_stamp = 0;
+	cpu_buffer->read_stamp = 0;
 }
 
 /**
-- 
1.5.6.5

-- 

Re: [PATCH 1/5] trace: do not disable wake up tracer on output of trace

[Ingo Molnar]

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

> From: Steven Rostedt <srostedt@redhat.com>
> 
> Impact: fix to erased trace output
> 
> To try not to have the outputing of a trace interfere with the wakeup 
> tracer, it would disable tracing while the output was printing. But if a 
> trace had started when it was disabled, it can show a partial trace. To 
> try to solve this, on closing of the tracer, it would clear the trace 
> buffer.
> 
> The latency tracers (wakeup and irqsoff) have two buffers. One for 
> recording and one for holding the max trace that is printed. The 
> clearing of the trace above should only affect the recording buffer. But 
> for some reason it would move the erased trace to the print buffer. 
> Probably due to a race with the closing of the trace and the saving ofhe 
> max race.

hm, that race needs to be fixed then.

> The above is all pretty useless, and if the user does not want the 
> printing of the trace to be traced itself, then the user can manual 
> disable tracing. This patch removes all the code that tries to keep the 
> output of the tracer from modifying the trace.

printing of the trace should not be traced. I cannot imagine any usage 
mode where that would be interesting - and i can imagine a ton of cases 
where users would be confused/distracted by the tracer in essence zapping 
their measurement by replacing it with some uninteresting 'the tracer 
itself has wakeup delays' data.

auto-disabling latency tracing while the trace is being output is 
essential. Measurement should never impact the workload that is being 
measured.

We should fix that race instead.

	Ingo

Re: [PATCH 1/5] trace: do not disable wake up tracer on output of trace

[Ingo Molnar]

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

> auto-disabling latency tracing while the trace is being output is 
> essential. Measurement should never impact the workload that is being 
> measured.

On the other hand - the latencies caused by tracing output itself should be 
quite low, correct? If not then that needs fixing too. So i've picked up 
your change - lets see how useful the result is.

But "if it hurts, disable tracing before reading the tracing result" method 
you expressed is really not acceptable.

	Ingo

Re: [PATCH 0/5] ftrace: updates for tip

[Ingo Molnar]

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

> Ingo,
> 
> These patches are fixes for the wakeup tracer.

That was quick! :-)

> The first is a fix to the empty output you reported to me earlier.
> 
> The second is a fix for the ring buffer to not record updates if it is 
> disabled, otherwised you can get empty traces there too.
> 
> The third is the wakeup change to record all tasks and not just realtime 
> tasks. It adds a wakeup_rt tracer to record only rt tasks.
> 
> The forth is the addition of the scheduling wakeup and sched switch output 
> to the wakeup tracer. This is very helpful data.
> 
> The last is probably the most important, and should go into 29 as well. I 
> never reset the timestamps used to connect the trace stamps in the 
> buffers. This can cause stale stamps to appear and explains some of the 
> really bad timestamps in the buffer I've seen.

okay, i've pulled your fixes into tip/tracing/ftrace and i've cherry-picked 
the timestamp fix over into tracing/urgent.

Thanks,

	Ingo

Re: [PATCH 1/5] trace: do not disable wake up tracer on output of trace

[Steven Rostedt]

On Thu, 22 Jan 2009, Ingo Molnar wrote:

> 
> * Steven Rostedt <rostedt@goodmis.org> wrote:
> 
> > From: Steven Rostedt <srostedt@redhat.com>
> > 
> > Impact: fix to erased trace output
> > 
> > To try not to have the outputing of a trace interfere with the wakeup 
> > tracer, it would disable tracing while the output was printing. But if a 
> > trace had started when it was disabled, it can show a partial trace. To 
> > try to solve this, on closing of the tracer, it would clear the trace 
> > buffer.
> > 
> > The latency tracers (wakeup and irqsoff) have two buffers. One for 
> > recording and one for holding the max trace that is printed. The 
> > clearing of the trace above should only affect the recording buffer. But 
> > for some reason it would move the erased trace to the print buffer. 
> > Probably due to a race with the closing of the trace and the saving ofhe 
> > max race.
> 
> hm, that race needs to be fixed then.
> 
> > The above is all pretty useless, and if the user does not want the 
> > printing of the trace to be traced itself, then the user can manual 
> > disable tracing. This patch removes all the code that tries to keep the 
> > output of the tracer from modifying the trace.
> 
> printing of the trace should not be traced. I cannot imagine any usage 
> mode where that would be interesting - and i can imagine a ton of cases 
> where users would be confused/distracted by the tracer in essence zapping 
> their measurement by replacing it with some uninteresting 'the tracer 
> itself has wakeup delays' data.
> 
> auto-disabling latency tracing while the trace is being output is 
> essential. Measurement should never impact the workload that is being 
> measured.
> 
> We should fix that race instead.

Well actually, I don't see the output causing any issues. That's another 
point. Should we work on adding all this complex code for something that 
might not every cause an issues?  I added it because it did cause an issue 
with the irqs off traces, although I'm not sure that is true any 
more either. I just added it to the wakeup tracer just to be consistent.

With the new trace_off switch that disables the ring buffer, and the 
stopping of the swap buffers with the switch off, I do not think that this 
code is even necessary anymore.

I think I'll rip out the code from irqsoff and see if it is still an issue 
there. If not, I think we can get rid of it.

-- Steve

Re: [PATCH 1/5] trace: do not disable wake up tracer on output of trace

[Ingo Molnar]

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

> Well actually, I don't see the output causing any issues. That's another 
> point. Should we work on adding all this complex code for something that 
> might not every cause an issues?  I added it because it did cause an 
> issue with the irqs off traces, although I'm not sure that is true any 
> more either. I just added it to the wakeup tracer just to be consistent.
> 
> With the new trace_off switch that disables the ring buffer, and the 
> stopping of the swap buffers with the switch off, I do not think that 
> this code is even necessary anymore.
> 
> I think I'll rip out the code from irqsoff and see if it is still an 
> issue there. If not, I think we can get rid of it.

agreed - if the output itself does not disturb max-latency tracing in 
practice then i'm all for ripping it out.

	Ingo