ftrace updates for tip
Subsystems (2)
Steven Rostedt
maintainercover 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(-)
Steven Rostedt
maintainerPATCH 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
@@ -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
@@ -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 --
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_entriestobuffer_sizeThe 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 oftrace_entriespointless.Since
trace_sizemight 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 <[email protected]>--- Documentation/ftrace.txt | 18 +++++++++--------- kernel/trace/trace.c | 4 ++-- 2 files changed, 11 insertions(+), 11 deletions(-)Documentation/ftrace.txt +9
-9@@ -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 85kernel/trace/trace.c +2
-3@@ -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.
Steven Rostedt
maintainerPATCH 2/3 ftrace: rename iter_ctrl to trace_options
In reply to Steven RostedtImpact: 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
@@ -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
@@ -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 --
Steven Rostedt
maintainerPATCH 3/3 ftrace: CPU buffer start annotation clean ups
In reply to Steven RostedtImpact: 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
@@ -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
@@ -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 --
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_entrieswill be renamed tobuffer_size
iter_ctrlwill be renamed totrace_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: renametrace_entriestobuffer_size
ftrace: renameiter_ctrltotrace_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