Skip to contentSkip to conversation

ftrace updates for tip

PATCH In review Steven Rostedt 3 participants 6 messages Nov 12, 2008 – Nov 13, 2008

Subsystems (2)
lore
Share & tools
lore

Steven Rostedt

author maintainer
#0 lore raw

cover ftrace updates for tip

[
I added a bit more people to the Cc so that they are aware of the pending renames that are coming.

Namely, trace_entries will be renamed to buffer_size
iter_ctrl will be renamed to trace_options
]

Ingo,

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 (3):
ftrace: rename trace_entries to buffer_size
ftrace: rename iter_ctrl to trace_options
ftrace: CPU buffer start annotation clean ups

----

 Documentation/ftrace.txt |   32 ++++++++++++++++----------------
 kernel/trace/trace.c     |   38 ++++++++++++++++++++++++++------------
 kernel/trace/trace.h     |    1 +
 3 files changed, 43 insertions(+), 28 deletions(-)
author maintainer
#1 lore raw

PATCH 1/3 ftrace: rename trace_entries to buffer_size

Impact: rename of debugfs file trace_entries to buffer_size

The original ftrace had fixed size entries, and the number of entries was shown and modified via the file called trace_entries. By converting to the unified trace buffer, we now allow for variable size entries which makes the meaning of trace_entries pointless.

Since trace_size might be confused to the size of the trace, this patch names it "buffer_size" (thanks to Arjan van de Ven for this idea).

---
 Documentation/ftrace.txt |   18 +++++++++---------
 kernel/trace/trace.c     |    4 ++--
 2 files changed, 11 insertions(+), 11 deletions(-)
Documentation/ftrace.txt +9 -9
index 9cc4d68..58cba1f 100644
@@ -94,7 +94,7 @@ of ftrace. Here is a list of some of the key files:
 		only be recorded if the latency is greater than
 		the value in this file. (in microseconds)
 
-  trace_entries: This sets or displays the number of bytes each CPU
+  buffer_size: This sets or displays the number of bytes each CPU
 		buffer can hold. The tracer buffers are the same size
 		for each CPU. The displayed number is the size of the
 		 CPU buffer and not total size of all buffers. The
@@ -1299,13 +1299,13 @@ trace entries
 -------------
 
 Having too much or not enough data can be troublesome in diagnosing
-an issue in the kernel. The file trace_entries is used to modify
+an issue in the kernel. The file buffer_size is used to modify
 the size of the internal trace buffers. The number listed
 is the number of entries that can be recorded per CPU. To know
 the full size, multiply the number of possible CPUS with the
 number of entries.
 
- # cat /debug/tracing/trace_entries
+ # cat /debug/tracing/buffer_size
 65620
 
 Note, to modify this, you must have tracing completely disabled. To do that,
@@ -1313,8 +1313,8 @@ echo "nop" into the current_tracer. If the current_tracer is not set
 to "nop", an EINVAL error will be returned.
 
  # echo nop > /debug/tracing/current_tracer
- # echo 100000 > /debug/tracing/trace_entries
- # cat /debug/tracing/trace_entries
+ # echo 100000 > /debug/tracing/buffer_size
+ # cat /debug/tracing/buffer_size
 100045
 
 
@@ -1323,8 +1323,8 @@ are held in individual pages. It allocates the number of pages it takes
 to fulfill the request. If more entries may fit on the last page
 then they will be added.
 
- # echo 1 > /debug/tracing/trace_entries
- # cat /debug/tracing/trace_entries
+ # echo 1 > /debug/tracing/buffer_size
+ # cat /debug/tracing/buffer_size
 85
 
 This shows us that 85 entries can fit in a single page.
@@ -1332,8 +1332,8 @@ This shows us that 85 entries can fit in a single page.
 The number of pages which will be allocated is limited to a percentage
 of available memory. Allocating too much will produce an error.
 
- # echo 1000000000000 > /debug/tracing/trace_entries
+ # echo 1000000000000 > /debug/tracing/buffer_size
 -bash: echo: write error: Cannot allocate memory
- # cat /debug/tracing/trace_entries
+ # cat /debug/tracing/buffer_size
 85
 
kernel/trace/trace.c +2 -2
index 4bf070b..c681778 100644
@@ -3198,11 +3198,11 @@ static __init int tracer_init_debugfs(void)
 		pr_warning("Could not create debugfs "
 			   "'trace_pipe' entry\n");
 
-	entry = debugfs_create_file("trace_entries", 0644, d_tracer,
+	entry = debugfs_create_file("buffer_size", 0644, d_tracer,
 				    &global_trace, &tracing_entries_fops);
 	if (!entry)
 		pr_warning("Could not create debugfs "
-			   "'trace_entries' entry\n");
+			   "'buffer_size' entry\n");
 
 	entry = debugfs_create_file("trace_marker", 0220, d_tracer,
 				    NULL, &tracing_mark_fops);
Signature · 3 lines
1.5.6.5

-- 
#2 lore raw

Re: [PATCH 1/3] ftrace: rename trace_entries to buffer_size

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

Quoted 99 lines

Impact: rename of debugfs file trace_entries to buffer_size

The original ftrace had fixed size entries, and the number of entries was shown and modified via the file called trace_entries. By converting to the unified trace buffer, we now allow for variable size entries which makes the meaning of trace_entries pointless.

Since trace_size might be confused to the size of the trace, this patch names it "buffer_size" (thanks to Arjan van de Ven for this idea).

---
 Documentation/ftrace.txt |   18 +++++++++---------
 kernel/trace/trace.c     |    4 ++--
 2 files changed, 11 insertions(+), 11 deletions(-)
Documentation/ftrace.txt +9 -9
index 9cc4d68..58cba1f 100644
@@ -94,7 +94,7 @@ of ftrace. Here is a list of some of the key files:
               only be recorded if the latency is greater than
               the value in this file. (in microseconds)
 
-  trace_entries: This sets or displays the number of bytes each CPU
+  buffer_size: This sets or displays the number of bytes each CPU
               buffer can hold. The tracer buffers are the same size
               for each CPU. The displayed number is the size of the
                CPU buffer and not total size of all buffers. The
@@ -1299,13 +1299,13 @@ trace entries
 -------------
 
 Having too much or not enough data can be troublesome in diagnosing
-an issue in the kernel. The file trace_entries is used to modify
+an issue in the kernel. The file buffer_size is used to modify
 the size of the internal trace buffers. The number listed
 is the number of entries that can be recorded per CPU. To know
 the full size, multiply the number of possible CPUS with the
 number of entries.
 
- # cat /debug/tracing/trace_entries
+ # cat /debug/tracing/buffer_size
 65620
 
 Note, to modify this, you must have tracing completely disabled. To do that,
@@ -1313,8 +1313,8 @@ echo "nop" into the current_tracer. If the current_tracer is not set
 to "nop", an EINVAL error will be returned.
 
 # echo nop > /debug/tracing/current_tracer
- # echo 100000 > /debug/tracing/trace_entries
- # cat /debug/tracing/trace_entries
+ # echo 100000 > /debug/tracing/buffer_size
+ # cat /debug/tracing/buffer_size
 100045
 
 
@@ -1323,8 +1323,8 @@ are held in individual pages. It allocates the number of pages it takes
 to fulfill the request. If more entries may fit on the last page
 then they will be added.
 
- # echo 1 > /debug/tracing/trace_entries
- # cat /debug/tracing/trace_entries
+ # echo 1 > /debug/tracing/buffer_size
+ # cat /debug/tracing/buffer_size
 85
 
 This shows us that 85 entries can fit in a single page.
@@ -1332,8 +1332,8 @@ This shows us that 85 entries can fit in a single page.
 The number of pages which will be allocated is limited to a percentage
 of available memory. Allocating too much will produce an error.
 
- # echo 1000000000000 > /debug/tracing/trace_entries
+ # echo 1000000000000 > /debug/tracing/buffer_size
 -bash: echo: write error: Cannot allocate memory
- # cat /debug/tracing/trace_entries
+ # cat /debug/tracing/buffer_size
 85
 
kernel/trace/trace.c +2 -3
index 4bf070b..c681778 100644
@@ -3198,11 +3198,11 @@ static __init int tracer_init_debugfs(void)
               pr_warning("Could not create debugfs "
                          "'trace_pipe' entry\n");
 
-       entry = debugfs_create_file("trace_entries", 0644, d_tracer,
+       entry = debugfs_create_file("buffer_size", 0644, d_tracer,
                                   &global_trace, &tracing_entries_fops);
       if (!entry)
               pr_warning("Could not create debugfs "
-                          "'trace_entries' entry\n");
+                          "'buffer_size' entry\n");
 
       entry = debugfs_create_file("trace_marker", 0220, d_tracer,
                                   NULL, &tracing_mark_fops);
--

1.5.6.5

Quoted 2 lines

--

Yes this name is much more obvious.

author maintainer
#3 lore raw

PATCH 2/3 ftrace: rename iter_ctrl to trace_options

In reply to Steven Rostedt

Impact: debugfs file iter_ctrl renamed to trace_options

The original ftrace had a file called "iter_ctrl" that would control the way the output was iterated. But this file grew into a catch all for different trace options. This patch renames the file from iter_ctrl to trace_options to reflect this change.

---
 Documentation/ftrace.txt |   14 +++++++-------
 kernel/trace/trace.c     |   18 +++++++++---------
 2 files changed, 16 insertions(+), 16 deletions(-)
Documentation/ftrace.txt +7 -7
index 58cba1f..01ac404 100644
@@ -82,7 +82,7 @@ of ftrace. Here is a list of some of the key files:
 		tracer is not adding more data, they will display
 		the same information every time they are read.
 
-  iter_ctrl: This file lets the user control the amount of data
+  trace_options: This file lets the user control the amount of data
 		that is displayed in one of the above output
 		files.
 
@@ -316,23 +316,23 @@ The above is mostly meaningful for kernel developers.
   The rest is the same as the 'trace' file.
 
 
-iter_ctrl
----------
+trace_options
+-------------
 
-The iter_ctrl file is used to control what gets printed in the trace
+The trace_options file is used to control what gets printed in the trace
 output. To see what is available, simply cat the file:
 
-  cat /debug/tracing/iter_ctrl
+  cat /debug/tracing/trace_options
   print-parent nosym-offset nosym-addr noverbose noraw nohex nobin \
  noblock nostacktrace nosched-tree
 
 To disable one of the options, echo in the option prepended with "no".
 
-  echo noprint-parent > /debug/tracing/iter_ctrl
+  echo noprint-parent > /debug/tracing/trace_options
 
 To enable an option, leave off the "no".
 
-  echo sym-offset > /debug/tracing/iter_ctrl
+  echo sym-offset > /debug/tracing/trace_options
 
 Here are the available options:
 
kernel/trace/trace.c +9 -9
index c681778..32cef26 100644
@@ -204,7 +204,7 @@ static DEFINE_MUTEX(trace_types_lock);
 /* trace_wait is a waitqueue for tasks blocked on trace_poll */
 static DECLARE_WAIT_QUEUE_HEAD(trace_wait);
 
-/* trace_flags holds iter_ctrl options */
+/* trace_flags holds trace_options default values */
 unsigned long trace_flags = TRACE_ITER_PRINT_PARENT | TRACE_ITER_PRINTK;
 
 /**
@@ -2411,7 +2411,7 @@ static struct file_operations tracing_cpumask_fops = {
 };
 
 static ssize_t
-tracing_iter_ctrl_read(struct file *filp, char __user *ubuf,
+tracing_trace_options_read(struct file *filp, char __user *ubuf,
 		       size_t cnt, loff_t *ppos)
 {
 	char *buf;
@@ -2448,7 +2448,7 @@ tracing_iter_ctrl_read(struct file *filp, char __user *ubuf,
 }
 
 static ssize_t
-tracing_iter_ctrl_write(struct file *filp, const char __user *ubuf,
+tracing_trace_options_write(struct file *filp, const char __user *ubuf,
 			size_t cnt, loff_t *ppos)
 {
 	char buf[64];
@@ -2493,8 +2493,8 @@ tracing_iter_ctrl_write(struct file *filp, const char __user *ubuf,
 
 static struct file_operations tracing_iter_fops = {
 	.open		= tracing_open_generic,
-	.read		= tracing_iter_ctrl_read,
-	.write		= tracing_iter_ctrl_write,
+	.read		= tracing_trace_options_read,
+	.write		= tracing_trace_options_write,
 };
 
 static const char readme_msg[] =
@@ -2508,9 +2508,9 @@ static const char readme_msg[] =
 	"# echo sched_switch > /debug/tracing/current_tracer\n"
 	"# cat /debug/tracing/current_tracer\n"
 	"sched_switch\n"
-	"# cat /debug/tracing/iter_ctrl\n"
+	"# cat /debug/tracing/trace_options\n"
 	"noprint-parent nosym-offset nosym-addr noverbose\n"
-	"# echo print-parent > /debug/tracing/iter_ctrl\n"
+	"# echo print-parent > /debug/tracing/trace_options\n"
 	"# echo 1 > /debug/tracing/tracing_enabled\n"
 	"# cat /debug/tracing/trace > /tmp/trace.txt\n"
 	"echo 0 > /debug/tracing/tracing_enabled\n"
@@ -3145,10 +3145,10 @@ static __init int tracer_init_debugfs(void)
 	if (!entry)
 		pr_warning("Could not create debugfs 'tracing_enabled' entry\n");
 
-	entry = debugfs_create_file("iter_ctrl", 0644, d_tracer,
+	entry = debugfs_create_file("trace_options", 0644, d_tracer,
 				    NULL, &tracing_iter_fops);
 	if (!entry)
-		pr_warning("Could not create debugfs 'iter_ctrl' entry\n");
+		pr_warning("Could not create debugfs 'trace_options' entry\n");
 
 	entry = debugfs_create_file("tracing_cpumask", 0644, d_tracer,
 				    NULL, &tracing_cpumask_fops);
Signature · 3 lines
1.5.6.5

-- 
author maintainer
#4 lore raw

PATCH 3/3 ftrace: CPU buffer start annotation clean ups

In reply to Steven Rostedt

Impact: better handling of CPU buffer start annotation

Because of the confusion with the per CPU buffers wrapping where one CPU might be more active at the end of the trace than the other CPUs causing that one CPU to have a shorter history. Kernel developers were confused by the "missing" data of that one CPU at the beginning of the trace output. An annotation was added to the trace output to show that the buffer had started:

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

          <idle>-0     [003]   158.192959: smp_apic_timer_interrupt
[...]
          <idle>-0     [003]   161.556520: default_idle
##### CPU 1 buffer started ####
          <idle>-0     [001]   161.592494: hrtimer_force_reprogram

[etc]

But this annotation gets a bit messy when tracers do not fill the buffers. This patch does a couple of things:

One) it adds a flag to trace_options to disable these annotations

Two) it does not annotate if the tracer did not overflow its buffer.

This makes the output much cleaner.

---
 kernel/trace/trace.c |   16 +++++++++++++++-
 kernel/trace/trace.h |    1 +
 2 files changed, 16 insertions(+), 1 deletions(-)
kernel/trace/trace.c +15 -1
index 32cef26..40c9cc1 100644
@@ -205,7 +205,8 @@ static DEFINE_MUTEX(trace_types_lock);
 static DECLARE_WAIT_QUEUE_HEAD(trace_wait);
 
 /* trace_flags holds trace_options default values */
-unsigned long trace_flags = TRACE_ITER_PRINT_PARENT | TRACE_ITER_PRINTK;
+unsigned long trace_flags = TRACE_ITER_PRINT_PARENT | TRACE_ITER_PRINTK |
+	TRACE_ITER_ANNOTATE;
 
 /**
  * trace_wake_up - wake up tasks waiting for trace input
@@ -261,6 +262,7 @@ static const char *trace_options[] = {
 #ifdef CONFIG_BRANCH_TRACER
 	"branch",
 #endif
+	"annotate",
 	NULL
 };
 
@@ -1113,6 +1115,7 @@ void tracing_stop_function_trace(void)
 
 enum trace_file_type {
 	TRACE_FILE_LAT_FMT	= 1,
+	TRACE_FILE_ANNOTATE	= 2,
 };
 
 static void trace_iterator_increment(struct trace_iterator *iter, int cpu)
@@ -1532,6 +1535,12 @@ static void test_cpu_buff_start(struct trace_iterator *iter)
 {
 	struct trace_seq *s = &iter->seq;
 
+	if (!(trace_flags & TRACE_ITER_ANNOTATE))
+		return;
+
+	if (!(iter->iter_flags & TRACE_FILE_ANNOTATE))
+		return;
+
 	if (cpu_isset(iter->cpu, iter->started))
 		return;
 
@@ -2132,6 +2141,11 @@ __tracing_open(struct inode *inode, struct file *file, int *ret)
 	iter->trace = current_trace;
 	iter->pos = -1;
 
+	/* Annotate start of buffers if we had overruns */
+	if (ring_buffer_overruns(iter->tr->buffer))
+		iter->iter_flags |= TRACE_FILE_ANNOTATE;
+
+
 	for_each_tracing_cpu(cpu) {
 
 		iter->buffer_iter[cpu] =
kernel/trace/trace.h +1 -0
index 9e015f5..790ea8c 100644
@@ -473,6 +473,7 @@ enum trace_iterator_flags {
 #ifdef CONFIG_BRANCH_TRACER
 	TRACE_ITER_BRANCH		= 0x1000,
 #endif
+	TRACE_ITER_ANNOTATE		= 0x2000,
 };
 
 /*
Signature · 3 lines
1.5.6.5

-- 
#5 lore raw
In reply to Steven Rostedt
Quoted 14 lines · Steven Rostedt

[
I added a bit more people to the Cc so that they are aware of the pending renames that are coming.

Namely, trace_entries will be renamed to buffer_size
iter_ctrl will be renamed to trace_options
]

Ingo,

The following patches are in:

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

Quoted 7 lines

branch: tip/devel

Steven Rostedt (3):
ftrace: rename trace_entries to buffer_size
ftrace: rename iter_ctrl to trace_options
ftrace: CPU buffer start annotation clean ups

i've applied them to tip/tracing/ftrace, with some small changes:

12ef7d4: ftrace: CPU buffer start annotation clean ups
ee6bce5: ftrace: rename iter_ctrl to trace_options 1696b2b: ftrace: show buffer size in kilobytes
a94c80e: ftrace: rename trace_entries to buffer_size_kb

as per Arjan's suggestion i changed buffer_size to buffer_size_kb - and also removed the kilobytes string from its output.

thanks Steve!

Ingo