Skip to content

ftrace: Add function arguments to function tracers

Steven Rostedt bpf linux-trace-kernel lkml 3 versions – In review

Get series with b4
b4 am [email protected]

Versions newest first · linked by author and title

  1. v4 Latest4 patches 25 repliesIn review
  2. v34 patches 5 repliesSuperseded
  3. v24 patches 13 repliesSuperseded

Patches in v4 No applies recorded yet

#Subject and filesSizeRepliesApplied
1/4ftrace: Add print_function_args()include/linux/ftrace_regs.h kernel/trace/Kconfig kernel/trace/trace_output.c +1 more+105 -00 replies
2/4ftrace: Add support for function argument to graph tracerkernel/trace/Kconfig kernel/trace/trace.h kernel/trace/trace_entries.h +1 more+124 -3525 replies
3/4ftrace: Have funcgraph-args take affect during tracingkernel/trace/trace_functions_graph.c+26 -10 replies
4/4ftrace: Add arguments to function tracerkernel/trace/trace.c kernel/trace/trace.h kernel/trace/trace_entries.h +4 more+85 -180 replies

Reviews trailers per patch

All 4 patches have a Reviewed-by or Acked-by.

PatchMasami Hiramatsu (Google)
1/4R-b
2/4R-b
3/4A-b
4/4R-b

Trailers given in replies are filled; those carried in the patches from earlier versions are outlined with dashes.

Read the v4 thread

Cover letter [PATCH v4 0/4] ftrace: Add function arguments to function tracers

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    |    }

[..]

This was last posted by Sven Schnelle here:

https://lore.kernel.org/all/[email protected]/

As Sven hasn't worked on it since, I decided to continue to push it through. I'm keeping Sven as original author and added myself as "Co-developed-by".

Changes since v3: https://lore.kernel.org/linux-trace-kernel/[email protected]/

- kernel test robot flagged that this broke builds of archictecuters that do not support function args access.
This was due to missing #ifdefs around calls of functions those archs do not implement.

- For archs that do not support function graph tracer, the irqsoff trace uses trace_function, but that now has a new parameter.

- Here's the diff between v3 and this series:

kernel/trace/trace.c +2 -0
index 86d828b9dc7c..cb13c88abfd6 100644
@@ -2895,10 +2895,12 @@ trace_function(struct trace_array *tr, unsigned long ip, unsigned long
 	entry->ip			= ip;
 	entry->parent_ip		= parent_ip;
 
+#ifdef CONFIG_HAVE_FUNCTION_ARG_ACCESS_API
 	if (fregs) {
 		for (int i = 0; i < FTRACE_REGS_MAX_ARGS; i++)
 			entry->args[i] = ftrace_regs_get_argument(fregs, i);
 	}
+#endif
 
 	if (static_branch_unlikely(&trace_function_exports_enabled))
 		ftrace_exports(event, TRACE_EXPORT_FUNCTION);
kernel/trace/trace.h +1 -0
index 472ec5d623db..32da87f45010 100644
@@ -21,6 +21,7 @@
 #include <linux/workqueue.h>
 #include <linux/ctype.h>
 #include <linux/once_lite.h>
+#include <linux/ftrace_regs.h>
 
 #include "pid_list.h"
 
kernel/trace/trace_functions_graph.c +2 -0
index 49fcf665cb58..71b2fb068b6b 100644
@@ -132,10 +132,12 @@ static int __graph_entry(struct trace_array *tr, struct ftrace_graph_ent *trace,
 	entry = ring_buffer_event_data(event);
 	entry->graph_ent = *trace;
 
+#ifdef CONFIG_HAVE_FUNCTION_ARG_ACCESS_API
 	if (fregs) {
 		for (int i = 0; i < FTRACE_REGS_MAX_ARGS; i++)
 			entry->args[i] = ftrace_regs_get_argument(fregs, i);
 	}
+#endif
 
 	trace_buffer_unlock_commit_nostack(buffer, event);
 
kernel/trace/trace_irqsoff.c +7 -1
index 0ce00fe66d0c..c8bfa7310a91 100644
@@ -299,7 +299,13 @@ __trace_function(struct trace_array *tr,
 }
 
 #else
-#define __trace_function trace_function
+static inline void
+__trace_function(struct trace_array *tr,
+		 unsigned long ip, unsigned long parent_ip,
+		 unsigned int trace_ctx)
+{
+	return trace_function(tr, ip, parent_ip, trace_ctx, NULL);
+}
 
 static enum print_line_t irqsoff_print_line(struct trace_iterator *iter)
 {

Changes since v2: https://lore.kernel.org/linux-trace-kernel/[email protected]/

- Removed unneeded headers

- Put back removed '\n' that was accidentally erased.

- Do not use bpf_get_btf_vmlinux() to get btf element as btf_find_func_proto() will handle that.

- Fixed how structures are printed

Changes since Sven's work:

- Made the kconfig option unconditional if all the dependencies are set.

- Not save ftrace_regs in the ring buffer, as that is an abstract descriptor defined by the architectures and should remain opaque from generic code. Instead, the args are read at the time they are recorded (with the ftrace_regs passed to the callback function), and saved into the ring buffer. Then the print function only takes an array of elements.

This could allow archs to retrieve arguments that are on the stack where as, post processing ftrace_regs could cause undesirable results.

- Made the function and function graph entry events dynamically sized to allow the arguments to be appended to the event in the ring buffer. The print function only looks to see if the event saved in the ring buffer is big enough to hold all the arguments defined by the new FTRACE_REGS_MAX_ARGS macro and if so, it will assume there are arguments there and print them. This also means user space will not break on reading these events as arguments will simply be ignored.

- The printing of the arguments has some more data when things are not processed by BPF. Any unsupported argument will have the type printed out in the ring buffer.

- Also removed the spaces around the '=' as that's more in line to how trace events show their fields.

- One new patch I added to convert function graph tracing over to using args as soon as the user sets the option even if function graph tracing is enabled. Function tracer did this already by default.

Steven Rostedt (1):
ftrace: Have funcgraph-args take affect during tracing

Sven Schnelle (3):
ftrace: Add print_function_args()
ftrace: Add support for function argument to graph tracer
ftrace: Add arguments to function tracer

----

 include/linux/ftrace_regs.h          |   5 +
 kernel/trace/Kconfig                 |  12 +++
 kernel/trace/trace.c                 |  14 ++-
 kernel/trace/trace.h                 |   5 +-
 kernel/trace/trace_entries.h         |  12 ++-
 kernel/trace/trace_functions.c       |  46 +++++++++-
 kernel/trace/trace_functions_graph.c | 172 ++++++++++++++++++++++++++++-------
 kernel/trace/trace_irqsoff.c         |  12 ++-
 kernel/trace/trace_output.c          | 103 ++++++++++++++++++++-
 kernel/trace/trace_output.h          |   9 ++
 kernel/trace/trace_sched_wakeup.c    |   4 +-
 11 files changed, 340 insertions(+), 54 deletions(-)