linux-kernel - Re: [PATCH v4 2/4] ftrace: Add support for function argument to graph tracer

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: <2edc0ba8-2f45-40dc-86d9-5ab7cea8938c@sirena.org.uk>
Date: Fri, 11 Apr 2025 17:58:32 +0100
From: Mark Brown <broonie@...nel.org>
To: Steven Rostedt <rostedt@...dmis.org>
Cc: linux-kernel@...r.kernel.org, linux-trace-kernel@...r.kernel.org,
	bpf@...r.kernel.org, Masami Hiramatsu <mhiramat@...nel.org>,
	Mark Rutland <mark.rutland@....com>,
	Mathieu Desnoyers <mathieu.desnoyers@...icios.com>,
	Andrew Morton <akpm@...ux-foundation.org>,
	Sven Schnelle <svens@...ux.ibm.com>,
	Paul Walmsley <paul.walmsley@...ive.com>,
	Palmer Dabbelt <palmer@...belt.com>,
	Albert Ou <aou@...s.berkeley.edu>, Guo Ren <guoren@...nel.org>,
	Donglin Peng <dolinux.peng@...il.com>,
	Zheng Yejian <zhengyejian@...weicloud.com>, Aishwarya.TCV@....com
Subject: Re: [PATCH v4 2/4] ftrace: Add support for function argument to
 graph tracer

On Fri, Apr 11, 2025 at 12:45:52PM -0400, Steven Rostedt wrote:
> Mark Brown <broonie@...nel.org> wrote:
> > On Thu, Apr 10, 2025 at 01:17:45PM -0400, Steven Rostedt wrote:

> > > Hmm, I wonder if there's junk being added into the trace.  

> > > Can you add this patch, and show me the output when it fails again?  

> Can you show the information before this output, to see what it is actually
> testing?

Here's a bit more of the context - this is literally just the ftrace
selftests so it'll be doing whatever that does, there's a huge amount of
log splat generated when enumerating all the triggers.  I do note that
it appears to assume there's a ping binary which might confusing things,
though I'm surprised that'd be a regression rather than something that
just never worked:

# # + reset_ftrace_filter
# # + [ ! -f set_ftrace_filter ]
# # + echo
# # + grep -v ^# set_ftrace_filter
# # + read t
# # + disable_events
# # + echo 0
# # + clear_dynamic_events
# # + again=1
# # + stop=1
# # + [ 1 -eq 1 ]
# # + stop=2
# # + [ 2 -gt 10 ]
# # + again=2
# # + grep -v ^# dynamic_events
# # + read line
# # + [ 2 -eq 1 ]
# # + [ -f set_event_pid ]
# # + echo
# # + [ -f set_ftrace_pid ]
# # + echo
# # + [ -f set_ftrace_notrace ]
# # + echo
# # + [ -f set_graph_function ]
# # + echo
# # + tee set_graph_function set_graph_notrace
# # 
# # + [ -f stack_trace_filter ]
# # + echo
# # + [ -f kprobe_events ]
# # + echo
# # + [ -f uprobe_events ]
# # + echo
# # + [ -f synthetic_events ]
# # + echo
# # + [ -f snapshot ]
# # + echo 0
# # + [ -f options/pause-on-trace ]
# # + echo 1
# # + clear_trace
# # + echo
# # + enable_tracing
# # + echo 1
# # + . /opt/kselftest/ftrace/test.d/ftrace/func-filter-pid.tc
# # + do_function_fork=1
# # + do_funcgraph_proc=1
# # + [ ! -f options/function-fork ]
# # + [ ! -f options/funcgraph-proc ]
# # + read PID _
# # + [ 1 -eq 1 ]
# # + grep function-fork trace_options
# # + orig_value=nofunction-fork
# # + [ 1 -eq 1 ]
# # + cat options/funcgraph-proc
# # + orig_value2=0
# # + echo 1
# # + do_test function
# # + TRACER=function
# # + disable_tracing
# # + echo 0
# # + echo do_execve*
# # + echo kernel_clone
# # + echo 5190
# # + echo function
# # + [ 1 -eq 1 ]
# # + echo nofunction-fork
# # + enable_tracing
# # + echo 1
# # + yield
# # + ping 127.0.0.1 -c 1
# # ./ftracetest: 179: /opt/kselftest/ftrace/test.d/ftrace/func-filter-pid.tc: ping: not found
# # + sleep .001
# # + cat trace
# # + grep -v ^#
# # + grep 5190
# # + wc -l
# # + count_pid=2
# # + cat trace
# # + grep -v ^#
# # + grep -v 5190
# # + wc -l
# # + count_other=0
# # + [ 2 -eq 0 -o 0 -ne 0 ]
# # + disable_tracing
# # + echo 0
# # + clear_trace
# # + echo
# # + [ 1 -eq 0 ]
# # + echo function-fork
# # + enable_tracing
# # + echo 1
# # + yield
# # + ping 127.0.0.1 -c 1
# # ./ftracetest: 179: /opt/kselftest/ftrace/test.d/ftrace/func-filter-pid.tc: ping: not found
# # + sleep .001
# # + cat trace
# # + grep -v ^#
# # + grep 5190
# # + wc -l
# # + count_pid=2
# # + cat trace
# # + grep -v ^#
# # + grep -v 5190
# # + wc -l
# # + count_other=17
# # + [ 2 -eq 0 -o 17 -eq 0 ]
# # + grep -s function_graph available_tracers
# # function_graph wakeup_dl wakeup_rt wakeup preemptirqsoff preemptoff irqsoff function nop
# # + do_test function_graph
# # + TRACER=function_graph
# # + disable_tracing
# # + echo 0
# # + echo do_execve*
# # + echo kernel_clone
# # + echo 5190
# # + echo function_graph
# # + [ 1 -eq 1 ]
# # + echo nofunction-fork
# # + enable_tracing
# # + echo 1
# # + yield
# # + ping 127.0.0.1 -c 1
# # ./ftracetest: 179: /opt/kselftest/ftrace/test.d/ftrace/func-filter-pid.tc: ping: not found
# # + sleep .001
# # + cat trace
# # + grep -v ^#
# # + grep 5190
# # + wc -l
# # + count_pid=2
# # + cat trace
# # + grep -v ^#
# # + grep -v 5190
# # + wc -l
# # + count_other=3
# # + [ 2 -eq 0 -o 3 -ne 0 ]
# # + cat trace
# # # tracer: function_graph
# # #
# # # CPU  TASK/PID         DURATION                  FUNCTION CALLS
# # # |     |    |           |   |                     |   |   |   |
# # 0)  ftracet-5190  | ! 537.633 us  |  kernel_clone(); /* ret=0x1470 */
# # 
# # 0)  ftracet-5190  | ! 508.253 us  |  kernel_clone(); /* ret=0x1471 */
# # 
# # 0)  ftracet-5190  | ! 215.716 us  |  kernel_clone(); /* ret=0x1476 */
# # 
# # 0)  ftracet-5190  | ! 493.890 us  |  kernel_clone(); /* ret=0x147b */
# # 
# # + fail PID filtering not working?
# # + do_reset
# # + [ 1 -eq 1 ]
# # + echo nofunction-fork
# # + [ 1 -eq 1 ]
# # + echo 0
# # + echo PID filtering not working?
# # PID filtering not working?
# # + exit_fail
# # + exit 1

> > # # + cat trace
> > # # # tracer: function_graph
> > # # #
> > # # # CPU  TASK/PID         DURATION                  FUNCTION CALLS
> > # # # |     |    |           |   |                     |   |   |   |
> > # # 0) ftracet-12279  | ! 598.118 us  |  kernel_clone(); /* ret=0x301f */
> > # # 
> > # # 0) ftracet-12279  | ! 492.539 us  |  kernel_clone(); /* ret=0x3020 */
> > # # 
> > # # 0) ftracet-12279  | ! 231.104 us  |  kernel_clone(); /* ret=0x3025 */
> > # # 
> > # # 0) ftracet-12279  | ! 555.566 us  |  kernel_clone(); /* ret=0x302a */
> > # # 
> > # # + fail PID filtering not working?

> Also, is it possible to just enable function_graph tarcing and see if it
> adds these blank lines between events?

That'll take a bit more arranging, I'm running these tests as batch jobs
in CI infrastructure.  I'll try to have a look.  The only other test
that actually failed was:

# not ok 25 Checking dynamic events limitations

which isn't flagged as a regression (there's some other UNRESOLVED ones).

Download attachment "signature.asc" of type "application/pgp-signature" (489 bytes)