[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-Id: <20240930085139.5d34f28236a67ef1e9143655@kernel.org>
Date: Mon, 30 Sep 2024 08:51:39 +0900
From: Masami Hiramatsu (Google) <mhiramat@...nel.org>
To: Tatsuya S <tatsuya.s2862@...il.com>
Cc: Steven Rostedt <rostedt@...dmis.org>, Mathieu Desnoyers
<mathieu.desnoyers@...icios.com>, linux-kernel@...r.kernel.org,
linux-trace-kernel@...r.kernel.org
Subject: Re: [PATCH v2] ftrace: Hide a extra entry in stack trace
On Thu, 26 Sep 2024 15:13:07 +0900
Tatsuya S <tatsuya.s2862@...il.com> wrote:
> A extra entry is shown on stack trace(CONFIG_UNWINDER_ORC=y).
>
> [003] ..... 110.171589: vfs_write <-__x64_sys_write
> [003] ..... 110.171600: <stack trace>
> => XXXXXXXXX (Wrong function name)
> => vfs_write
> => __x64_sys_write
> => do_syscall_64
> => entry_SYSCALL_64_after_hwframe
OK, I confirmed it;
------
echo 1 > options/func_stack_trace
echo "vfs_write" >> set_ftrace_filter
echo "function" > current_tracer
echo > /dev/null
cat trace
sh-136 [005] ..... 266.884180: vfs_write <-ksys_write
sh-136 [005] ..... 266.884188: <stack trace>
=> 0xffffffffa0004099
=> vfs_write
=> ksys_write
=> do_syscall_64
=> entry_SYSCALL_64_after_hwframe
------
>
> To resolve this, increment skip in __ftrace_trace_stack().
> The reason why skip is incremented in __ftrace_trace_stack()
> is because __ftrace_trace_stack() in stack trace is the only function
> that wasn't skipped from anywhere.
>
> Signed-off-by: Tatsuya S <tatsuya.s2862@...il.com>
> ---
> kernel/trace/trace.c | 4 +---
> 1 file changed, 1 insertion(+), 3 deletions(-)
>
> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> index c3b2c7dfadef..0f2e255f563c 100644
> --- a/kernel/trace/trace.c
> +++ b/kernel/trace/trace.c
> @@ -2916,10 +2916,8 @@ static void __ftrace_trace_stack(struct trace_buffer *buffer,
> * Add one, for this function and the call to save_stack_trace()
> * If regs is set, then these functions will not be in the way.
> */
Hmm, with this change, the above comment should also be updated.
> -#ifndef CONFIG_UNWINDER_ORC
> - if (!regs)
> + if (IS_ENABLED(CONFIG_UNWINDER_ORC) || !regs)
> skip++;
> -#endif
Also, this solves just one pattern (only enable function tracer) but if
there are fprobes (or kprobes) on the same function, it introduces another issue.
e.g. (with this fix)
------
echo 1 > options/func_stack_trace
echo 1 > options/stacktrace
echo "vfs_write" >> set_ftrace_filter
echo "function" > current_tracer
echo "f:myevent vfs_write" > dynamic_events
echo 1 > events/fprobes/myevent/enable
echo > /dev/null
cat trace
...
sh-140 [001] ...1. 18.352601: myevent: (vfs_write+0x4/0x560)
sh-140 [001] ...1. 18.352602: <stack trace>
=> ksys_write
=> do_syscall_64
=> entry_SYSCALL_64_after_hwframe
sh-140 [001] ...1. 18.352602: vfs_write <-ksys_write
sh-140 [001] ...1. 18.352604: <stack trace>
=> ftrace_regs_call
=> vfs_write
=> ksys_write
=> do_syscall_64
=> entry_SYSCALL_64_after_hwframe
------
As you can see, myevent skips "vfs_write".
(and function tracer still have ftrace_regs_call() )
Thank you,
>
> preempt_disable_notrace();
>
> --
> 2.46.1
>
--
Masami Hiramatsu (Google) <mhiramat@...nel.org>
Powered by blists - more mailing lists