Re: [PATCH 1/2] ftrace: Fix preemption acounting for stacktrace trigger command

[Steven Rostedt <rostedt@goodmis.org>]

On Mon, 12 May 2025 17:42:45 +0800
pengdonglin <dolinux.peng@gmail.com> wrote:

> From: pengdonglin <pengdonglin@xiaomi.com>
> 
> While using the stacktrace trigger command to trace syscalls/sys_enter_read,
> I noticed that the preemption count was consistently reported as 1, which seemed
> incorrect:

FYI, the change log should always be in "imperative mood". The above is
fine for cover letters, but for the change log that will live forever in
the git history, it should not reference "I" nor "This patch". That is, it
should state:

   When using the stacktrace trigger command to trace syscalls, the
   preemption count was consistently reported as 1 when the system call
   event itself had 0 (".").

   For example:

> 
> root@ubuntu22-vm:/sys/kernel/tracing/events/syscalls/sys_enter_read
> $ echo stacktrace > trigger
> $ echo 1 > enable
> 
>     sshd-416     [002] .....   232.864910: sys_read(fd: a, buf: 556b1f3221d0, count: 8000)
>     sshd-416     [002] ...1.   232.864913: <stack trace>
>  => ftrace_syscall_enter
>  => syscall_trace_enter
>  => do_syscall_64
>  => entry_SYSCALL_64_after_hwframe  
> 
> The root cause is that the trace framework disables preemption in __DO_TRACE before
> invoking the trigger callback.
> 
> This patch uses tracing_gen_ctx_dec() to obtain the correct preemption
> count within the callback, resulting in accurate reporting:

Instead of "This patch ..."

   Use the tracing_gen_ctx_dec() that will accommodate for the increase of
   the preemption count in __DO_TRACE when calling the callback. The result
   is the accurate reporting of:

This is FYI for when you send new patches. You don't need to resend. I'll
update the change logs and take these patches (unless of course I find
something else wrong with them).

-- Steve

> 
>     sshd-410     [004] .....   210.117660: sys_read(fd: 4, buf: 559b725ba130, count: 40000)
>     sshd-410     [004] .....   210.117662: <stack trace>
>  => ftrace_syscall_enter
>  => syscall_trace_enter
>  => do_syscall_64
>  => entry_SYSCALL_64_after_hwframe  
> 
> Signed-off-by: pengdonglin <dolinux.peng@gmail.com>
> ---
>  kernel/trace/trace_events_trigger.c | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
> 
> diff --git a/kernel/trace/trace_events_trigger.c b/kernel/trace/trace_events_trigger.c
> index b66b6d235d91..6e87ae2a1a66 100644
> --- a/kernel/trace/trace_events_trigger.c
> +++ b/kernel/trace/trace_events_trigger.c
> @@ -1560,7 +1560,7 @@ stacktrace_trigger(struct event_trigger_data *data,
>  	struct trace_event_file *file = data->private_data;
>  
>  	if (file)
> -		__trace_stack(file->tr, tracing_gen_ctx(), STACK_SKIP);
> +		__trace_stack(file->tr, tracing_gen_ctx_dec(), STACK_SKIP);
>  	else
>  		trace_dump_stack(STACK_SKIP);
>  }