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

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <20250512101608.3eb16e43@gandalf.local.home>
Date: Mon, 12 May 2025 10:16:08 -0400
From: Steven Rostedt <rostedt@...dmis.org>
To: pengdonglin <dolinux.peng@...il.com>
Cc: mhiramat@...nel.org, dolinux.peng@...i.com,
 linux-trace-kernel@...r.kernel.org, linux-kernel@...r.kernel.org
Subject: Re: [PATCH 1/2] ftrace: Fix preemption acounting for stacktrace
 trigger command

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

> From: pengdonglin <pengdonglin@...omi.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@...ntu22-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@...il.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);
>  }