ftrace: overrun accounting and trace_pipe headers

This patch sets up the infrastructure to record overruns of the tracing buffer.

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

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

Index: linux-sched-devel.git/kernel/trace/trace.c
===================================================================

kernel/trace/trace.c +2 -0

@@ -612,6 +612,7 @@ void unregister_tracer(struct tracer *ty
 void tracing_reset(struct trace_array_cpu *data)
 {
 	data->trace_idx = 0;
+	data->overrun = 0;
 	data->trace_head = data->trace_tail = head_page(data);
 	data->trace_head_idx = 0;
 	data->trace_tail_idx = 0;

@@ -753,6 +754,7 @@ tracing_get_trace_entry(struct trace_arr
 	if (data->trace_head == data->trace_tail &&
 	    idx_next == data->trace_tail_idx) {
 		/* overrun */
+		data->overrun++;
 		data->trace_tail_idx++;
 		if (data->trace_tail_idx >= ENTRIES_PER_PAGE) {
 			data->trace_tail =

On Mon, 21 Apr 2008 17:09:36 -0400
Steven Rostedt <[email protected]> wrote:

....

kernel/trace/trace.c tracing_read_pipe(struct file *filp, cha · line 2518

Quoted 9 lines

kernel/trace/trace.c +5 -0

@@ -2510,6 +2511,11 @@ tracing_read_pipe(struct file *filp, cha
 	for_each_cpu_mask(cpu, mask) {
 		data = iter->tr->data[cpu];
 		__raw_spin_lock(&data->lock);
+
+		if (data->overrun > iter->last_overrun[cpu])
+			iter->overrun[cpu] +=
+				data->overrun - iter->last_overrun[cpu];
+		iter->last_overrun[cpu] = data->overrun;

Option 1: move this code earlier.
(Could also remove the `if' and make it unconditional.)

kernel/trace/trace.h struct trace_array_cpu { · line 105

Quoted 6 lines

kernel/trace/trace.h +2 -0

+++ linux-sched-devel.git/kernel/trace/trace.h	2008-04-21 14:38:09.000000000 -0400

@@ -102,6 +102,7 @@ struct trace_array_cpu {
 	void			*trace_head; /* producer */
 	void			*trace_tail; /* consumer */
 	unsigned long		trace_idx;
+	unsigned long		overrun;

Option 2: Change this into atomic_t.

kernel/trace/trace.h struct trace_seq { · line 169

Quoted 8 lines

kernel/trace/trace.h +2 -1

  * results to users and which routines might sleep, etc:
  */
 struct trace_iterator {
-	struct trace_seq	seq;
 	struct trace_array	*tr;
 	struct tracer		*trace;
+	long			last_overrun[NR_CPUS];
+	long			overrun[NR_CPUS];

The problem with these fields is that they are updated only after the read hook has been called in tracing_read_pipe(), which means all "N events lost!" entries will be one read call behind. This can be any number of events.

If trace_array_cpu::overrun was atomic_t, I could process that in the read callback. But, trace_iterator::overrun would be good, because I could just reset it to zero every time I encounter a non-zero value.

I can think of two options, the ones noted above: moving the update earlier, or using atomic_t. Or maybe do both, so that we don't have to lock the trace_array_cpu structs early and also avoid duplicating the overrun/last_overrun logic in a tracer.

What shall we do?

This patch adds a method for open_pipe and open_read to the pluggins so that they can add a header to the trace pipe call.

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

Quoted 3 lines · On Mon, 21 Apr 2008 17:09:37 -0400 Steven Rostedt <[email protected]> wrote:

This patch adds a method for open_pipe and open_read to the pluggins so that they can add a header to the trace pipe call.

Quoted 1 line

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

In addition to this, I think I need tracer::close method called on tracing_release_pipe(). Use case: the reader closes the pipe before I have printed all of my header, i.e. walked through all PCI devices, so I need to properly destroy trace_iterator::private.

I also intend to use trace_iterator::seq for printing my header, so I am looking if I can reuse code from tracing_read_pipe(). Looks like I'll extract the "return any leftover data" part into a separate function.

To check trace_iterator::overrun, I'd like to be able to use for_each_tracing_cpu(), but that is local to trace.c.

What happens when the tracing cpu mask changes? Mmiotrace does not take that into account and will continue to record with all CPUs, will this lead to problems, when mmiotrace starts to support SMP properly?

Now that I think of it, I probably want to use for_each_online_cpu() in checking for overruns... but that's not good either, if someone enables/disables a cpu during tracing. I guess you will have to / had to deal with this case in tracing core, too.

The first patch in this series adds accounting to record overruns. That is where the writing catches up to the reading of the buffer. This really only matters for trace_pipe since that's a consumer / producer output file.

The next patch adds new methods for the plugins to hook into the open_pipe and open_read, to let a plugin produce a header. The open_read method can also be used to do something when overruns are detected.

The last patch is a test patch AND SHOULD NOT BE APPLIED. It is just an example in how to use the new methods to produce a header. It simply makes the ftrace tracer produce a simple "Test header" before any output.

The first patch in this series adds accounting to record overruns. That is where the writing catches up to the reading of the buffer. This really only matters for trace_pipe since that's a consumer / producer output file.

The next patch adds new methods for the plugins to hook into the open_pipe and open_read, to let a plugin produce a header. The open_read method can also be used to do something when overruns are detected.

The last patch is a test patch AND SHOULD NOT BE APPLIED. It is just an example in how to use the new methods to produce a header. It simply makes the ftrace tracer produce a simple "Test header" before any output.

Excellent!

Quoted 3 lines · On Mon, 21 Apr 2008 17:09:35 -0400 Steven Rostedt <[email protected]> wrote:

The first patch in this series adds accounting to record overruns. That is where the writing catches up to the reading of the buffer. This really only matters for trace_pipe since that's a consumer / producer output file.

This takes me some thinking how to make the best of it, but looks like it allows me to relay the overrun events into the trace log. Very good.

Quoted 4 lines

The next patch adds new methods for the plugins to hook into the open_pipe and open_read, to let a plugin produce a header. The open_read method can also be used to do something when overruns are detected.

You mean pipe_open() and read()? :-)
And read() is pipe specific?

Ah, now I see what you mean by read() can be used to notice overruns:
it is called for every read syscall, not just in the beginning.

Quoted 5 lines

The last patch is a test patch AND SHOULD NOT BE APPLIED. It is just an example in how to use the new methods to produce a header. It simply makes the ftrace tracer produce a simple "Test header" before any output.

In function_read(), shouldn't I be doing something with filp and/or ppos?