On 10/1/24 10:27 PM, ts wrote:

On 9/30/24 8:51 AM, Masami Hiramatsu (Google) wrote:
On Thu, 26 Sep 2024 15:13:07 +0900
Tatsuya S<tatsuya.s2...@gmail.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.s2...@gmail.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() )

Thanks for the other tests. This issue may be function_trace_call() specific problem.

Not function_trace_call(),  function_stack_trace_call().
So I will change the place to increment skip number.

Thank you,

        preempt_disable_notrace();
  --
2.46.1

Thank you,

Reply via email to