diff options
Diffstat (limited to 'kernel/trace/ftrace.c')
-rw-r--r-- | kernel/trace/ftrace.c | 60 |
1 files changed, 45 insertions, 15 deletions
diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c index 2404b59b3097..fa7ece649fe1 100644 --- a/kernel/trace/ftrace.c +++ b/kernel/trace/ftrace.c | |||
@@ -264,6 +264,7 @@ struct ftrace_profile { | |||
264 | unsigned long counter; | 264 | unsigned long counter; |
265 | #ifdef CONFIG_FUNCTION_GRAPH_TRACER | 265 | #ifdef CONFIG_FUNCTION_GRAPH_TRACER |
266 | unsigned long long time; | 266 | unsigned long long time; |
267 | unsigned long long time_squared; | ||
267 | #endif | 268 | #endif |
268 | }; | 269 | }; |
269 | 270 | ||
@@ -366,9 +367,9 @@ static int function_stat_headers(struct seq_file *m) | |||
366 | { | 367 | { |
367 | #ifdef CONFIG_FUNCTION_GRAPH_TRACER | 368 | #ifdef CONFIG_FUNCTION_GRAPH_TRACER |
368 | seq_printf(m, " Function " | 369 | seq_printf(m, " Function " |
369 | "Hit Time Avg\n" | 370 | "Hit Time Avg s^2\n" |
370 | " -------- " | 371 | " -------- " |
371 | "--- ---- ---\n"); | 372 | "--- ---- --- ---\n"); |
372 | #else | 373 | #else |
373 | seq_printf(m, " Function Hit\n" | 374 | seq_printf(m, " Function Hit\n" |
374 | " -------- ---\n"); | 375 | " -------- ---\n"); |
@@ -380,11 +381,19 @@ static int function_stat_show(struct seq_file *m, void *v) | |||
380 | { | 381 | { |
381 | struct ftrace_profile *rec = v; | 382 | struct ftrace_profile *rec = v; |
382 | char str[KSYM_SYMBOL_LEN]; | 383 | char str[KSYM_SYMBOL_LEN]; |
384 | int ret = 0; | ||
383 | #ifdef CONFIG_FUNCTION_GRAPH_TRACER | 385 | #ifdef CONFIG_FUNCTION_GRAPH_TRACER |
384 | static DEFINE_MUTEX(mutex); | ||
385 | static struct trace_seq s; | 386 | static struct trace_seq s; |
386 | unsigned long long avg; | 387 | unsigned long long avg; |
388 | unsigned long long stddev; | ||
387 | #endif | 389 | #endif |
390 | mutex_lock(&ftrace_profile_lock); | ||
391 | |||
392 | /* we raced with function_profile_reset() */ | ||
393 | if (unlikely(rec->counter == 0)) { | ||
394 | ret = -EBUSY; | ||
395 | goto out; | ||
396 | } | ||
388 | 397 | ||
389 | kallsyms_lookup(rec->ip, NULL, NULL, NULL, str); | 398 | kallsyms_lookup(rec->ip, NULL, NULL, NULL, str); |
390 | seq_printf(m, " %-30.30s %10lu", str, rec->counter); | 399 | seq_printf(m, " %-30.30s %10lu", str, rec->counter); |
@@ -394,17 +403,31 @@ static int function_stat_show(struct seq_file *m, void *v) | |||
394 | avg = rec->time; | 403 | avg = rec->time; |
395 | do_div(avg, rec->counter); | 404 | do_div(avg, rec->counter); |
396 | 405 | ||
397 | mutex_lock(&mutex); | 406 | /* Sample standard deviation (s^2) */ |
407 | if (rec->counter <= 1) | ||
408 | stddev = 0; | ||
409 | else { | ||
410 | stddev = rec->time_squared - rec->counter * avg * avg; | ||
411 | /* | ||
412 | * Divide only 1000 for ns^2 -> us^2 conversion. | ||
413 | * trace_print_graph_duration will divide 1000 again. | ||
414 | */ | ||
415 | do_div(stddev, (rec->counter - 1) * 1000); | ||
416 | } | ||
417 | |||
398 | trace_seq_init(&s); | 418 | trace_seq_init(&s); |
399 | trace_print_graph_duration(rec->time, &s); | 419 | trace_print_graph_duration(rec->time, &s); |
400 | trace_seq_puts(&s, " "); | 420 | trace_seq_puts(&s, " "); |
401 | trace_print_graph_duration(avg, &s); | 421 | trace_print_graph_duration(avg, &s); |
422 | trace_seq_puts(&s, " "); | ||
423 | trace_print_graph_duration(stddev, &s); | ||
402 | trace_print_seq(m, &s); | 424 | trace_print_seq(m, &s); |
403 | mutex_unlock(&mutex); | ||
404 | #endif | 425 | #endif |
405 | seq_putc(m, '\n'); | 426 | seq_putc(m, '\n'); |
427 | out: | ||
428 | mutex_unlock(&ftrace_profile_lock); | ||
406 | 429 | ||
407 | return 0; | 430 | return ret; |
408 | } | 431 | } |
409 | 432 | ||
410 | static void ftrace_profile_reset(struct ftrace_profile_stat *stat) | 433 | static void ftrace_profile_reset(struct ftrace_profile_stat *stat) |
@@ -650,6 +673,10 @@ static void profile_graph_return(struct ftrace_graph_ret *trace) | |||
650 | if (!stat->hash || !ftrace_profile_enabled) | 673 | if (!stat->hash || !ftrace_profile_enabled) |
651 | goto out; | 674 | goto out; |
652 | 675 | ||
676 | /* If the calltime was zero'd ignore it */ | ||
677 | if (!trace->calltime) | ||
678 | goto out; | ||
679 | |||
653 | calltime = trace->rettime - trace->calltime; | 680 | calltime = trace->rettime - trace->calltime; |
654 | 681 | ||
655 | if (!(trace_flags & TRACE_ITER_GRAPH_TIME)) { | 682 | if (!(trace_flags & TRACE_ITER_GRAPH_TIME)) { |
@@ -668,8 +695,10 @@ static void profile_graph_return(struct ftrace_graph_ret *trace) | |||
668 | } | 695 | } |
669 | 696 | ||
670 | rec = ftrace_find_profiled_func(stat, trace->func); | 697 | rec = ftrace_find_profiled_func(stat, trace->func); |
671 | if (rec) | 698 | if (rec) { |
672 | rec->time += calltime; | 699 | rec->time += calltime; |
700 | rec->time_squared += calltime * calltime; | ||
701 | } | ||
673 | 702 | ||
674 | out: | 703 | out: |
675 | local_irq_restore(flags); | 704 | local_irq_restore(flags); |
@@ -1481,6 +1510,8 @@ static void *t_start(struct seq_file *m, loff_t *pos) | |||
1481 | if (*pos > 0) | 1510 | if (*pos > 0) |
1482 | return t_hash_start(m, pos); | 1511 | return t_hash_start(m, pos); |
1483 | iter->flags |= FTRACE_ITER_PRINTALL; | 1512 | iter->flags |= FTRACE_ITER_PRINTALL; |
1513 | /* reset in case of seek/pread */ | ||
1514 | iter->flags &= ~FTRACE_ITER_HASH; | ||
1484 | return iter; | 1515 | return iter; |
1485 | } | 1516 | } |
1486 | 1517 | ||
@@ -1861,7 +1892,6 @@ function_trace_probe_call(unsigned long ip, unsigned long parent_ip) | |||
1861 | struct hlist_head *hhd; | 1892 | struct hlist_head *hhd; |
1862 | struct hlist_node *n; | 1893 | struct hlist_node *n; |
1863 | unsigned long key; | 1894 | unsigned long key; |
1864 | int resched; | ||
1865 | 1895 | ||
1866 | key = hash_long(ip, FTRACE_HASH_BITS); | 1896 | key = hash_long(ip, FTRACE_HASH_BITS); |
1867 | 1897 | ||
@@ -1875,12 +1905,12 @@ function_trace_probe_call(unsigned long ip, unsigned long parent_ip) | |||
1875 | * period. This syncs the hash iteration and freeing of items | 1905 | * period. This syncs the hash iteration and freeing of items |
1876 | * on the hash. rcu_read_lock is too dangerous here. | 1906 | * on the hash. rcu_read_lock is too dangerous here. |
1877 | */ | 1907 | */ |
1878 | resched = ftrace_preempt_disable(); | 1908 | preempt_disable_notrace(); |
1879 | hlist_for_each_entry_rcu(entry, n, hhd, node) { | 1909 | hlist_for_each_entry_rcu(entry, n, hhd, node) { |
1880 | if (entry->ip == ip) | 1910 | if (entry->ip == ip) |
1881 | entry->ops->func(ip, parent_ip, &entry->data); | 1911 | entry->ops->func(ip, parent_ip, &entry->data); |
1882 | } | 1912 | } |
1883 | ftrace_preempt_enable(resched); | 1913 | preempt_enable_notrace(); |
1884 | } | 1914 | } |
1885 | 1915 | ||
1886 | static struct ftrace_ops trace_probe_ops __read_mostly = | 1916 | static struct ftrace_ops trace_probe_ops __read_mostly = |
@@ -2388,7 +2418,7 @@ static const struct file_operations ftrace_filter_fops = { | |||
2388 | .open = ftrace_filter_open, | 2418 | .open = ftrace_filter_open, |
2389 | .read = seq_read, | 2419 | .read = seq_read, |
2390 | .write = ftrace_filter_write, | 2420 | .write = ftrace_filter_write, |
2391 | .llseek = ftrace_regex_lseek, | 2421 | .llseek = no_llseek, |
2392 | .release = ftrace_filter_release, | 2422 | .release = ftrace_filter_release, |
2393 | }; | 2423 | }; |
2394 | 2424 | ||
@@ -3212,8 +3242,8 @@ free: | |||
3212 | } | 3242 | } |
3213 | 3243 | ||
3214 | static void | 3244 | static void |
3215 | ftrace_graph_probe_sched_switch(struct rq *__rq, struct task_struct *prev, | 3245 | ftrace_graph_probe_sched_switch(void *ignore, |
3216 | struct task_struct *next) | 3246 | struct task_struct *prev, struct task_struct *next) |
3217 | { | 3247 | { |
3218 | unsigned long long timestamp; | 3248 | unsigned long long timestamp; |
3219 | int index; | 3249 | int index; |
@@ -3267,7 +3297,7 @@ static int start_graph_tracing(void) | |||
3267 | } while (ret == -EAGAIN); | 3297 | } while (ret == -EAGAIN); |
3268 | 3298 | ||
3269 | if (!ret) { | 3299 | if (!ret) { |
3270 | ret = register_trace_sched_switch(ftrace_graph_probe_sched_switch); | 3300 | ret = register_trace_sched_switch(ftrace_graph_probe_sched_switch, NULL); |
3271 | if (ret) | 3301 | if (ret) |
3272 | pr_info("ftrace_graph: Couldn't activate tracepoint" | 3302 | pr_info("ftrace_graph: Couldn't activate tracepoint" |
3273 | " probe to kernel_sched_switch\n"); | 3303 | " probe to kernel_sched_switch\n"); |
@@ -3339,11 +3369,11 @@ void unregister_ftrace_graph(void) | |||
3339 | goto out; | 3369 | goto out; |
3340 | 3370 | ||
3341 | ftrace_graph_active--; | 3371 | ftrace_graph_active--; |
3342 | unregister_trace_sched_switch(ftrace_graph_probe_sched_switch); | ||
3343 | ftrace_graph_return = (trace_func_graph_ret_t)ftrace_stub; | 3372 | ftrace_graph_return = (trace_func_graph_ret_t)ftrace_stub; |
3344 | ftrace_graph_entry = ftrace_graph_entry_stub; | 3373 | ftrace_graph_entry = ftrace_graph_entry_stub; |
3345 | ftrace_shutdown(FTRACE_STOP_FUNC_RET); | 3374 | ftrace_shutdown(FTRACE_STOP_FUNC_RET); |
3346 | unregister_pm_notifier(&ftrace_suspend_notifier); | 3375 | unregister_pm_notifier(&ftrace_suspend_notifier); |
3376 | unregister_trace_sched_switch(ftrace_graph_probe_sched_switch, NULL); | ||
3347 | 3377 | ||
3348 | out: | 3378 | out: |
3349 | mutex_unlock(&ftrace_lock); | 3379 | mutex_unlock(&ftrace_lock); |