* [PATCH] ftrace: Get the true parent ip for function tracer
@ 2024-08-21 13:27 Jeff Xie
2024-08-21 13:59 ` Steven Rostedt
0 siblings, 1 reply; 3+ messages in thread
From: Jeff Xie @ 2024-08-21 13:27 UTC (permalink / raw)
To: rostedt, mhiramat
Cc: mathieu.desnoyers, linux-trace-kernel, linux-kernel, xiehuan09,
Jeff Xie
Currently, when using both function tracer and function graph simultaneously,
it is found that function tracer sometimes captures a fake parent ip(return_to_handler)
instead of the true parent ip.
This issue is easy to reproduce. Below are my reproduction steps:
jeff-labs:~/bin # ./trace-net.sh
jeff-labs:~/bin # cat /sys/kernel/debug/tracing/instances/foo/trace | grep return_to_handler
trace-net.sh-405 [001] ...2. 31.859501: avc_has_perm+0x4/0x190 <-return_to_handler+0x0/0x40
trace-net.sh-405 [001] ...2. 31.859503: simple_setattr+0x4/0x70 <-return_to_handler+0x0/0x40
trace-net.sh-405 [001] ...2. 31.859503: truncate_pagecache+0x4/0x60 <-return_to_handler+0x0/0x40
trace-net.sh-405 [001] ...2. 31.859505: unmap_mapping_range+0x4/0x140 <-return_to_handler+0x0/0x40
trace-net.sh-405 [001] ...3. 31.859508: _raw_spin_unlock+0x4/0x30 <-return_to_handler+0x0/0x40
[...]
The following is my simple trace script:
<snip>
jeff-labs:~/bin # cat ./trace-net.sh
TRACE_PATH="/sys/kernel/debug/tracing"
set_events() {
echo 1 > $1/events/net/enable
echo 1 > $1/events/tcp/enable
echo 1 > $1/events/sock/enable
echo 1 > $1/events/napi/enable
echo 1 > $1/events/fib/enable
echo 1 > $1/events/neigh/enable
}
set_events ${TRACE_PATH}
echo 1 > ${TRACE_PATH}/options/sym-offset
echo 1 > ${TRACE_PATH}/options/funcgraph-tail
echo 1 > ${TRACE_PATH}/options/funcgraph-proc
echo 1 > ${TRACE_PATH}/options/funcgraph-abstime
echo 'tcp_orphan*' > ${TRACE_PATH}/set_ftrace_notrace
echo function_graph > ${TRACE_PATH}/current_tracer
INSTANCE_FOO=${TRACE_PATH}/instances/foo
if [ ! -e $INSTANCE_FOO ]; then
mkdir ${INSTANCE_FOO}
fi
set_events ${INSTANCE_FOO}
echo 1 > ${INSTANCE_FOO}/options/sym-offset
echo 'tcp_orphan*' > ${INSTANCE_FOO}/set_ftrace_notrace
echo function > ${INSTANCE_FOO}/current_tracer
echo 1 > ${TRACE_PATH}/tracing_on
echo 1 > ${INSTANCE_FOO}/tracing_on
echo > ${TRACE_PATH}/trace
echo > ${INSTANCE_FOO}/trace
</snip>
Signed-off-by: Jeff Xie <jeff.xie@linux.dev>
---
kernel/trace/trace_functions.c | 18 ++++++++++++++++++
1 file changed, 18 insertions(+)
diff --git a/kernel/trace/trace_functions.c b/kernel/trace/trace_functions.c
index 3b0cea37e029..273b8c7eeb2d 100644
--- a/kernel/trace/trace_functions.c
+++ b/kernel/trace/trace_functions.c
@@ -176,6 +176,19 @@ static void function_trace_start(struct trace_array *tr)
tracing_reset_online_cpus(&tr->array_buffer);
}
+static unsigned long
+function_get_true_parent_ip(unsigned long parent_ip, struct ftrace_regs *fregs)
+{
+ unsigned long true_parent_ip;
+ int idx = 0;
+
+ true_parent_ip = parent_ip;
+ if (unlikely(parent_ip == (unsigned long)&return_to_handler))
+ true_parent_ip = ftrace_graph_ret_addr(current, &idx, parent_ip,
+ (unsigned long *)fregs->regs.sp);
+ return true_parent_ip;
+}
+
static void
function_trace_call(unsigned long ip, unsigned long parent_ip,
struct ftrace_ops *op, struct ftrace_regs *fregs)
@@ -193,6 +206,8 @@ function_trace_call(unsigned long ip, unsigned long parent_ip,
if (bit < 0)
return;
+ parent_ip = function_get_true_parent_ip(parent_ip, fregs);
+
trace_ctx = tracing_gen_ctx();
cpu = smp_processor_id();
@@ -241,6 +256,7 @@ function_stack_trace_call(unsigned long ip, unsigned long parent_ip,
* recursive protection is performed.
*/
local_irq_save(flags);
+ parent_ip = function_get_true_parent_ip(parent_ip, fregs);
cpu = raw_smp_processor_id();
data = per_cpu_ptr(tr->array_buffer.data, cpu);
disabled = atomic_inc_return(&data->disabled);
@@ -309,6 +325,7 @@ function_no_repeats_trace_call(unsigned long ip, unsigned long parent_ip,
if (bit < 0)
return;
+ parent_ip = function_get_true_parent_ip(parent_ip, fregs);
cpu = smp_processor_id();
data = per_cpu_ptr(tr->array_buffer.data, cpu);
if (atomic_read(&data->disabled))
@@ -356,6 +373,7 @@ function_stack_no_repeats_trace_call(unsigned long ip, unsigned long parent_ip,
* recursive protection is performed.
*/
local_irq_save(flags);
+ parent_ip = function_get_true_parent_ip(parent_ip, fregs);
cpu = raw_smp_processor_id();
data = per_cpu_ptr(tr->array_buffer.data, cpu);
disabled = atomic_inc_return(&data->disabled);
--
2.34.1
^ permalink raw reply related [flat|nested] 3+ messages in thread
* Re: [PATCH] ftrace: Get the true parent ip for function tracer
2024-08-21 13:27 [PATCH] ftrace: Get the true parent ip for function tracer Jeff Xie
@ 2024-08-21 13:59 ` Steven Rostedt
2024-08-21 14:16 ` jeff.xie
0 siblings, 1 reply; 3+ messages in thread
From: Steven Rostedt @ 2024-08-21 13:59 UTC (permalink / raw)
To: Jeff Xie
Cc: mhiramat, mathieu.desnoyers, linux-trace-kernel, linux-kernel,
xiehuan09
On Wed, 21 Aug 2024 21:27:55 +0800
Jeff Xie <jeff.xie@linux.dev> wrote:
Hi Jeff,
Thanks for the patch.
> Signed-off-by: Jeff Xie <jeff.xie@linux.dev>
> ---
> kernel/trace/trace_functions.c | 18 ++++++++++++++++++
> 1 file changed, 18 insertions(+)
>
> diff --git a/kernel/trace/trace_functions.c b/kernel/trace/trace_functions.c
> index 3b0cea37e029..273b8c7eeb2d 100644
> --- a/kernel/trace/trace_functions.c
> +++ b/kernel/trace/trace_functions.c
> @@ -176,6 +176,19 @@ static void function_trace_start(struct trace_array *tr)
> tracing_reset_online_cpus(&tr->array_buffer);
> }
>
> +static unsigned long
> +function_get_true_parent_ip(unsigned long parent_ip, struct ftrace_regs *fregs)
I wonder if we should make this inline, or even __always_inline, as this
will be called in a very hot path, and I want to make sure that the
compiler always inlines it. It likely should, but we should also give the
compiler a hint that it should.
-- Steve
> +{
> + unsigned long true_parent_ip;
> + int idx = 0;
> +
> + true_parent_ip = parent_ip;
> + if (unlikely(parent_ip == (unsigned long)&return_to_handler))
> + true_parent_ip = ftrace_graph_ret_addr(current, &idx, parent_ip,
> + (unsigned long *)fregs->regs.sp);
> + return true_parent_ip;
> +}
> +
> static void
> function_trace_call(unsigned long ip, unsigned long parent_ip,
> struct ftrace_ops *op, struct ftrace_regs *fregs)
> @@ -193,6 +206,8 @@ function_trace_call(unsigned long ip, unsigned long parent_ip,
> if (bit < 0)
> return;
>
> + parent_ip = function_get_true_parent_ip(parent_ip, fregs);
> +
> trace_ctx = tracing_gen_ctx();
>
> cpu = smp_processor_id();
> @@ -241,6 +256,7 @@ function_stack_trace_call(unsigned long ip, unsigned long parent_ip,
> * recursive protection is performed.
> */
> local_irq_save(flags);
> + parent_ip = function_get_true_parent_ip(parent_ip, fregs);
> cpu = raw_smp_processor_id();
> data = per_cpu_ptr(tr->array_buffer.data, cpu);
> disabled = atomic_inc_return(&data->disabled);
> @@ -309,6 +325,7 @@ function_no_repeats_trace_call(unsigned long ip, unsigned long parent_ip,
> if (bit < 0)
> return;
>
> + parent_ip = function_get_true_parent_ip(parent_ip, fregs);
> cpu = smp_processor_id();
> data = per_cpu_ptr(tr->array_buffer.data, cpu);
> if (atomic_read(&data->disabled))
> @@ -356,6 +373,7 @@ function_stack_no_repeats_trace_call(unsigned long ip, unsigned long parent_ip,
> * recursive protection is performed.
> */
> local_irq_save(flags);
> + parent_ip = function_get_true_parent_ip(parent_ip, fregs);
> cpu = raw_smp_processor_id();
> data = per_cpu_ptr(tr->array_buffer.data, cpu);
> disabled = atomic_inc_return(&data->disabled);
^ permalink raw reply [flat|nested] 3+ messages in thread
* Re: [PATCH] ftrace: Get the true parent ip for function tracer
2024-08-21 13:59 ` Steven Rostedt
@ 2024-08-21 14:16 ` jeff.xie
0 siblings, 0 replies; 3+ messages in thread
From: jeff.xie @ 2024-08-21 14:16 UTC (permalink / raw)
To: Steven Rostedt
Cc: mhiramat, mathieu.desnoyers, linux-trace-kernel, linux-kernel,
xiehuan09
August 21, 2024 at 9:59 PM, "Steven Rostedt" <rostedt@goodmis.org> wrote:
Hi Steven,
>
> On Wed, 21 Aug 2024 21:27:55 +0800
>
> Jeff Xie <jeff.xie@linux.dev> wrote:
>
> Hi Jeff,
>
> Thanks for the patch.
>
> >
> > Signed-off-by: Jeff Xie <jeff.xie@linux.dev>
> >
> > ---
> >
> > kernel/trace/trace_functions.c | 18 ++++++++++++++++++
> >
> > 1 file changed, 18 insertions(+)
> >
> >
> >
> > diff --git a/kernel/trace/trace_functions.c b/kernel/trace/trace_functions.c
> >
> > index 3b0cea37e029..273b8c7eeb2d 100644
> >
> > --- a/kernel/trace/trace_functions.c
> >
> > +++ b/kernel/trace/trace_functions.c
> >
> > @@ -176,6 +176,19 @@ static void function_trace_start(struct trace_array *tr)
> >
> > tracing_reset_online_cpus(&tr->array_buffer);
> >
> > }
> >
> >
> >
> > +static unsigned long
> >
> > +function_get_true_parent_ip(unsigned long parent_ip, struct ftrace_regs *fregs)
> >
>
> I wonder if we should make this inline, or even __always_inline, as this
>
> will be called in a very hot path, and I want to make sure that the
>
> compiler always inlines it. It likely should, but we should also give the
>
> compiler a hint that it should.
Yes, Thank you for your suggestion. It is indeed a very hot path,
and I will add __always_inline in the next version.
>
> -- Steve
>
> >
> > +{
> >
> > + unsigned long true_parent_ip;
> >
> > + int idx = 0;
> >
> > +
> >
> > + true_parent_ip = parent_ip;
> >
> > + if (unlikely(parent_ip == (unsigned long)&return_to_handler))
> >
> > + true_parent_ip = ftrace_graph_ret_addr(current, &idx, parent_ip,
> >
> > + (unsigned long *)fregs->regs.sp);
> >
> > + return true_parent_ip;
> >
> > +}
> >
> > +
> >
> > static void
> >
> > function_trace_call(unsigned long ip, unsigned long parent_ip,
> >
> > struct ftrace_ops *op, struct ftrace_regs *fregs)
> >
> > @@ -193,6 +206,8 @@ function_trace_call(unsigned long ip, unsigned long parent_ip,
> >
> > if (bit < 0)
> >
> > return;
> >
> >
> >
> > + parent_ip = function_get_true_parent_ip(parent_ip, fregs);
> >
> > +
> >
> > trace_ctx = tracing_gen_ctx();
> >
> >
> >
> > cpu = smp_processor_id();
> >
> > @@ -241,6 +256,7 @@ function_stack_trace_call(unsigned long ip, unsigned long parent_ip,
> >
> > * recursive protection is performed.
> >
> > */
> >
> > local_irq_save(flags);
> >
> > + parent_ip = function_get_true_parent_ip(parent_ip, fregs);
> >
> > cpu = raw_smp_processor_id();
> >
> > data = per_cpu_ptr(tr->array_buffer.data, cpu);
> >
> > disabled = atomic_inc_return(&data->disabled);
> >
> > @@ -309,6 +325,7 @@ function_no_repeats_trace_call(unsigned long ip, unsigned long parent_ip,
> >
> > if (bit < 0)
> >
> > return;
> >
> >
> >
> > + parent_ip = function_get_true_parent_ip(parent_ip, fregs);
> >
> > cpu = smp_processor_id();
> >
> > data = per_cpu_ptr(tr->array_buffer.data, cpu);
> >
> > if (atomic_read(&data->disabled))
> >
> > @@ -356,6 +373,7 @@ function_stack_no_repeats_trace_call(unsigned long ip, unsigned long parent_ip,
> >
> > * recursive protection is performed.
> >
> > */
> >
> > local_irq_save(flags);
> >
> > + parent_ip = function_get_true_parent_ip(parent_ip, fregs);
> >
> > cpu = raw_smp_processor_id();
> >
> > data = per_cpu_ptr(tr->array_buffer.data, cpu);
> >
> > disabled = atomic_inc_return(&data->disabled);
> >
>
^ permalink raw reply [flat|nested] 3+ messages in thread
end of thread, other threads:[~2024-08-21 14:16 UTC | newest]
Thread overview: 3+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2024-08-21 13:27 [PATCH] ftrace: Get the true parent ip for function tracer Jeff Xie
2024-08-21 13:59 ` Steven Rostedt
2024-08-21 14:16 ` jeff.xie
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).