tracing: Change the function format to display function names by perf

Here is an example for this change.

$ sudo perf record -e 'ftrace:function' --filter='ip==schedule'
$ sudo perf report

The output of perf before this patch:

\# Samples: 100  of event 'ftrace:function'
\# Event count (approx.): 100
\#
\# Overhead  Trace output
\# ........  ......................................
\#
    51.00%   ffffffff81f6aaa0 <-- ffffffff81158e8d
    29.00%   ffffffff81f6aaa0 <-- ffffffff8116ccb2
     8.00%   ffffffff81f6aaa0 <-- ffffffff81f6f2ed
     4.00%   ffffffff81f6aaa0 <-- ffffffff811628db
     4.00%   ffffffff81f6aaa0 <-- ffffffff81f6ec5b
     2.00%   ffffffff81f6aaa0 <-- ffffffff81f6f21a
     1.00%   ffffffff81f6aaa0 <-- ffffffff811b04af
     1.00%   ffffffff81f6aaa0 <-- ffffffff8143ce17

After this patch:

\# Samples: 36  of event 'ftrace:function'
\# Event count (approx.): 36
\#
\# Overhead  Trace output
\# ........  ............................................
\#
    38.89%   schedule <-- schedule_hrtimeout_range_clock
    27.78%   schedule <-- worker_thread
    13.89%   schedule <-- schedule_timeout
    11.11%   schedule <-- smpboot_thread_fn
     5.56%   schedule <-- rcu_gp_kthread
     2.78%   schedule <-- exit_to_usermode_loop

Link: http://lkml.kernel.org/r/20190209161919.32350-1-changbin.du@gmail.com

Signed-off-by: Changbin Du <changbin.du@gmail.com>
Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
This commit is contained in:
Changbin Du 2019-02-10 00:19:19 +08:00 committed by Steven Rostedt (VMware)
parent d325c40296
commit 85acbb21b9
1 changed files with 19 additions and 22 deletions

View File

@ -65,7 +65,8 @@ FTRACE_ENTRY_REG(function, ftrace_entry,
__field( unsigned long, parent_ip ) __field( unsigned long, parent_ip )
), ),
F_printk(" %lx <-- %lx", __entry->ip, __entry->parent_ip), F_printk(" %ps <-- %ps",
(void *)__entry->ip, (void *)__entry->parent_ip),
FILTER_TRACE_FN, FILTER_TRACE_FN,
@ -83,7 +84,7 @@ FTRACE_ENTRY_PACKED(funcgraph_entry, ftrace_graph_ent_entry,
__field_desc( int, graph_ent, depth ) __field_desc( int, graph_ent, depth )
), ),
F_printk("--> %lx (%d)", __entry->func, __entry->depth), F_printk("--> %ps (%d)", (void *)__entry->func, __entry->depth),
FILTER_OTHER FILTER_OTHER
); );
@ -102,8 +103,8 @@ FTRACE_ENTRY_PACKED(funcgraph_exit, ftrace_graph_ret_entry,
__field_desc( int, ret, depth ) __field_desc( int, ret, depth )
), ),
F_printk("<-- %lx (%d) (start: %llx end: %llx) over: %d", F_printk("<-- %ps (%d) (start: %llx end: %llx) over: %d",
__entry->func, __entry->depth, (void *)__entry->func, __entry->depth,
__entry->calltime, __entry->rettime, __entry->calltime, __entry->rettime,
__entry->depth), __entry->depth),
@ -167,12 +168,6 @@ FTRACE_ENTRY_DUP(wakeup, ctx_switch_entry,
#define FTRACE_STACK_ENTRIES 8 #define FTRACE_STACK_ENTRIES 8
#ifndef CONFIG_64BIT
# define IP_FMT "%08lx"
#else
# define IP_FMT "%016lx"
#endif
FTRACE_ENTRY(kernel_stack, stack_entry, FTRACE_ENTRY(kernel_stack, stack_entry,
TRACE_STACK, TRACE_STACK,
@ -182,12 +177,13 @@ FTRACE_ENTRY(kernel_stack, stack_entry,
__dynamic_array(unsigned long, caller ) __dynamic_array(unsigned long, caller )
), ),
F_printk("\t=> (" IP_FMT ")\n\t=> (" IP_FMT ")\n\t=> (" IP_FMT ")\n" F_printk("\t=> %ps\n\t=> %ps\n\t=> %ps\n"
"\t=> (" IP_FMT ")\n\t=> (" IP_FMT ")\n\t=> (" IP_FMT ")\n" "\t=> %ps\n\t=> %ps\n\t=> %ps\n"
"\t=> (" IP_FMT ")\n\t=> (" IP_FMT ")\n", "\t=> %ps\n\t=> %ps\n",
__entry->caller[0], __entry->caller[1], __entry->caller[2], (void *)__entry->caller[0], (void *)__entry->caller[1],
__entry->caller[3], __entry->caller[4], __entry->caller[5], (void *)__entry->caller[2], (void *)__entry->caller[3],
__entry->caller[6], __entry->caller[7]), (void *)__entry->caller[4], (void *)__entry->caller[5],
(void *)__entry->caller[6], (void *)__entry->caller[7]),
FILTER_OTHER FILTER_OTHER
); );
@ -201,12 +197,13 @@ FTRACE_ENTRY(user_stack, userstack_entry,
__array( unsigned long, caller, FTRACE_STACK_ENTRIES ) __array( unsigned long, caller, FTRACE_STACK_ENTRIES )
), ),
F_printk("\t=> (" IP_FMT ")\n\t=> (" IP_FMT ")\n\t=> (" IP_FMT ")\n" F_printk("\t=> %ps\n\t=> %ps\n\t=> %ps\n"
"\t=> (" IP_FMT ")\n\t=> (" IP_FMT ")\n\t=> (" IP_FMT ")\n" "\t=> %ps\n\t=> %ps\n\t=> %ps\n"
"\t=> (" IP_FMT ")\n\t=> (" IP_FMT ")\n", "\t=> %ps\n\t=> %ps\n",
__entry->caller[0], __entry->caller[1], __entry->caller[2], (void *)__entry->caller[0], (void *)__entry->caller[1],
__entry->caller[3], __entry->caller[4], __entry->caller[5], (void *)__entry->caller[2], (void *)__entry->caller[3],
__entry->caller[6], __entry->caller[7]), (void *)__entry->caller[4], (void *)__entry->caller[5],
(void *)__entry->caller[6], (void *)__entry->caller[7]),
FILTER_OTHER FILTER_OTHER
); );