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

[Mark Brown]

On Thu, Feb 27, 2025 at 01:58:06PM -0500, Steven Rostedt wrote:
> From: Sven Schnelle <svens@xxxxxxxxxxxxx>
> 
> Wire up the code to print function arguments in the function graph
> tracer. This functionality can be enabled/disabled during runtime with
> options/funcgraph-args.

We've been seeing the PID filters selftest failing for a while on
several arm64 systems, a bisect I managed to run without running into
any confounding issues pointed to this patch which is in mainline as
ff5c9c576e75.  It's in the ftrace code, but I'm not immediately seeing
the relevance.  Output from a failing run:

 6190 18:38:41.261255  # not ok 48 ftrace - function pid filters
 6191 18:38:41.274039  # # execute: /lava-922575/1/tests/2_kselftest-ftrace/automated/linux/kselftest/ftrace/test.d/ftrace/func-filter-pid.tc
 6192 18:38:41.285261  # # + checkreq /lava-922575/1/tests/2_kselftest-ftrace/automated/linux/kselftest/ftrace/test.d/ftrace/func-filter-pid.tc
 6193 18:38:41.296551  # # + grep ^#[ t]*requires: /lava-922575/1/tests/2_kselftest-ftrace/automated/linux/kselftest/ftrace/test.d/ftrace/func-filter-pid.tc
 6194 18:38:41.307877  # # + cut -f2- -d:
 6195 18:38:41.308157  # # + requires= set_ftrace_pid set_ftrace_filter function:tracer
 6196 18:38:41.319397  # # + eval check_requires  set_ftrace_pid set_ftrace_filter function:tracer
 6197 18:38:41.319681  # # + check_requires set_ftrace_pid set_ftrace_filter function:tracer
 6198 18:38:41.319905  # # + p=set_ftrace_pid
 6199 18:38:41.330653  # # + r=set_ftrace_pid
 6200 18:38:41.330936  # # + t=set_ftrace_pid
 6201 18:38:41.331161  # # + [ set_ftrace_pid != set_ftrace_pid ]
 6202 18:38:41.331367  # # + [ set_ftrace_pid != set_ftrace_pid ]
 6203 18:38:41.342045  # # + [ set_ftrace_pid != set_ftrace_pid ]
 6204 18:38:41.342330  # # + [ ! -e set_ftrace_pid ]
 .......
 6364 18:39:15.411636  # # + grep -v 7190
 6365 18:39:15.411865  # # + wc -l
 6366 18:39:15.412073  # # + count_other=3
 6367 18:39:15.412554  # # + [ 2 -eq 0 -o 3 -ne 0 ]
 6368 18:39:15.412773  # # + fail PID filtering not working?
 6369 18:39:15.422776  # # + do_reset
 6370 18:39:15.423055  # # + [ 1 -eq 1 ]
 6371 18:39:15.423278  # # + echo nofunction-fork
 6372 18:39:15.423485  # # + [ 1 -eq 1 ]
 6373 18:39:15.423681  # # + echo 0
 6374 18:39:15.423873  # # + echo PID filtering not working?
 6375 18:39:15.434095  # # PID filtering not working?
 6376 18:39:15.434377  # # + exit_fail
 6377 18:39:15.434602  # # + exit 1

bisect log:

git bisect start
# status: waiting for both good and bad commits
# good: [38fec10eb60d687e30c8c6b5420d86e8149f7557] Linux 6.14
git bisect good 38fec10eb60d687e30c8c6b5420d86e8149f7557
# status: waiting for bad commit, 1 good commit known
# bad: [46086739de22d72319e37c37a134d32db52e1c5c] Add linux-next specific files for 20250409
git bisect bad 46086739de22d72319e37c37a134d32db52e1c5c
# bad: [390513642ee6763c7ada07f0a1470474986e6c1c] io_uring: always do atomic put from iowq
git bisect bad 390513642ee6763c7ada07f0a1470474986e6c1c
# good: [9b960d8cd6f712cb2c03e2bdd4d5ca058238037f] Merge tag 'for-6.15/block-20250322' of git://git.kernel.dk/linux
git bisect good 9b960d8cd6f712cb2c03e2bdd4d5ca058238037f
# good: [023b1e9d265ca0662111a9df23d22b4632717a8a] Merge git://git.kernel.org/pub/scm/linux/kernel/git/netdev/net
git bisect good 023b1e9d265ca0662111a9df23d22b4632717a8a
# good: [3a90a72aca0a98125f0c7350ffb7cc63665f8047] Merge tag 'asm-generic-6.15-2' of git://git.kernel.org/pub/scm/linux/kernel/git/arnd/asm-generic
git bisect good 3a90a72aca0a98125f0c7350ffb7cc63665f8047
# good: [4a4b30ea80d8cb5e8c4c62bb86201f4ea0d9b030] Merge tag 'bcachefs-2025-03-24' of git://evilpiepirate.org/bcachefs
git bisect good 4a4b30ea80d8cb5e8c4c62bb86201f4ea0d9b030
# bad: [a7e135fe59a516b2a981fc5820e7a1e2118b427e] Merge tag 'probes-v6.15' of git://git.kernel.org/pub/scm/linux/kernel/git/trace/linux-trace
git bisect bad a7e135fe59a516b2a981fc5820e7a1e2118b427e
# bad: [31eb415bf6f06c90fdd9b635caf3a6c5110a38b6] Merge tag 'ftrace-v6.15' of git://git.kernel.org/pub/scm/linux/kernel/git/trace/linux-trace
git bisect bad 31eb415bf6f06c90fdd9b635caf3a6c5110a38b6
# good: [e8eac9fc4832976af800628ba8cbd351edc7f841] ext4: remove unneeded forward declaration in namei.c
git bisect good e8eac9fc4832976af800628ba8cbd351edc7f841
# good: [129245cfbd6d79c6d603f357f428010ccc0f0ee7] ext4: correct the error handle in ext4_fallocate()
git bisect good 129245cfbd6d79c6d603f357f428010ccc0f0ee7
# good: [dc208c69c033d3caba0509da1ae065d2b5ff165f] scripts/sorttable: Allow matches to functions before function entry
git bisect good dc208c69c033d3caba0509da1ae065d2b5ff165f
# bad: [5ba8f4a39ecd160c7b6ef8ef1373375799710a97] function_graph: Remove the unused variable func
git bisect bad 5ba8f4a39ecd160c7b6ef8ef1373375799710a97
# good: [533c20b062d7c25cbcbadb31e3ecb95a08ddb877] ftrace: Add print_function_args()
git bisect good 533c20b062d7c25cbcbadb31e3ecb95a08ddb877
# bad: [c7a60a733c373eed0094774c141bf2934237e7ff] ftrace: Have funcgraph-args take affect during tracing
git bisect bad c7a60a733c373eed0094774c141bf2934237e7ff
# bad: [ff5c9c576e754563b3be4922c3968bc3b0269541] ftrace: Add support for function argument to graph tracer
git bisect bad ff5c9c576e754563b3be4922c3968bc3b0269541
# first bad commit: [ff5c9c576e754563b3be4922c3968bc3b0269541] ftrace: Add support for function argument to graph tracer

Attachment: signature.asc
Description: PGP signature