[PATCH 0/3] ftrace updates for tip

[PATCH 0/3] ftrace updates for tip

[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

    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(-)

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

[Steven Rostedt]

[-- Attachment #1: 0001-ftrace-rename-trace_entries-to-buffer_size.patch --]
[-- Type: text/plain, Size: 3825 bytes --]

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).

Signed-off-by: Steven Rostedt <srostedt@redhat.com>
---
 Documentation/ftrace.txt |   18 +++++++++---------
 kernel/trace/trace.c     |    4 ++--
 2 files changed, 11 insertions(+), 11 deletions(-)

diff --git a/Documentation/ftrace.txt b/Documentation/ftrace.txt
index 9cc4d68..58cba1f 100644
--- a/Documentation/ftrace.txt
+++ b/Documentation/ftrace.txt
@@ -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
 
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 4bf070b..c681778 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -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

-- 

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

[Frédéric Weisbecker]

2008/11/12 Steven Rostedt <rostedt@goodmis.org>:
> 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).
>
> Signed-off-by: Steven Rostedt <srostedt@redhat.com>
> ---
>  Documentation/ftrace.txt |   18 +++++++++---------
>  kernel/trace/trace.c     |    4 ++--
>  2 files changed, 11 insertions(+), 11 deletions(-)
>
> diff --git a/Documentation/ftrace.txt b/Documentation/ftrace.txt
> index 9cc4d68..58cba1f 100644
> --- a/Documentation/ftrace.txt
> +++ b/Documentation/ftrace.txt
> @@ -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
>
> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> index 4bf070b..c681778 100644
> --- a/kernel/trace/trace.c
> +++ b/kernel/trace/trace.c
> @@ -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
>
> --
>



Yes this name is much more obvious.

[PATCH 2/3] ftrace: rename iter_ctrl to trace_options

[Steven Rostedt]

[-- Attachment #1: 0002-ftrace-rename-iter_ctrl-to-trace_options.patch --]
[-- Type: text/plain, Size: 4531 bytes --]

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.

Signed-off-by: Steven Rostedt <srostedt@redhat.com>
---
 Documentation/ftrace.txt |   14 +++++++-------
 kernel/trace/trace.c     |   18 +++++++++---------
 2 files changed, 16 insertions(+), 16 deletions(-)

diff --git a/Documentation/ftrace.txt b/Documentation/ftrace.txt
index 58cba1f..01ac404 100644
--- a/Documentation/ftrace.txt
+++ b/Documentation/ftrace.txt
@@ -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:
 
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index c681778..32cef26 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -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);
-- 
1.5.6.5

-- 

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

[Steven Rostedt]

[-- Attachment #1: 0003-ftrace-CPU-buffer-start-annotation-clean-ups.patch --]
[-- Type: text/plain, Size: 3152 bytes --]

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.

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

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 32cef26..40c9cc1 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -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] =
diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index 9e015f5..790ea8c 100644
--- a/kernel/trace/trace.h
+++ b/kernel/trace/trace.h
@@ -473,6 +473,7 @@ enum trace_iterator_flags {
 #ifdef CONFIG_BRANCH_TRACER
 	TRACE_ITER_BRANCH		= 0x1000,
 #endif
+	TRACE_ITER_ANNOTATE		= 0x2000,
 };
 
 /*
-- 
1.5.6.5

-- 

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

[Ingo Molnar]

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

> [
>   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

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