* [PATCH] tracing: print function names instead of just address
@ 2019-02-09 16:19 Changbin Du
2019-02-11 19:55 ` Steven Rostedt
0 siblings, 1 reply; 3+ messages in thread
From: Changbin Du @ 2019-02-09 16:19 UTC (permalink / raw)
To: rostedt; +Cc: mingo, linux-kernel, Changbin Du
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
Signed-off-by: Changbin Du <changbin.du@gmail.com>
---
kernel/trace/trace_entries.h | 41 +++++++++++++++++-------------------
1 file changed, 19 insertions(+), 22 deletions(-)
diff --git a/kernel/trace/trace_entries.h b/kernel/trace/trace_entries.h
index 06bb2fd9a56c..fc8e97328e54 100644
--- a/kernel/trace/trace_entries.h
+++ b/kernel/trace/trace_entries.h
@@ -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
);
--
2.19.1
^ permalink raw reply related [flat|nested] 3+ messages in thread
* Re: [PATCH] tracing: print function names instead of just address
2019-02-09 16:19 [PATCH] tracing: print function names instead of just address Changbin Du
@ 2019-02-11 19:55 ` Steven Rostedt
2019-02-12 2:58 ` Changbin Du
0 siblings, 1 reply; 3+ messages in thread
From: Steven Rostedt @ 2019-02-11 19:55 UTC (permalink / raw)
To: Changbin Du; +Cc: mingo, linux-kernel
On Sun, 10 Feb 2019 00:19:19 +0800
Changbin Du <changbin.du@gmail.com> wrote:
> Here is an example for this change.
>
> $ sudo perf record -e 'ftrace:function' --filter='ip==schedule'
> $ sudo perf report
I took this but changed the subject as it only affects perf (the kernel
doesn't use the format field for output, and trace-cmd has an internal
plugin that overrides it too).
-- Steve
>
> 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
>
> Signed-off-by: Changbin Du <changbin.du@gmail.com>
> ---
> kernel/trace/trace_entries.h | 41 +++++++++++++++++-------------------
> 1 file changed, 19 insertions(+), 22 deletions(-)
>
>
^ permalink raw reply [flat|nested] 3+ messages in thread
* Re: [PATCH] tracing: print function names instead of just address
2019-02-11 19:55 ` Steven Rostedt
@ 2019-02-12 2:58 ` Changbin Du
0 siblings, 0 replies; 3+ messages in thread
From: Changbin Du @ 2019-02-12 2:58 UTC (permalink / raw)
To: Steven Rostedt; +Cc: Changbin Du, mingo, linux-kernel
On Mon, Feb 11, 2019 at 02:55:32PM -0500, Steven Rostedt wrote:
> On Sun, 10 Feb 2019 00:19:19 +0800
> Changbin Du <changbin.du@gmail.com> wrote:
>
> > Here is an example for this change.
> >
> > $ sudo perf record -e 'ftrace:function' --filter='ip==schedule'
> > $ sudo perf report
>
> I took this but changed the subject as it only affects perf (the kernel
> doesn't use the format field for output, and trace-cmd has an internal
> plugin that overrides it too).
>
Thanks. You explained why I can't find the usage for the other entries.
I was looking for it before... :)
> -- Steve
>
> >
> > 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
> >
> > Signed-off-by: Changbin Du <changbin.du@gmail.com>
> > ---
> > kernel/trace/trace_entries.h | 41 +++++++++++++++++-------------------
> > 1 file changed, 19 insertions(+), 22 deletions(-)
> >
> >
--
Cheers,
Changbin Du
^ permalink raw reply [flat|nested] 3+ messages in thread
end of thread, other threads:[~2019-02-12 2:58 UTC | newest]
Thread overview: 3+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2019-02-09 16:19 [PATCH] tracing: print function names instead of just address Changbin Du
2019-02-11 19:55 ` Steven Rostedt
2019-02-12 2:58 ` Changbin Du
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox