On 20 Jun 2024, at 2:03 PM, James Clark [off-list ref] wrote:



On 18/06/2024 11:44, James Clark wrote:

quoted

On 17/06/2024 17:47, Athira Rajeev wrote:

quoted

quoted

On 17 Jun 2024, at 8:30 PM, James Clark [off-list ref] wrote:



On 17/06/2024 13:21, Athira Rajeev wrote:

quoted

Running "perftool-testsuite_probe" fails as below:

./perf test -v "perftool-testsuite_probe"
83: perftool-testsuite_probe  : FAILED

There are three fails:

1. Regexp not found: "\s*probe:inode_permission(?:_\d+)?\s+\(on inode_permission(?:[:\+][0-9A-Fa-f]+)?@.+\)"
 -- [ FAIL ] -- perf_probe :: test_adding_kernel :: listing added probe :: perf probe -l (output regexp parsing)

On a machine where NO_DEBUGINFO gets set, this one skips for me. But on
a machine where there _is_ debug info this test still fails.

But in both cases the probe looks like it was added successfully. So I'm
wondering if this one does need to be skipped, or it's just always
failing? Do you have this test passing anywhere where there is debug info?

The list command looks like it successfully lists the probe for me in
both cases, it just doesn't have an address on the end:

perf list 'probe:*'

 probe:inode_permission (on inode_permission)

Does the missing address mean anything or is it just not handled
properly by the test?

Ironically the machine that _does_ pass the debug info test also prints
this, but it looks like it still adds and lists the probe correctly:

perf probe -l probe:*

Failed to find debug information for address 0xffff80008047ac30
  probe:inode_permission (on inode_permission)

Hi James,

Thanks for checking this patch.

In environment where kernel is compiled with debuginfo:

1) Add probe point

# ./perf probe --add inode_permission
Added new event:
 probe:inode_permission (on inode_permission)

You can now use it in all perf tools, such as:

perf record -e probe:inode_permission -aR sleep 1


2) Check using perf probe -l

# ./perf probe -l
probe:inode_permission (on inode_permission:2@fs/namei.c)

With debuginfo, the result has additional info.
The test looks for matching pattern "\s*probe:inode_permission(?:_\d+)?\s+\(on inode_permission(?:[:\+][0-9A-Fa-f]+)?@.+\)” in result
where it is expecting "inode_permission:2@fs/namei.c” . The “@fs/namei.c” info needs debuginfo here.

Hi Athira,

Maybe there is a real bug and this patch is ok to go in and we should leave
it as failing. Probe -L shows there is debug info available for inode_permission:

  $ ./perf probe -L inode_permission

 <inode_permission@linux/fs/namei.c:0>
     0  int inode_permission(struct mnt_idmap *idmap,
                            struct inode *inode, int mask)
 ... more source code ...

But probe -l has an error which could be related to the following
line not showing the filename details:

 $ ./perf probe -l

 Failed to find debug information for address 0xffff80008047ac30
   probe:inode_permission (on inode_permission)

I'm running a clang kernel and sometimes I see issues with debug
info or toolchain stuff, that could be the reason.

quoted

The function I am using in patch to check for debuginfo (skip_if_no_debuginfo) is from "tests/shell/lib/probe_vfs_getname.sh"

skip_if_no_debuginfo() {
       add_probe_vfs_getname -v 2>&1 | grep -E -q "^(Failed to find the path for the kernel|Debuginfo-analysis is not supported)|(file has no debug information)" && return 2
       return 1
}

So the debuginfo test passes in your case since the log has "Failed to find debug information” which is not present in above grep string. 

It passes because there is debug info for getname_flags() which is what the
debug info check looks for. After some greps and seds it ultimately does this
which succeeds:

$ perf probe "vfs_getname=getname_flags:72 pathname=result->name:string"

Added new event:
   probe:vfs_getname    (on getname_flags:72 with pathname=result->name:string)

"Failed to find debug information for address" is only ever printed
with "perf probe -l" when there are probes added. The stderr
of that command is never piped into any grep anyway, which is why I
see it on the test output.

So "probe -L" is working but "probe -l" isn't. Ultimately it looks like a real
issue and we should leave the failure in.

To avoid confusion, by leave it in I mean this debuginfo patch is ok and
the failure I'm seeing is caused by something else.

Reviewed-by: James Clark <redacted>

Thanks James for the Reviewed-by,

Athira

quoted

quoted

James,

Only “perf probe -l” subtest fails with debuginfo enabled or other two subtests as well? Can you also share result on how other two subtests behaves ? 

1. Fail 2 :
  perf probe -nf --max-probes=512 -a 'vfs_* $params’


2. Fail 3 :
 perf probe 'vfs_read somenonexistingrandomstuffwhichisalsoprettylongorevenlongertoexceed64'

Here's the full output:

$ sudo ./perf test -vvv "testsuite_probe"
84: perftool-testsuite_probe:

--- start ---

test child forked, pid 4872
-- [ PASS ] -- perf_probe :: test_adding_kernel :: adding probe inode_permission :: 
-- [ PASS ] -- perf_probe :: test_adding_kernel :: adding probe inode_permission :: -a
-- [ PASS ] -- perf_probe :: test_adding_kernel :: adding probe inode_permission :: --add
-- [ PASS ] -- perf_probe :: test_adding_kernel :: listing added probe :: perf list
Failed to find debug information for address 0xffff80008047ac30
Regexp not found: "\s*probe:inode_permission(?:_\d+)?\s+\(on inode_permission(?:[:\+][0-9A-Fa-f]+)?@.+\)"
-- [ FAIL ] -- perf_probe :: test_adding_kernel :: listing added probe :: perf probe -l (output regexp parsing)
-- [ PASS ] -- perf_probe :: test_adding_kernel :: using added probe
-- [ PASS ] -- perf_probe :: test_adding_kernel :: deleting added probe
-- [ PASS ] -- perf_probe :: test_adding_kernel :: listing removed probe (should NOT be listed)
-- [ PASS ] -- perf_probe :: test_adding_kernel :: dry run :: adding probe
-- [ PASS ] -- perf_probe :: test_adding_kernel :: force-adding probes :: first probe adding
-- [ PASS ] -- perf_probe :: test_adding_kernel :: force-adding probes :: second probe adding (without force)
Failed to find debug information for address 0xffff80008047ac30
-- [ PASS ] -- perf_probe :: test_adding_kernel :: force-adding probes :: second probe adding (with force)
-- [ PASS ] -- perf_probe :: test_adding_kernel :: using doubled probe
-- [ PASS ] -- perf_probe :: test_adding_kernel :: removing multiple probes
-- [ PASS ] -- perf_probe :: test_adding_kernel :: wildcard adding support
-- [ PASS ] -- perf_probe :: test_adding_kernel :: non-existing variable
-- [ PASS ] -- perf_probe :: test_adding_kernel :: function with retval :: add
Regexp not found: "^\[\s+perf\s+record:\s+Woken up [0-9\.]+ times? to write data\s+\].*$"
Regexp not found: "^\[\s+perf\s+record:\s+Captured and wrote [0-9\.]+\s*MB\s+(?:[\w\+\.-]*(?:(?:[\w\+\.-]+)?(?:\/[\w\+\.-]+)+)?\/)?perf\.data(?:\.\d+)?\s*\(~?[0-9\.]+ samples\)\s+\].*$"
-- [ FAIL ] -- perf_probe :: test_adding_kernel :: function with retval :: record (command exitcode + output regexp parsing)
zero-sized data (/tmp/perftool-testsuite_probe.VMU/perf_probe/perf.data), nothing to do!
Regexp not found: "\s*cat\s+[0-9\.]+\s+\[[0-9\.]+\]\s+[0-9\.]+:\s+probe:inode_permission\w*:\s+\([0-9A-Fa-f]+\s+<\-\s+[0-9A-Fa-f]+\)\s+arg1=[0-9A-Fa-f]+"
-- [ FAIL ] -- perf_probe :: test_adding_kernel :: function argument probing :: script (command exitcode + output regexp parsing)
## [ FAIL ] ## perf_probe :: test_adding_kernel SUMMARY :: 3 failures found
---- end(-1) ----
84: perftool-testsuite_probe                                        : FAILED!

quoted

Also since you mentioned this gets skipped when debuginfo is not enabled, curious to know what is debuginfo message from your setup with debuginfo disabled.

 $ sudo ./perf probe -L getname_flags
 Failed to find the path for the kernel: Invalid ELF file
   Error: Failed to show lines.

quoted

Thanks again for checking.

Athira

quoted

quoted

quoted

2. Regexp not found: "probe:vfs_mknod"
 Regexp not found: "probe:vfs_create"
 Regexp not found: "probe:vfs_rmdir"
 Regexp not found: "probe:vfs_link"
 Regexp not found: "probe:vfs_write"
 -- [ FAIL ] -- perf_probe :: test_adding_kernel :: wildcard adding support (command exitcode + output regexp parsing)

3. Regexp not found: "Failed to find"
 Regexp not found: "somenonexistingrandomstuffwhichisalsoprettylongorevenlongertoexceed64"
 Regexp not found: "in this function|at this address"
 Line did not match any pattern: "The /boot/vmlinux file has no debug information."
 Line did not match any pattern: "Rebuild with CONFIG_DEBUG_INFO=y, or install an appropriate debuginfo package."

These three tests depends on kernel debug info.
1. Fail 1 expects file name along with probe which needs debuginfo
2. Fail 2 :
  perf probe -nf --max-probes=512 -a 'vfs_* $params'
  Debuginfo-analysis is not supported.
   Error: Failed to add events.

3. Fail 3 :
 perf probe 'vfs_read somenonexistingrandomstuffwhichisalsoprettylongorevenlongertoexceed64'
 Debuginfo-analysis is not supported.
 Error: Failed to add events.

There is already helper function skip_if_no_debuginfo in
lib/probe_vfs_getname.sh which does perf probe and returns
"2" if debug info is not present. Use the skip_if_no_debuginfo
function and skip only the three tests which needs debuginfo
based on the result.

With the patch:

  83: perftool-testsuite_probe:
 --- start ---
 test child forked, pid 3927
 -- [ PASS ] -- perf_probe :: test_adding_kernel :: adding probe inode_permission ::
 -- [ PASS ] -- perf_probe :: test_adding_kernel :: adding probe inode_permission :: -a
 -- [ PASS ] -- perf_probe :: test_adding_kernel :: adding probe inode_permission :: --add
 -- [ PASS ] -- perf_probe :: test_adding_kernel :: listing added probe :: perf list
 Regexp not found: "\s*probe:inode_permission(?:_\d+)?\s+\(on inode_permission(?:[:\+][0-9A-Fa-f]+)?@.+\)"
 -- [ SKIP ] -- perf_probe :: test_adding_kernel :: 2 2 Skipped due to missing debuginfo :: testcase skipped
 -- [ PASS ] -- perf_probe :: test_adding_kernel :: using added probe
 -- [ PASS ] -- perf_probe :: test_adding_kernel :: deleting added probe
 -- [ PASS ] -- perf_probe :: test_adding_kernel :: listing removed probe (should NOT be listed)
 -- [ PASS ] -- perf_probe :: test_adding_kernel :: dry run :: adding probe
 -- [ PASS ] -- perf_probe :: test_adding_kernel :: force-adding probes :: first probe adding
 -- [ PASS ] -- perf_probe :: test_adding_kernel :: force-adding probes :: second probe adding (without force)
 -- [ PASS ] -- perf_probe :: test_adding_kernel :: force-adding probes :: second probe adding (with force)
 -- [ PASS ] -- perf_probe :: test_adding_kernel :: using doubled probe
 -- [ PASS ] -- perf_probe :: test_adding_kernel :: removing multiple probes
 Regexp not found: "probe:vfs_mknod"
 Regexp not found: "probe:vfs_create"
 Regexp not found: "probe:vfs_rmdir"
 Regexp not found: "probe:vfs_link"
 Regexp not found: "probe:vfs_write"
 -- [ SKIP ] -- perf_probe :: test_adding_kernel :: 2 2 Skipped due to missing debuginfo :: testcase skipped
 Regexp not found: "Failed to find"
 Regexp not found: "somenonexistingrandomstuffwhichisalsoprettylongorevenlongertoexceed64"
 Regexp not found: "in this function|at this address"
 Line did not match any pattern: "The /boot/vmlinux file has no debug information."
 Line did not match any pattern: "Rebuild with CONFIG_DEBUG_INFO=y, or install an appropriate debuginfo package."
 -- [ SKIP ] -- perf_probe :: test_adding_kernel :: 2 2 Skipped due to missing debuginfo :: testcase skipped
 -- [ PASS ] -- perf_probe :: test_adding_kernel :: function with retval :: add
 -- [ PASS ] -- perf_probe :: test_adding_kernel :: function with retval :: record
 -- [ PASS ] -- perf_probe :: test_adding_kernel :: function argument probing :: script
 ## [ PASS ] ## perf_probe :: test_adding_kernel SUMMARY
 ---- end(0) ----
 83: perftool-testsuite_probe                                        : Ok

Only the three specific tests are skipped and remaining
ran successfully.

Signed-off-by: Athira Rajeev <redacted>
---
.../shell/base_probe/test_adding_kernel.sh    | 31 +++++++++++++++++--
1 file changed, 28 insertions(+), 3 deletions(-)

diff --git a/tools/perf/tests/shell/base_probe/test_adding_kernel.sh b/tools/perf/tests/shell/base_probe/test_adding_kernel.sh
index 63bb8974b38e..187dc8d4b163 100755
--- a/tools/perf/tests/shell/base_probe/test_adding_kernel.sh
+++ b/tools/perf/tests/shell/base_probe/test_adding_kernel.sh

@@ -21,8 +21,18 @@

THIS_TEST_NAME=`basename $0 .sh`
TEST_RESULT=0

+# shellcheck source=lib/probe_vfs_getname.sh
+. "$(dirname "$0")/../lib/probe_vfs_getname.sh"
+
TEST_PROBE=${TEST_PROBE:-"inode_permission"}

+# set NO_DEBUGINFO to skip testcase if debuginfo is not present
+# skip_if_no_debuginfo returns 2 if debuginfo is not present
+skip_if_no_debuginfo
+if [ $? -eq 2 ]; then
+ NO_DEBUGINFO=1
+fi
+
check_kprobes_available
if [ $? -ne 0 ]; then
print_overall_skipped

@@ -67,7 +77,12 @@ PERF_EXIT_CODE=$?

../common/check_all_patterns_found.pl "\s*probe:${TEST_PROBE}(?:_\d+)?\s+\(on ${TEST_PROBE}(?:[:\+]$RE_NUMBER_HEX)?@.+\)" < $LOGS_DIR/adding_kernel_list-l.log
CHECK_EXIT_CODE=$?

-print_results $PERF_EXIT_CODE $CHECK_EXIT_CODE "listing added probe :: perf probe -l"
+if [ $NO_DEBUGINFO ] ; then
+ print_testcase_skipped $NO_DEBUGINFO $NO_DEBUGINFO "Skipped due to missing debuginfo"
+else
+ print_results $PERF_EXIT_CODE $CHECK_EXIT_CODE "listing added probe :: perf probe -l"
+fi
+
(( TEST_RESULT += $? ))

@@ -208,7 +223,12 @@ PERF_EXIT_CODE=$?

../common/check_all_patterns_found.pl "probe:vfs_mknod" "probe:vfs_create" "probe:vfs_rmdir" "probe:vfs_link" "probe:vfs_write" < $LOGS_DIR/adding_kernel_adding_wildcard.err
CHECK_EXIT_CODE=$?

-print_results $PERF_EXIT_CODE $CHECK_EXIT_CODE "wildcard adding support"
+if [ $NO_DEBUGINFO ] ; then
+ print_testcase_skipped $NO_DEBUGINFO $NO_DEBUGINFO "Skipped due to missing debuginfo"
+else
+ print_results $PERF_EXIT_CODE $CHECK_EXIT_CODE "wildcard adding support"
+fi
+
(( TEST_RESULT += $? ))

@@ -232,7 +252,12 @@ CHECK_EXIT_CODE=$?

../common/check_no_patterns_found.pl "$RE_SEGFAULT" < $LOGS_DIR/adding_kernel_nonexisting.err
(( CHECK_EXIT_CODE += $? ))

-print_results $PERF_EXIT_CODE $CHECK_EXIT_CODE "non-existing variable"
+if [ $NO_DEBUGINFO ]; then
+ print_testcase_skipped $NO_DEBUGINFO $NO_DEBUGINFO "Skipped due to missing debuginfo"
+else
+ print_results $PERF_EXIT_CODE $CHECK_EXIT_CODE "non-existing variable"
+fi
+
(( TEST_RESULT += $? ))