aboutsummaryrefslogtreecommitdiffstats
path: root/kernel/trace/ftrace.c
diff options
context:
space:
mode:
Diffstat (limited to 'kernel/trace/ftrace.c')
-rw-r--r--kernel/trace/ftrace.c60
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');
427out:
428 mutex_unlock(&ftrace_profile_lock);
406 429
407 return 0; 430 return ret;
408} 431}
409 432
410static void ftrace_profile_reset(struct ftrace_profile_stat *stat) 433static 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
1886static struct ftrace_ops trace_probe_ops __read_mostly = 1916static 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
3214static void 3244static void
3215ftrace_graph_probe_sched_switch(struct rq *__rq, struct task_struct *prev, 3245ftrace_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);