Skip to contentSkip to conversation

tracing: make a snapshot feature available from userspace

PATCH Superseded Hiraku Toyooka 2 participants 8 messages Dec 19, 2012 – Jan 24, 2013

Subsystems (3)

v3 of 4 Superseded Latest is v4 →

lore
Share & tools
lore
#0 lore raw

v3 cover tracing: make a snapshot feature available from userspace

Hi, Steven,

Thank you for your review.
I applied your review comments.

These patches depend on the next patch.

tracing: Add a resize function to make one buffer equivalent to another buffer
http://lkml.kernel.org/r/20121017025616.2627.91226.stgit@falsita

v2->v3:
[1/4] tracing: add checks if tr->buffer is NULL in tracing_reset{_online_cpus}
- (new patch)
[2/4] tracing: replace static old_tracer with strcmp
- (new patch)
[3/4] tracing: make a snapshot feature available from userspace
- changed snapshot file I/F (removed "snapshot_allocate")
- changed CONFIG_TRACER_SNAPSHOT's location and description
- changed an integer flag of __tracing_open() to bool
- switched to use seq_read() directly for reading snapshot
[4/4] tracing: add description of snapshot to Documentation/trace/ftrace.txt
- updated documentation of the snapshot

ToDo:
- adding "trace_snapshot" kernel parameter to allocate spare buffer on boot.

(v1: https://lkml.org/lkml/2012/10/2/67)
(v2: https://lkml.org/lkml/2012/10/16/585)

---

Hiraku Toyooka (4):
tracing: add checks if tr->buffer is NULL in tracing_reset{_online_cpus}
tracing: replace static old_tracer with strcmp
tracing: make a snapshot feature available from userspace
tracing: add description of snapshot to Documentation/trace/ftrace.txt

 Documentation/trace/ftrace.txt |   83 +++++++++++++++++++++
 include/linux/ftrace_event.h   |    3 +
 kernel/trace/Kconfig           |   10 +++
 kernel/trace/trace.c           |  158 ++++++++++++++++++++++++++++++++++------
 kernel/trace/trace.h           |    1 
 5 files changed, 231 insertions(+), 24 deletions(-)
Signature · 4 lines
Hiraku TOYOOKA
Linux Technology Center
Yokohama Research Laboratory
Hitachi Ltd.
#1 lore raw

PATCH v3 1/4 tracing: add checks if tr->buffer is NULL in tracing_reset{_online_cpus}

max_tr->buffer could be NULL in the tracing_reset{_online_cpus}. In this case, a NULL pointer dereference happens, so we should return immediately from these functions.

Cc Steven Rostedt <[email protected]>
Cc Frederic Weisbecker <[email protected]>
Cc Ingo Molnar <[email protected]>
---
 kernel/trace/trace.c |    6 ++++++
 1 file changed, 6 insertions(+)
kernel/trace/trace.c +6 -0
index c705c7a..a8ce008 100644
@@ -922,6 +922,9 @@ void tracing_reset(struct trace_array *tr, int cpu)
 {
 	struct ring_buffer *buffer = tr->buffer;
 
+	if (!buffer)
+		return;
+
 	ring_buffer_record_disable(buffer);
 
 	/* Make sure all commits have finished */
@@ -936,6 +939,9 @@ void tracing_reset_online_cpus(struct trace_array *tr)
 	struct ring_buffer *buffer = tr->buffer;
 	int cpu;
 
+	if (!buffer)
+		return;
+
 	ring_buffer_record_disable(buffer);
 
 	/* Make sure all commits have finished */
#2 lore raw

[tip:perf/core] tracing: Add checks if tr-> buffer is NULL in tracing_reset{_online_cpus}

Commit-ID:  a54164114b96b4693b42cdb553260eec41ea4393
Gitweb:     http://git.kernel.org/tip/a54164114b96b4693b42cdb553260eec41ea4393
Author:     Hiraku Toyooka <[email protected]>
AuthorDate: Wed, 19 Dec 2012 16:02:34 +0900
Committer:  Steven Rostedt <[email protected]>
CommitDate: Mon, 21 Jan 2013 13:22:32 -0500

tracing: Add checks if tr->buffer is NULL in tracing_reset{_online_cpus}

max_tr->buffer could be NULL in the tracing_reset{_online_cpus}. In this case, a NULL pointer dereference happens, so we should return immediately from these functions.

Note, the current code does not call tracing_reset*() with max_tr when its buffer is NULL, but future code will. This patch is needed to prevent the future code from crashing.

---
 kernel/trace/trace.c | 6 ++++++
 1 file changed, 6 insertions(+)
kernel/trace/trace.c +6 -0
index f8b7c62..72b171b 100644
@@ -922,6 +922,9 @@ void tracing_reset(struct trace_array *tr, int cpu)
 {
 	struct ring_buffer *buffer = tr->buffer;
 
+	if (!buffer)
+		return;
+
 	ring_buffer_record_disable(buffer);
 
 	/* Make sure all commits have finished */
@@ -936,6 +939,9 @@ void tracing_reset_online_cpus(struct trace_array *tr)
 	struct ring_buffer *buffer = tr->buffer;
 	int cpu;
 
+	if (!buffer)
+		return;
+
 	ring_buffer_record_disable(buffer);
 
 	/* Make sure all commits have finished */
#3 lore raw

PATCH v3 2/4 tracing: replace static old_tracer with strcmp

In reply to Hiraku Toyooka

Currently, read functions for trace buffer use static "old_tracer" for detecting changes of current tracer. This is because we can assume that these functions are used from only one file ("trace").

But we are adding snapshot feature for ftrace, then those functions are called from two files. So we remove all static "old_tracer", and replace those with string comparison between current and previous tracers.

Cc Steven Rostedt <[email protected]>
Cc Frederic Weisbecker <[email protected]>
Cc Ingo Molnar <[email protected]>
---
 kernel/trace/trace.c |   18 ++++++------------
 1 file changed, 6 insertions(+), 12 deletions(-)
kernel/trace/trace.c +6 -12
index a8ce008..8d05a44 100644
@@ -1948,7 +1948,6 @@ void tracing_iter_reset(struct trace_iterator *iter, int cpu)
 static void *s_start(struct seq_file *m, loff_t *pos)
 {
 	struct trace_iterator *iter = m->private;
-	static struct tracer *old_tracer;
 	int cpu_file = iter->cpu_file;
 	void *p = NULL;
 	loff_t l = 0;
@@ -1956,10 +1955,9 @@ static void *s_start(struct seq_file *m, loff_t *pos)
 
 	/* copy the tracer to avoid using a global lock all around */
 	mutex_lock(&trace_types_lock);
-	if (unlikely(old_tracer != current_trace && current_trace)) {
-		old_tracer = current_trace;
+	if (unlikely(current_trace &&
+		     strcmp(iter->trace->name, current_trace->name) != 0))
 		*iter->trace = *current_trace;
-	}
 	mutex_unlock(&trace_types_lock);
 
 	atomic_inc(&trace_record_cmdline_disabled);
@@ -3481,7 +3479,6 @@ tracing_read_pipe(struct file *filp, char __user *ubuf,
 		  size_t cnt, loff_t *ppos)
 {
 	struct trace_iterator *iter = filp->private_data;
-	static struct tracer *old_tracer;
 	ssize_t sret;
 
 	/* return any leftover data */
@@ -3493,10 +3490,9 @@ tracing_read_pipe(struct file *filp, char __user *ubuf,
 
 	/* copy the tracer to avoid using a global lock all around */
 	mutex_lock(&trace_types_lock);
-	if (unlikely(old_tracer != current_trace && current_trace)) {
-		old_tracer = current_trace;
+	if (unlikely(current_trace &&
+		     strcmp(iter->trace->name, current_trace->name) != 0))
 		*iter->trace = *current_trace;
-	}
 	mutex_unlock(&trace_types_lock);
 
 	/*
@@ -3652,7 +3648,6 @@ static ssize_t tracing_splice_read_pipe(struct file *filp,
 		.ops		= &tracing_pipe_buf_ops,
 		.spd_release	= tracing_spd_release_pipe,
 	};
-	static struct tracer *old_tracer;
 	ssize_t ret;
 	size_t rem;
 	unsigned int i;
@@ -3662,10 +3657,9 @@ static ssize_t tracing_splice_read_pipe(struct file *filp,
 
 	/* copy the tracer to avoid using a global lock all around */
 	mutex_lock(&trace_types_lock);
-	if (unlikely(old_tracer != current_trace && current_trace)) {
-		old_tracer = current_trace;
+	if (unlikely(current_trace &&
+		     strcmp(iter->trace->name, current_trace->name) != 0))
 		*iter->trace = *current_trace;
-	}
 	mutex_unlock(&trace_types_lock);
 
 	mutex_lock(&iter->mutex);
maintainer
#4 lore raw

Re: [PATCH v3 -tip 2/4] tracing: replace static old_tracer with strcmp

Quoted 8 lines · Hiraku Toyooka

Currently, read functions for trace buffer use static "old_tracer" for detecting changes of current tracer. This is because we can assume that these functions are used from only one file ("trace").

But we are adding snapshot feature for ftrace, then those functions are called from two files. So we remove all static "old_tracer", and replace those with string comparison between current and previous tracers.

I reworded what you wrote:

---
Currently the trace buffer read functions use a static variable "old_tracer" for detecting if the current tracer changes. This was suitable for a single trace file ("trace"), but to add a snapshot feature that will use the same function for its file, a check against a static variable is not sufficient.

To use the output functions for two different files, instead of storing the current tracer in a static variable, as the trace iterator descriptor
contains a pointer to the original current tracer's name, that pointer can now be used to check if the current tracer has changed between different reads of the trace file.
---

And I also realized a more efficient approach.

Quoted 23 lines
Cc Steven Rostedt <[email protected]>
Cc Frederic Weisbecker <[email protected]>
Cc Ingo Molnar <[email protected]>
---
 kernel/trace/trace.c |   18 ++++++------------
 1 file changed, 6 insertions(+), 12 deletions(-)
kernel/trace/trace.c +0 -1
index a8ce008..8d05a44 100644
@@ -1948,7 +1948,6 @@ void tracing_iter_reset(struct trace_iterator *iter, int cpu)
 static void *s_start(struct seq_file *m, loff_t *pos)
 {
 	struct trace_iterator *iter = m->private;
-	static struct tracer *old_tracer;
 	int cpu_file = iter->cpu_file;
 	void *p = NULL;
 	loff_t l = 0;

kernel/trace/trace.c static void *s_start(struct seq_file *m, loff_t *pos) · line 1960

Quoted 8 lines
kernel/trace/trace.c +2 -2
@@ -1956,10 +1955,9 @@ static void *s_start(struct seq_file *m, loff_t *pos)
 
 	/* copy the tracer to avoid using a global lock all around */
 	mutex_lock(&trace_types_lock);
-	if (unlikely(old_tracer != current_trace && current_trace)) {
-		old_tracer = current_trace;
+	if (unlikely(current_trace &&
+		     strcmp(iter->trace->name, current_trace->name) != 0))
 		*iter->trace = *current_trace;

As iter->trace is a copy of current_trace, it points to everything that the current_trace pointed to. As the current_trace->name is a pointer to a const char string that never changes, we don't need to do the strcmp() you can simply do a direct comparison:

	if (unlikely(current_trace && iter->trace->name != current_trace->name)) {

I would add a comment about that too:
/*
* iter->trace is a copy of current_trace, the pointer to the
* name may be used instead of a strcmp(), as iter->trace->name
* will point to the same string as current_trace->name. */

-- Steve

Quoted 46 lines
kernel/trace/trace.c +4 -9
-	}
 	mutex_unlock(&trace_types_lock);
 
 	atomic_inc(&trace_record_cmdline_disabled);
@@ -3481,7 +3479,6 @@ tracing_read_pipe(struct file *filp, char __user *ubuf,
 		  size_t cnt, loff_t *ppos)
 {
 	struct trace_iterator *iter = filp->private_data;
-	static struct tracer *old_tracer;
 	ssize_t sret;
 
 	/* return any leftover data */
@@ -3493,10 +3490,9 @@ tracing_read_pipe(struct file *filp, char __user *ubuf,
 
 	/* copy the tracer to avoid using a global lock all around */
 	mutex_lock(&trace_types_lock);
-	if (unlikely(old_tracer != current_trace && current_trace)) {
-		old_tracer = current_trace;
+	if (unlikely(current_trace &&
+		     strcmp(iter->trace->name, current_trace->name) != 0))
 		*iter->trace = *current_trace;
-	}
 	mutex_unlock(&trace_types_lock);
 
 	/*
@@ -3652,7 +3648,6 @@ static ssize_t tracing_splice_read_pipe(struct file *filp,
 		.ops		= &tracing_pipe_buf_ops,
 		.spd_release	= tracing_spd_release_pipe,
 	};
-	static struct tracer *old_tracer;
 	ssize_t ret;
 	size_t rem;
 	unsigned int i;
@@ -3662,10 +3657,9 @@ static ssize_t tracing_splice_read_pipe(struct file *filp,
 
 	/* copy the tracer to avoid using a global lock all around */
 	mutex_lock(&trace_types_lock);
-	if (unlikely(old_tracer != current_trace && current_trace)) {
-		old_tracer = current_trace;
+	if (unlikely(current_trace &&
+		     strcmp(iter->trace->name, current_trace->name) != 0))
 		*iter->trace = *current_trace;
-	}
 	mutex_unlock(&trace_types_lock);
 
 	mutex_lock(&iter->mutex);
#5 lore raw

Re: [PATCH v3 -tip 2/4] tracing: replace static old_tracer with strcmp

Hi,

Quoted 5 lines · Steven Rostedt
Quoted 4 lines · Hiraku Toyooka

Currently, read functions for trace buffer use static "old_tracer" for detecting changes of current tracer. This is because we can assume that these functions are used from only one file ("trace").

Quoted 7 lines
Quoted 4 lines

But we are adding snapshot feature for ftrace, then those functions are called from two files. So we remove all static "old_tracer", and replace those with string comparison between current and previous tracers.

I reworded what you wrote:

Thank you very much.

Quoted 54 lines

---
Currently the trace buffer read functions use a static variable "old_tracer" for detecting if the current tracer changes. This was suitable for a single trace file ("trace"), but to add a snapshot feature that will use the same function for its file, a check against a static variable is not sufficient.

To use the output functions for two different files, instead of storing the current tracer in a static variable, as the trace iterator descriptor
contains a pointer to the original current tracer's name, that pointer can now be used to check if the current tracer has changed between different reads of the trace file.
---

And I also realized a more efficient approach.

Quoted 23 lines
Cc Steven Rostedt <[email protected]>
Cc Frederic Weisbecker <[email protected]>
Cc Ingo Molnar <[email protected]>
---
  kernel/trace/trace.c |   18 ++++++------------
  1 file changed, 6 insertions(+), 12 deletions(-)
kernel/trace/trace.c +0 -1
index a8ce008..8d05a44 100644
@@ -1948,7 +1948,6 @@ void tracing_iter_reset(struct trace_iterator *iter, int cpu)
  static void *s_start(struct seq_file *m, loff_t *pos)
  {
  	struct trace_iterator *iter = m->private;
-	static struct tracer *old_tracer;
  	int cpu_file = iter->cpu_file;
  	void *p = NULL;
  	loff_t l = 0;

kernel/trace/trace.c static void *s_start(struct seq_file *m, loff_t *pos) · line 1960

Quoted 8 lines
kernel/trace/trace.c +2 -2
@@ -1956,10 +1955,9 @@ static void *s_start(struct seq_file *m, loff_t *pos)
 
  	/* copy the tracer to avoid using a global lock all around */
  	mutex_lock(&trace_types_lock);
-	if (unlikely(old_tracer != current_trace && current_trace)) {
-		old_tracer = current_trace;
+	if (unlikely(current_trace &&
+		     strcmp(iter->trace->name, current_trace->name) != 0))
  		*iter->trace = *current_trace;

As iter->trace is a copy of current_trace, it points to everything that the current_trace pointed to. As the current_trace->name is a pointer to a const char string that never changes, we don't need to do the strcmp() you can simply do a direct comparison:

Quoted 2 lines
	if (unlikely(current_trace && iter->trace->name != current_trace->name)) {

Yes. I'll update my patch to use this efficient way.

Quoted 6 lines

I would add a comment about that too:
/*
* iter->trace is a copy of current_trace, the pointer to the
* name may be used instead of a strcmp(), as iter->trace->name
* will point to the same string as current_trace->name. */

OK. I'll include this comment in my patch.

Thanks,
Hiraku Toyooka

#6 lore raw

PATCH v3 3/4 tracing: make a snapshot feature available from userspace

In reply to Hiraku Toyooka

Ftrace has a snapshot feature available from kernel space and latency tracers (e.g. irqsoff) are using it. This patch enables user applictions to take a snapshot via debugfs.

Add "snapshot" debugfs file in "tracing" directory.

snapshot:
This is used to take a snapshot and to read the output of the snapshot.

# echo 1 > snapshot

This will allocate the spare buffer for snapshot (if it is not allocated), and take a snapshot.

# cat snapshot

This will show contents of the snapshot.

# echo 0 > snapshot

This will free the snapshot if it is allocated.

Any other positive values will clear the snapshot contents if the snapshot is allocated, or return EINVAL if it is not allocated.

Cc Steven Rostedt <[email protected]>
Cc Frederic Weisbecker <[email protected]>
Cc Ingo Molnar <[email protected]>
Cc Jiri Olsa <[email protected]>
Cc David Sharp <[email protected]>
---
 include/linux/ftrace_event.h |    3 +
 kernel/trace/Kconfig         |   10 +++
 kernel/trace/trace.c         |  134 ++++++++++++++++++++++++++++++++++++++----
 kernel/trace/trace.h         |    1 
 4 files changed, 136 insertions(+), 12 deletions(-)
include/linux/ftrace_event.h +3 -0
index a3d4895..9bebadd 100644
@@ -84,6 +84,9 @@ struct trace_iterator {
 	long			idx;
 
 	cpumask_var_t		started;
+
+	/* it's true when current open file is snapshot */
+	bool			snapshot;
 };
 
 enum trace_iter_flags {
kernel/trace/Kconfig +10 -0
index 5d89335..82a8ff5 100644
@@ -250,6 +250,16 @@ config FTRACE_SYSCALLS
 	help
 	  Basic tracer to catch the syscall entry and exit events.
 
+config TRACER_SNAPSHOT
+	bool "Create a snapshot trace buffer"
+	select TRACER_MAX_TRACE
+	help
+	  Allow tracing users to take snapshot of the current buffer using the
+	  ftrace interface, e.g.:
+
+	      echo 1 > /sys/kernel/debug/tracing/snapshot
+	      cat snapshot
+
 config TRACE_BRANCH_PROFILING
 	bool
 	select GENERIC_TRACER
kernel/trace/trace.c +122 -12

227 lines not on this page · raw message

kernel/trace/trace.h +1 -0
index c75d798..512afe5 100644
@@ -287,6 +287,7 @@ struct tracer {
 	struct tracer_flags	*flags;
 	bool			print_max;
 	bool			use_max_tr;
+	bool			allocated_snapshot;
 };
 
 
#7 lore raw

PATCH v3 4/4 tracing: add description of snapshot to Documentation/trace/ftrace.txt

In reply to Hiraku Toyooka

This patch adds snapshot description in ftrace documentation. This description includes what the snapshot is and how to use it.

Cc Steven Rostedt <[email protected]>
Cc Frederic Weisbecker <[email protected]>
Cc Ingo Molnar <[email protected]>
Cc Rob Landley <[email protected]>
---
 Documentation/trace/ftrace.txt |   83 ++++++++++++++++++++++++++++++++++++++++
 1 file changed, 83 insertions(+)
Documentation/trace/ftrace.txt +83 -0
index 6f51fed..53d6a3c 100644
@@ -1842,6 +1842,89 @@ an error.
  # cat buffer_size_kb
 85
 
+Snapshot
+--------
+CONFIG_TRACER_SNAPSHOT makes a generic snapshot feature
+available to all non latency tracers. (Latency tracers which
+record max latency, such as "irqsoff" or "wakeup", can't use
+this feature, since those are already using the snapshot
+mechanism internally.)
+
+Snapshot preserves a current trace buffer at a particular point
+in time without stopping tracing. Ftrace swaps the current
+buffer with a spare buffer, and tracing continues in the new
+current (=previous spare) buffer.
+
+The following debugfs files in "tracing" are related to this
+feature:
+
+  snapshot:
+
+	This is used to take a snapshot and to read the output
+	of the snapshot. Echo 1 into this file to allocate a
+	spare buffer and to take a snapshot (swap), then read
+	the snapshot from this file in the same format as
+	"trace" (described above in the section "The File
+	System"). Both reads snapshot and tracing are executable
+	in parallel. When the spare buffer is allocated, echoing
+	0 frees it, and echoing else (positive) values clear the
+	snapshot contents.
+	More details are shown in the table below.
+
+	status\input  |     0      |     1      |    else    |
+	--------------+------------+------------+------------+
+	not allocated |(do nothing)| alloc+swap |   EINVAL   |
+	--------------+------------+------------+------------+
+	allocated     |    free    |    swap    |   clear    |
+	--------------+------------+------------+------------+
+
+Here is an example of using the snapshot feature.
+
+ # echo 1 > events/sched/enable
+ # echo 1 > snapshot
+ # cat snapshot
+# tracer: nop
+#
+# entries-in-buffer/entries-written: 71/71   #P:8
+#
+#                              _-----=> irqs-off
+#                             / _----=> need-resched
+#                            | / _---=> hardirq/softirq
+#                            || / _--=> preempt-depth
+#                            ||| /     delay
+#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
+#              | |       |   ||||       |         |
+          <idle>-0     [005] d...  2440.603828: sched_switch: prev_comm=swapper/5 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=snapshot-test-2 next_pid=2242 next_prio=120
+           sleep-2242  [005] d...  2440.603846: sched_switch: prev_comm=snapshot-test-2 prev_pid=2242 prev_prio=120 prev_state=R ==> next_comm=kworker/5:1 next_pid=60 next_prio=120
+[...]
+          <idle>-0     [002] d...  2440.707230: sched_switch: prev_comm=swapper/2 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=snapshot-test-2 next_pid=2229 next_prio=120
+
+ # cat trace
+# tracer: nop
+#
+# entries-in-buffer/entries-written: 77/77   #P:8
+#
+#                              _-----=> irqs-off
+#                             / _----=> need-resched
+#                            | / _---=> hardirq/softirq
+#                            || / _--=> preempt-depth
+#                            ||| /     delay
+#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
+#              | |       |   ||||       |         |
+          <idle>-0     [007] d...  2440.707395: sched_switch: prev_comm=swapper/7 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=snapshot-test-2 next_pid=2243 next_prio=120
+ snapshot-test-2-2229  [002] d...  2440.707438: sched_switch: prev_comm=snapshot-test-2 prev_pid=2229 prev_prio=120 prev_state=S ==> next_comm=swapper/2 next_pid=0 next_prio=120
+[...]
+
+
+If you try to use this snapshot feature when current tracer is
+one of the latency tracers, you will get the following results.
+
+ # echo wakeup > current_tracer
+ # echo 1 > snapshot
+bash: echo: write error: Device or resource busy
+ # cat snapshot
+cat: snapshot: Device or resource busy
+
 -----------
 
 More details can be found in the source code, in the