diff options
author | Tim Bird <tim.bird@am.sony.com> | 2010-02-25 18:36:43 -0500 |
---|---|---|
committer | Steven Rostedt <rostedt@goodmis.org> | 2010-03-05 21:20:57 -0500 |
commit | 0e95017355dcf43031da6d0e360a748717e56df1 (patch) | |
tree | 829989bfb494e8d2d773d9dc1bc014b7f28d3bed /kernel | |
parent | 1acaa1b2d9b5904c9cce06122990a2d71046ce16 (diff) |
function-graph: Add tracing_thresh support to function_graph tracer
Add support for tracing_thresh to the function_graph tracer. This
version of this feature isolates the checks into new entry and
return functions, to avoid adding more conditional code into the
main function_graph paths.
When the tracing_thresh is set and the function graph tracer is
enabled, only the functions that took longer than the time in
microseconds that was set in tracing_thresh are recorded. To do this
efficiently, only the function exits are recorded:
[tracing]# echo 100 > tracing_thresh
[tracing]# echo function_graph > current_tracer
[tracing]# cat trace
# tracer: function_graph
#
# CPU DURATION FUNCTION CALLS
# | | | | | | |
1) ! 119.214 us | } /* smp_apic_timer_interrupt */
1) <========== |
0) ! 101.527 us | } /* __rcu_process_callbacks */
0) ! 126.461 us | } /* rcu_process_callbacks */
0) ! 145.111 us | } /* __do_softirq */
0) ! 149.667 us | } /* do_softirq */
0) ! 168.817 us | } /* irq_exit */
0) ! 248.254 us | } /* smp_apic_timer_interrupt */
Also, add support for specifying tracing_thresh on the kernel
command line. When used like so: "tracing_thresh=200 ftrace=function_graph"
this can be used to analyse system startup. It is important to disable
tracing soon after boot, in order to avoid losing the trace data.
Acked-by: Frederic Weisbecker <fweisbec@gmail.com>
Signed-off-by: Tim Bird <tim.bird@am.sony.com>
LKML-Reference: <4B87098B.4040308@am.sony.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
Diffstat (limited to 'kernel')
-rw-r--r-- | kernel/trace/trace.c | 20 | ||||
-rw-r--r-- | kernel/trace/trace.h | 3 | ||||
-rw-r--r-- | kernel/trace/trace_functions_graph.c | 25 |
3 files changed, 43 insertions, 5 deletions
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c index 6efd5cb3c252..ababedb4e87f 100644 --- a/kernel/trace/trace.c +++ b/kernel/trace/trace.c | |||
@@ -374,6 +374,21 @@ static int __init set_buf_size(char *str) | |||
374 | } | 374 | } |
375 | __setup("trace_buf_size=", set_buf_size); | 375 | __setup("trace_buf_size=", set_buf_size); |
376 | 376 | ||
377 | static int __init set_tracing_thresh(char *str) | ||
378 | { | ||
379 | unsigned long threshhold; | ||
380 | int ret; | ||
381 | |||
382 | if (!str) | ||
383 | return 0; | ||
384 | ret = strict_strtoul(str, 0, &threshhold); | ||
385 | if (ret < 0) | ||
386 | return 0; | ||
387 | tracing_thresh = threshhold * 1000; | ||
388 | return 1; | ||
389 | } | ||
390 | __setup("tracing_thresh=", set_tracing_thresh); | ||
391 | |||
377 | unsigned long nsecs_to_usecs(unsigned long nsecs) | 392 | unsigned long nsecs_to_usecs(unsigned long nsecs) |
378 | { | 393 | { |
379 | return nsecs / 1000; | 394 | return nsecs / 1000; |
@@ -579,9 +594,10 @@ static ssize_t trace_seq_to_buffer(struct trace_seq *s, void *buf, size_t cnt) | |||
579 | static arch_spinlock_t ftrace_max_lock = | 594 | static arch_spinlock_t ftrace_max_lock = |
580 | (arch_spinlock_t)__ARCH_SPIN_LOCK_UNLOCKED; | 595 | (arch_spinlock_t)__ARCH_SPIN_LOCK_UNLOCKED; |
581 | 596 | ||
597 | unsigned long __read_mostly tracing_thresh; | ||
598 | |||
582 | #ifdef CONFIG_TRACER_MAX_TRACE | 599 | #ifdef CONFIG_TRACER_MAX_TRACE |
583 | unsigned long __read_mostly tracing_max_latency; | 600 | unsigned long __read_mostly tracing_max_latency; |
584 | unsigned long __read_mostly tracing_thresh; | ||
585 | 601 | ||
586 | /* | 602 | /* |
587 | * Copy the new maximum trace into the separate maximum-trace | 603 | * Copy the new maximum trace into the separate maximum-trace |
@@ -4248,10 +4264,10 @@ static __init int tracer_init_debugfs(void) | |||
4248 | #ifdef CONFIG_TRACER_MAX_TRACE | 4264 | #ifdef CONFIG_TRACER_MAX_TRACE |
4249 | trace_create_file("tracing_max_latency", 0644, d_tracer, | 4265 | trace_create_file("tracing_max_latency", 0644, d_tracer, |
4250 | &tracing_max_latency, &tracing_max_lat_fops); | 4266 | &tracing_max_latency, &tracing_max_lat_fops); |
4267 | #endif | ||
4251 | 4268 | ||
4252 | trace_create_file("tracing_thresh", 0644, d_tracer, | 4269 | trace_create_file("tracing_thresh", 0644, d_tracer, |
4253 | &tracing_thresh, &tracing_max_lat_fops); | 4270 | &tracing_thresh, &tracing_max_lat_fops); |
4254 | #endif | ||
4255 | 4271 | ||
4256 | trace_create_file("README", 0444, d_tracer, | 4272 | trace_create_file("README", 0444, d_tracer, |
4257 | NULL, &tracing_readme_fops); | 4273 | NULL, &tracing_readme_fops); |
diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h index fd05bcaf91b0..1bc8cd1431d7 100644 --- a/kernel/trace/trace.h +++ b/kernel/trace/trace.h | |||
@@ -396,9 +396,10 @@ extern int process_new_ksym_entry(char *ksymname, int op, unsigned long addr); | |||
396 | 396 | ||
397 | extern unsigned long nsecs_to_usecs(unsigned long nsecs); | 397 | extern unsigned long nsecs_to_usecs(unsigned long nsecs); |
398 | 398 | ||
399 | extern unsigned long tracing_thresh; | ||
400 | |||
399 | #ifdef CONFIG_TRACER_MAX_TRACE | 401 | #ifdef CONFIG_TRACER_MAX_TRACE |
400 | extern unsigned long tracing_max_latency; | 402 | extern unsigned long tracing_max_latency; |
401 | extern unsigned long tracing_thresh; | ||
402 | 403 | ||
403 | void update_max_tr(struct trace_array *tr, struct task_struct *tsk, int cpu); | 404 | void update_max_tr(struct trace_array *tr, struct task_struct *tsk, int cpu); |
404 | void update_max_tr_single(struct trace_array *tr, | 405 | void update_max_tr_single(struct trace_array *tr, |
diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c index 7b1f24618d97..e9df04b60267 100644 --- a/kernel/trace/trace_functions_graph.c +++ b/kernel/trace/trace_functions_graph.c | |||
@@ -237,6 +237,14 @@ int trace_graph_entry(struct ftrace_graph_ent *trace) | |||
237 | return ret; | 237 | return ret; |
238 | } | 238 | } |
239 | 239 | ||
240 | int trace_graph_thresh_entry(struct ftrace_graph_ent *trace) | ||
241 | { | ||
242 | if (tracing_thresh) | ||
243 | return 1; | ||
244 | else | ||
245 | return trace_graph_entry(trace); | ||
246 | } | ||
247 | |||
240 | static void __trace_graph_return(struct trace_array *tr, | 248 | static void __trace_graph_return(struct trace_array *tr, |
241 | struct ftrace_graph_ret *trace, | 249 | struct ftrace_graph_ret *trace, |
242 | unsigned long flags, | 250 | unsigned long flags, |
@@ -290,13 +298,26 @@ void set_graph_array(struct trace_array *tr) | |||
290 | smp_mb(); | 298 | smp_mb(); |
291 | } | 299 | } |
292 | 300 | ||
301 | void trace_graph_thresh_return(struct ftrace_graph_ret *trace) | ||
302 | { | ||
303 | if (tracing_thresh && | ||
304 | (trace->rettime - trace->calltime < tracing_thresh)) | ||
305 | return; | ||
306 | else | ||
307 | trace_graph_return(trace); | ||
308 | } | ||
309 | |||
293 | static int graph_trace_init(struct trace_array *tr) | 310 | static int graph_trace_init(struct trace_array *tr) |
294 | { | 311 | { |
295 | int ret; | 312 | int ret; |
296 | 313 | ||
297 | set_graph_array(tr); | 314 | set_graph_array(tr); |
298 | ret = register_ftrace_graph(&trace_graph_return, | 315 | if (tracing_thresh) |
299 | &trace_graph_entry); | 316 | ret = register_ftrace_graph(&trace_graph_thresh_return, |
317 | &trace_graph_thresh_entry); | ||
318 | else | ||
319 | ret = register_ftrace_graph(&trace_graph_return, | ||
320 | &trace_graph_entry); | ||
300 | if (ret) | 321 | if (ret) |
301 | return ret; | 322 | return ret; |
302 | tracing_start_cmdline_record(); | 323 | tracing_start_cmdline_record(); |