tracing: Change the function format to display function names by perf
authorChangbin Du <changbin.du@gmail.com>
Sat, 9 Feb 2019 16:19:19 +0000 (00:19 +0800)
committerSteven Rostedt (VMware) <rostedt@goodmis.org>
Mon, 11 Feb 2019 19:53:43 +0000 (14:53 -0500)
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>
kernel/trace/trace_entries.h

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