| Message ID | 20240904065908.1009086-1-svens@linux.ibm.com (mailing list archive) |
|---|---|
| Headers | show |
| Series | add function arguments to ftrace | expand |
On Wed, 4 Sep 2024 08:58:54 +0200 Sven Schnelle <svens@linux.ibm.com> wrote: > These patches add support for printing function arguments in ftrace. > > Example usage: > > function tracer: > > cd /sys/kernel/tracing/ > echo icmp_rcv >set_ftrace_filter > echo function >current_tracer > echo 1 >options/func-args > ping -c 10 127.0.0.1 > [..] > cat trace > [..] > ping-1277 [030] ..s1. 39.120939: icmp_rcv(skb = 0xa0ecab00) <-ip_protocol_deliver_rcu > ping-1277 [030] ..s1. 39.120946: icmp_rcv(skb = 0xa0ecac00) <-ip_protocol_deliver_rcu > ping-1277 [030] ..s1. 40.179724: icmp_rcv(skb = 0xa0ecab00) <-ip_protocol_deliver_rcu > ping-1277 [030] ..s1. 40.179730: icmp_rcv(skb = 0xa0ecac00) <-ip_protocol_deliver_rcu > ping-1277 [030] ..s1. 41.219700: icmp_rcv(skb = 0xa0ecab00) <-ip_protocol_deliver_rcu > ping-1277 [030] ..s1. 41.219706: icmp_rcv(skb = 0xa0ecac00) <-ip_protocol_deliver_rcu > ping-1277 [030] ..s1. 42.259717: icmp_rcv(skb = 0xa0ecab00) <-ip_protocol_deliver_rcu > ping-1277 [030] ..s1. 42.259725: icmp_rcv(skb = 0xa0ecac00) <-ip_protocol_deliver_rcu > ping-1277 [030] ..s1. 43.299735: icmp_rcv(skb = 0xa0ecab00) <-ip_protocol_deliver_rcu > ping-1277 [030] ..s1. 43.299742: icmp_rcv(skb = 0xa0ecac00) <-ip_protocol_deliver_rcu > > function graph: > > cd /sys/kernel/tracing > echo icmp_rcv >set_graph_function > echo function_graph >current_tracer > echo 1 >options/funcgraph-args > > ping -c 1 127.0.0.1 > > cat trace > > 30) | icmp_rcv(skb = 0xa0ecab00) { > 30) | __skb_checksum_complete(skb = 0xa0ecab00) { > 30) | skb_checksum(skb = 0xa0ecab00, offset = 0, len = 64, csum = 0) { > 30) | __skb_checksum(skb = 0xa0ecab00, offset = 0, len = 64, csum = 0, ops = 0x232e0327a88) { > 30) 0.418 us | csum_partial(buff = 0xa0d20924, len = 64, sum = 0) > 30) 0.985 us | } > 30) 1.463 us | } > 30) 2.039 us | } > [..] > First I want to say THANK YOU!!!! This has been on my TODO list for far too long. I never got the time to work on it :-p Anyway, this is something I definitely want added. But I'm going to guess that there is going to be issues with it and I doubt it will be ready for the next merge window. I'm currently focused on some other things and also have to get ready for next weeks travels (I'll be in Prague for GNU Cauldron, then Vienna for Plumbers and OSS EU, then to Paris for Kernel Recipes!). But I most definitely want this in. Hopefully by 6.13. This may be something I can review on the plane (if I get my slides done). Again, thanks for doing this! -- Steve > > Sven Schnelle (7): > tracing: add ftrace_regs to function_graph_enter() > x86/tracing: pass ftrace_regs to function_graph_enter() > s390/tracing: pass ftrace_regs to function_graph_enter() > Add print_function_args() > tracing: add config option for print arguments in ftrace > tracing: add support for function argument to graph tracer > tracing: add arguments to function tracer > > arch/arm/kernel/ftrace.c | 2 +- > arch/arm64/kernel/ftrace.c | 2 +- > arch/csky/kernel/ftrace.c | 2 +- > arch/loongarch/kernel/ftrace.c | 2 +- > arch/loongarch/kernel/ftrace_dyn.c | 2 +- > arch/microblaze/kernel/ftrace.c | 2 +- > arch/mips/kernel/ftrace.c | 2 +- > arch/parisc/kernel/ftrace.c | 2 +- > arch/powerpc/kernel/trace/ftrace.c | 2 +- > arch/riscv/kernel/ftrace.c | 2 +- > arch/s390/kernel/entry.h | 4 +- > arch/s390/kernel/ftrace.c | 4 +- > arch/sh/kernel/ftrace.c | 2 +- > arch/sparc/kernel/ftrace.c | 2 +- > arch/x86/include/asm/ftrace.h | 2 +- > arch/x86/kernel/ftrace.c | 6 +- > include/linux/ftrace.h | 4 +- > kernel/trace/Kconfig | 12 ++++ > kernel/trace/fgraph.c | 7 ++- > kernel/trace/trace.c | 8 ++- > kernel/trace/trace.h | 4 +- > kernel/trace/trace_entries.h | 7 ++- > kernel/trace/trace_functions.c | 46 ++++++++++++++-- > kernel/trace/trace_functions_graph.c | 74 +++++++++++++------------ > kernel/trace/trace_irqsoff.c | 4 +- > kernel/trace/trace_output.c | 82 +++++++++++++++++++++++++++- > kernel/trace/trace_output.h | 9 +++ > kernel/trace/trace_sched_wakeup.c | 4 +- > 28 files changed, 228 insertions(+), 73 deletions(-) > > -- > 2.43.0
Steven Rostedt <rostedt@goodmis.org> writes: > On Wed, 4 Sep 2024 08:58:54 +0200 > Sven Schnelle <svens@linux.ibm.com> wrote: > >> These patches add support for printing function arguments in ftrace. > First I want to say THANK YOU!!!! > > This has been on my TODO list for far too long. I never got the time to > work on it :-p > > Anyway, this is something I definitely want added. But I'm going to guess > that there is going to be issues with it and I doubt it will be ready for > the next merge window. I'm currently focused on some other things and also > have to get ready for next weeks travels (I'll be in Prague for GNU Cauldron, > then Vienna for Plumbers and OSS EU, then to Paris for Kernel Recipes!). > > But I most definitely want this in. Hopefully by 6.13. This may be > something I can review on the plane (if I get my slides done). Thanks! It's been hanging in my git repo for quite a while, so no need to rush. One thing i learned after submitting the series is that struct ftrace_regs depends on CONFIG_FUNCTION_TRACER, so it cannot be used with the graph tracer. So either we make it available unconditionally, or use some other data structure. Would like to hear your opinion on that, but i'll wait for the review after your travel because there are likely other issues that needs to be fixed as well. Thanks, Sven
On Fri, 06 Sep 2024 08:18:02 +0200 Sven Schnelle <svens@linux.ibm.com> wrote: > One thing i learned after submitting the series is that struct > ftrace_regs depends on CONFIG_FUNCTION_TRACER, so it cannot be used > with the graph tracer. So either we make it available unconditionally, > or use some other data structure. Would like to hear your opinion on > that, but i'll wait for the review after your travel because there > are likely other issues that needs to be fixed as well. Hmm, I thought the graph tracer depends on function tracer? Anyway, the configs should be cleaned up. I would like to make CONFIG_FTRACE just mean the function hook mechanism (mcount,fentry,etc) and not be used for the tracing system. Anyway, we can just make ftrace_regs defined outside any config for now. -- Steve
On Fri, 6 Sep 2024 10:07:38 -0400 Steven Rostedt <rostedt@goodmis.org> wrote: > On Fri, 06 Sep 2024 08:18:02 +0200 > Sven Schnelle <svens@linux.ibm.com> wrote: > > > > One thing i learned after submitting the series is that struct > > ftrace_regs depends on CONFIG_FUNCTION_TRACER, so it cannot be used > > with the graph tracer. Yeah, this is solved by my series [1]. [1] https://patchwork.kernel.org/project/linux-trace-kernel/patch/172398532480.293426.13232399076477198126.stgit@devnote2/ So I think this series is easier to apply after my series, which passes fgraph_regs in return handler. Thanks, > > So either we make it available unconditionally, > > or use some other data structure. Would like to hear your opinion on > > that, but i'll wait for the review after your travel because there > > are likely other issues that needs to be fixed as well. > > Hmm, I thought the graph tracer depends on function tracer? Anyway, the > configs should be cleaned up. I would like to make CONFIG_FTRACE just mean > the function hook mechanism (mcount,fentry,etc) and not be used for the > tracing system. > > Anyway, we can just make ftrace_regs defined outside any config for now. > > -- Steve
Masami Hiramatsu (Google) <mhiramat@kernel.org> writes: > On Fri, 6 Sep 2024 10:07:38 -0400 > Steven Rostedt <rostedt@goodmis.org> wrote: > >> On Fri, 06 Sep 2024 08:18:02 +0200 >> Sven Schnelle <svens@linux.ibm.com> wrote: >> >> >> > One thing i learned after submitting the series is that struct >> > ftrace_regs depends on CONFIG_FUNCTION_TRACER, so it cannot be used >> > with the graph tracer. > > Yeah, this is solved by my series [1]. > > [1] https://patchwork.kernel.org/project/linux-trace-kernel/patch/172398532480.293426.13232399076477198126.stgit@devnote2/ > > So I think this series is easier to apply after my series, which > passes fgraph_regs in return handler. Thanks, i'll rebase my changes on top of your patches then. Regards Sven
Sven Schnelle <svens@linux.ibm.com> writes: > Masami Hiramatsu (Google) <mhiramat@kernel.org> writes: > >> On Fri, 6 Sep 2024 10:07:38 -0400 >> Steven Rostedt <rostedt@goodmis.org> wrote: >> >>> On Fri, 06 Sep 2024 08:18:02 +0200 >>> Sven Schnelle <svens@linux.ibm.com> wrote: >>> >>> >>> > One thing i learned after submitting the series is that struct >>> > ftrace_regs depends on CONFIG_FUNCTION_TRACER, so it cannot be used >>> > with the graph tracer. >> >> Yeah, this is solved by my series [1]. >> >> [1] https://patchwork.kernel.org/project/linux-trace-kernel/patch/172398532480.293426.13232399076477198126.stgit@devnote2/ >> >> So I think this series is easier to apply after my series, which >> passes fgraph_regs in return handler. > > Thanks, i'll rebase my changes on top of your patches then. While doing so i noticed that i completely forgot about arguments located on the stack. The current patchset tries to read from the current kernel stack, which is obviously wrong. So either the tracer needs to save the stack frame in the ringbuffer (which would be quite a lot of data), or ftrace only prints arguments located in registers. Also not nice. Opinions? Thanks Sven
On Fri, 13 Sep 2024 08:03:51 +0200 Sven Schnelle <svens@linux.ibm.com> wrote: > Sven Schnelle <svens@linux.ibm.com> writes: > > > Masami Hiramatsu (Google) <mhiramat@kernel.org> writes: > > > >> On Fri, 6 Sep 2024 10:07:38 -0400 > >> Steven Rostedt <rostedt@goodmis.org> wrote: > >> > >>> On Fri, 06 Sep 2024 08:18:02 +0200 > >>> Sven Schnelle <svens@linux.ibm.com> wrote: > >>> > >>> > >>> > One thing i learned after submitting the series is that struct > >>> > ftrace_regs depends on CONFIG_FUNCTION_TRACER, so it cannot be used > >>> > with the graph tracer. > >> > >> Yeah, this is solved by my series [1]. > >> > >> [1] https://patchwork.kernel.org/project/linux-trace-kernel/patch/172398532480.293426.13232399076477198126.stgit@devnote2/ > >> > >> So I think this series is easier to apply after my series, which > >> passes fgraph_regs in return handler. > > > > Thanks, i'll rebase my changes on top of your patches then. > > While doing so i noticed that i completely forgot about arguments > located on the stack. The current patchset tries to read from the > current kernel stack, which is obviously wrong. So either the tracer > needs to save the stack frame in the ringbuffer (which would be quite > a lot of data), or ftrace only prints arguments located in registers. > Also not nice. Opinions? We can limit it to first 6 arguments in the ftrace_regs by default, no need to save all of them. We can add an option to specify how many stack entries (but it is set 0 by default). Thank you, > > Thanks > Sven
These patches add support for printing function arguments in ftrace. Example usage: function tracer: cd /sys/kernel/tracing/ echo icmp_rcv >set_ftrace_filter echo function >current_tracer echo 1 >options/func-args ping -c 10 127.0.0.1 [..] cat trace [..] ping-1277 [030] ..s1. 39.120939: icmp_rcv(skb = 0xa0ecab00) <-ip_protocol_deliver_rcu ping-1277 [030] ..s1. 39.120946: icmp_rcv(skb = 0xa0ecac00) <-ip_protocol_deliver_rcu ping-1277 [030] ..s1. 40.179724: icmp_rcv(skb = 0xa0ecab00) <-ip_protocol_deliver_rcu ping-1277 [030] ..s1. 40.179730: icmp_rcv(skb = 0xa0ecac00) <-ip_protocol_deliver_rcu ping-1277 [030] ..s1. 41.219700: icmp_rcv(skb = 0xa0ecab00) <-ip_protocol_deliver_rcu ping-1277 [030] ..s1. 41.219706: icmp_rcv(skb = 0xa0ecac00) <-ip_protocol_deliver_rcu ping-1277 [030] ..s1. 42.259717: icmp_rcv(skb = 0xa0ecab00) <-ip_protocol_deliver_rcu ping-1277 [030] ..s1. 42.259725: icmp_rcv(skb = 0xa0ecac00) <-ip_protocol_deliver_rcu ping-1277 [030] ..s1. 43.299735: icmp_rcv(skb = 0xa0ecab00) <-ip_protocol_deliver_rcu ping-1277 [030] ..s1. 43.299742: icmp_rcv(skb = 0xa0ecac00) <-ip_protocol_deliver_rcu function graph: cd /sys/kernel/tracing echo icmp_rcv >set_graph_function echo function_graph >current_tracer echo 1 >options/funcgraph-args ping -c 1 127.0.0.1 cat trace 30) | icmp_rcv(skb = 0xa0ecab00) { 30) | __skb_checksum_complete(skb = 0xa0ecab00) { 30) | skb_checksum(skb = 0xa0ecab00, offset = 0, len = 64, csum = 0) { 30) | __skb_checksum(skb = 0xa0ecab00, offset = 0, len = 64, csum = 0, ops = 0x232e0327a88) { 30) 0.418 us | csum_partial(buff = 0xa0d20924, len = 64, sum = 0) 30) 0.985 us | } 30) 1.463 us | } 30) 2.039 us | } [..] Sven Schnelle (7): tracing: add ftrace_regs to function_graph_enter() x86/tracing: pass ftrace_regs to function_graph_enter() s390/tracing: pass ftrace_regs to function_graph_enter() Add print_function_args() tracing: add config option for print arguments in ftrace tracing: add support for function argument to graph tracer tracing: add arguments to function tracer arch/arm/kernel/ftrace.c | 2 +- arch/arm64/kernel/ftrace.c | 2 +- arch/csky/kernel/ftrace.c | 2 +- arch/loongarch/kernel/ftrace.c | 2 +- arch/loongarch/kernel/ftrace_dyn.c | 2 +- arch/microblaze/kernel/ftrace.c | 2 +- arch/mips/kernel/ftrace.c | 2 +- arch/parisc/kernel/ftrace.c | 2 +- arch/powerpc/kernel/trace/ftrace.c | 2 +- arch/riscv/kernel/ftrace.c | 2 +- arch/s390/kernel/entry.h | 4 +- arch/s390/kernel/ftrace.c | 4 +- arch/sh/kernel/ftrace.c | 2 +- arch/sparc/kernel/ftrace.c | 2 +- arch/x86/include/asm/ftrace.h | 2 +- arch/x86/kernel/ftrace.c | 6 +- include/linux/ftrace.h | 4 +- kernel/trace/Kconfig | 12 ++++ kernel/trace/fgraph.c | 7 ++- kernel/trace/trace.c | 8 ++- kernel/trace/trace.h | 4 +- kernel/trace/trace_entries.h | 7 ++- kernel/trace/trace_functions.c | 46 ++++++++++++++-- kernel/trace/trace_functions_graph.c | 74 +++++++++++++------------ kernel/trace/trace_irqsoff.c | 4 +- kernel/trace/trace_output.c | 82 +++++++++++++++++++++++++++- kernel/trace/trace_output.h | 9 +++ kernel/trace/trace_sched_wakeup.c | 4 +- 28 files changed, 228 insertions(+), 73 deletions(-) -- 2.43.0