* [PATCH v2 1/2] perf/test: Fix perf test 84 on s390
@ 2022-12-28 14:57 Thomas Richter
2022-12-28 14:57 ` [PATCH v2 2/2] perf/test: Fix test case 89 for x86 Thomas Richter
0 siblings, 1 reply; 5+ messages in thread
From: Thomas Richter @ 2022-12-28 14:57 UTC (permalink / raw)
To: linux-kernel, linux-perf-users, acme, sumanthk
Cc: svens, gor, hca, Thomas Richter
perf test '84: probe libc's inet_pton & backtrace it with ping'
fails on s390. Debugging revealed a changed stack trace for the
ping command using probes:
ping 35729 [002] 8006.365063: probe_libc:inet_pton: (3ff9603e7c0)
13e7c0 __GI___inet_pton+0x0 (/usr/lib64/libc.so.6)
---> 104371 text_to_binary_address+0xef1 (inlined)
104371 gaih_inet+0xef1 (inlined)
104371 __GI_getaddrinfo+0xef1 (inlined)
5d4b main+0x139b (/usr/bin/ping)
The line ---> text_to_binary_address ...
is new. It was introduced with glibc version 2.36.7.2 released
with Fedora 37 for s390.
Output before
# ./perf test 84
84: probe libc's inet_pton & backtrace it with ping : FAILED!
#
Output after:
# ./perf test 84
84: probe libc's inet_pton & backtrace it with ping : Ok
#
Signed-off-by: Thomas Richter <tmricht@linux.ibm.com>
---
tools/perf/tests/shell/record+probe_libc_inet_pton.sh | 1 +
1 file changed, 1 insertion(+)
diff --git a/tools/perf/tests/shell/record+probe_libc_inet_pton.sh b/tools/perf/tests/shell/record+probe_libc_inet_pton.sh
index 34c400ccbe04..4e9de55d871a 100755
--- a/tools/perf/tests/shell/record+probe_libc_inet_pton.sh
+++ b/tools/perf/tests/shell/record+probe_libc_inet_pton.sh
@@ -37,6 +37,7 @@ trace_libc_inet_pton_backtrace() {
case "$(uname -m)" in
s390x)
eventattr='call-graph=dwarf,max-stack=4'
+ echo "text_to_binary_address.*\+0x[[:xdigit:]]+[[:space:]]\($libc|inlined\)$" >> $expected
echo "gaih_inet.*\+0x[[:xdigit:]]+[[:space:]]\($libc|inlined\)$" >> $expected
echo "(__GI_)?getaddrinfo\+0x[[:xdigit:]]+[[:space:]]\($libc|inlined\)$" >> $expected
echo "main\+0x[[:xdigit:]]+[[:space:]]\(.*/bin/ping.*\)$" >> $expected
--
2.38.1
^ permalink raw reply related [flat|nested] 5+ messages in thread* [PATCH v2 2/2] perf/test: Fix test case 89 for x86 2022-12-28 14:57 [PATCH v2 1/2] perf/test: Fix perf test 84 on s390 Thomas Richter @ 2022-12-28 14:57 ` Thomas Richter 2023-01-03 13:20 ` Arnaldo Carvalho de Melo 0 siblings, 1 reply; 5+ messages in thread From: Thomas Richter @ 2022-12-28 14:57 UTC (permalink / raw) To: linux-kernel, linux-perf-users, acme, sumanthk Cc: svens, gor, hca, Thomas Richter From: Thomas Richter <richter@de.ibm.com> perf test '89: probe libc's inet_pton & backtrace it with ping' fails on x86. Debugging revealed a changed stack trace for the ping command using probes: ping 35729 [002] 8006.365063: probe_libc:inet_pton: (3ff9603e7c0) 12be50 __GI___inet_pton+0x0 (/usr/lib64/libc.so.6) 4fca main+0x139b (/usr/bin/ping) The line getaddrinfo.... in the call stack is gone. It was introduced with glibc version 2.36.8 released with Fedora 37. To make the test case more robust to glibc changes resulting in changed call stacks, redesign the test completely. Read the output lines from the perf probe of the ping command. Create an array of expected patterns. Each array entry specifies a pattern that may appear in the perf probe output. Check that each probe output line is matched in the expected patterns array. If there is no match it is an error. However not every pattern in the expected pattern array must be hit as there may be redundant entries. This scheme does not test the sequence of the call stack entries but the patterns itself are long and complicated enough. Also each perf probe output line has to be in the expected pattern array for the test to pass Output before on x86 # ./perf test 89 89: probe libc's inet_pton & backtrace it with ping : FAILED! # Output after on x86 # ./perf test 89 89: probe libc's inet_pton & backtrace it with ping : Ok # Signed-off-by: Thomas Richter <richter@de.ibm.com> --- .../shell/record+probe_libc_inet_pton.sh | 70 +++++++++++++------ 1 file changed, 47 insertions(+), 23 deletions(-) diff --git a/tools/perf/tests/shell/record+probe_libc_inet_pton.sh b/tools/perf/tests/shell/record+probe_libc_inet_pton.sh index 4e9de55d871a..3baef1aa92f5 100755 --- a/tools/perf/tests/shell/record+probe_libc_inet_pton.sh +++ b/tools/perf/tests/shell/record+probe_libc_inet_pton.sh @@ -30,28 +30,37 @@ add_libc_inet_pton_event() { trace_libc_inet_pton_backtrace() { - expected=`mktemp -u /tmp/expected.XXX` + declare -a expected + local -i idx=0 hit maxstack=4 - echo "ping[][0-9 \.:]+$event_name: \([[:xdigit:]]+\)" > $expected - echo ".*inet_pton\+0x[[:xdigit:]]+[[:space:]]\($libc|inlined\)$" >> $expected + expected[0]='ping[][0-9 \.:]+'"$event_name"': \([[:xdigit:]]+\)' + expected[1]='.*inet_pton\+0x[[:xdigit:]]+[[:space:]]\('"$libc"'|inlined\)$' case "$(uname -m)" in s390x) - eventattr='call-graph=dwarf,max-stack=4' - echo "text_to_binary_address.*\+0x[[:xdigit:]]+[[:space:]]\($libc|inlined\)$" >> $expected - echo "gaih_inet.*\+0x[[:xdigit:]]+[[:space:]]\($libc|inlined\)$" >> $expected - echo "(__GI_)?getaddrinfo\+0x[[:xdigit:]]+[[:space:]]\($libc|inlined\)$" >> $expected - echo "main\+0x[[:xdigit:]]+[[:space:]]\(.*/bin/ping.*\)$" >> $expected + eventattr='call-graph=dwarf,max-stack='"$maxstack" + expected[2]='text_to_binary_address.*\+0x[[:xdigit:]]+[[:space:]]\($libc|inlined\)$' + expected[3]='gaih_inet.*\+0x[[:xdigit:]]+[[:space:]]\('"$libc"'|inlined\)$' + expected[4]='(__GI_)?getaddrinfo\+0x[[:xdigit:]]+[[:space:]]\('"$libc"'|inlined\)$' + expected[5]='main\+0x[[:xdigit:]]+[[:space:]]\(.*/bin/ping.*\)$' ;; ppc64|ppc64le) - eventattr='max-stack=4' - echo "gaih_inet.*\+0x[[:xdigit:]]+[[:space:]]\($libc\)$" >> $expected - echo "getaddrinfo\+0x[[:xdigit:]]+[[:space:]]\($libc\)$" >> $expected - echo ".*(\+0x[[:xdigit:]]+|\[unknown\])[[:space:]]\(.*/bin/ping.*\)$" >> $expected + eventattr='max-stack='"$maxstack" + expected[2]='gaih_inet.*\+0x[[:xdigit:]]+[[:space:]]\('"$libc"'\)$' + expected[3]='getaddrinfo\+0x[[:xdigit:]]+[[:space:]]\('"$libc"'\)$' + # Line valid with glibc 2.35.x with fedora 36 + expected[4]='.*(\+0x[[:xdigit:]]+|\[unknown\])[[:space:]]\(.*/bin/ping.*\)$' + # New line introduced with glibc 2.36.x with fedora 37, replaces previous line + expected[5]='[[:xdigit:]]+[[:space:]](\[unknown\]|main)\+0x[[:xdigit:]]+.*\(.*/bin/ping.*\)$' ;; *) - eventattr='max-stack=3' - echo "getaddrinfo\+0x[[:xdigit:]]+[[:space:]]\($libc\)$" >> $expected - echo ".*(\+0x[[:xdigit:]]+|\[unknown\])[[:space:]]\(.*/bin/ping.*\)$" >> $expected + maxstack=3 + eventattr='max-stack='"$maxstack" + expected[2]='getaddrinfo\+0x[[:xdigit:]]+[[:space:]]\('"$libc"'\)$' + # Line valid with glibc 2.35.x with fedora 36 + expected[3]='.*(\+0x[[:xdigit:]]+|\[unknown\])[[:space:]]\(.*/bin/ping.*\)$' + # New lines introduced with glibc 2.36.x with fedora 37, replaces previous line + expected[4]='[[:xdigit:]]+[[:space:]](\[unknown\]|main)\+0x[[:xdigit:]]+.*\(.*/bin/ping.*\)$' + expected[5]='.*main\+0x[[:xdigit:]]+.*\('"$libc"'\)$' ;; esac @@ -60,16 +69,31 @@ trace_libc_inet_pton_backtrace() { perf record -e $event_name/$eventattr/ -o $perf_data ping -6 -c 1 ::1 > /dev/null 2>&1 perf script -i $perf_data > $perf_script + # To make the call stack checking more robust to changes in the glibc + # just check that each probe output line appears in the expected + # patterns array. + # This scheme does not check the sequence as before but tests + # that every line in the call stack is expected. Considering the + # long patterns this should be save too. exec 3<$perf_script - exec 4<$expected - while read line <&3 && read -r pattern <&4; do - [ -z "$pattern" ] && break - echo $line - echo "$line" | grep -E -q "$pattern" - if [ $? -ne 0 ] ; then - printf "FAIL: expected backtrace entry \"%s\" got \"%s\"\n" "$pattern" "$line" + + # Number of input lines to check, take value from max-stack attribute + while read line <&3; do + [ "$idx" -ge "$maxstack" ] && break + [ -z "$line" ] && break + + hit=0 + for pattern in "${expected[@]}" + do + echo "$line" | egrep -q "$pattern" + [ $? -eq 0 ] && { hit=1; break; } + done + if [ "$hit" -eq 0 ] + then + printf "FAIL: missing backtrace entry for line \"%s\"\n" "$line" return 1 fi + ((++idx)) done # If any statements are executed from this point onwards, @@ -92,6 +116,6 @@ skip_if_no_perf_probe && \ add_libc_inet_pton_event && \ trace_libc_inet_pton_backtrace err=$? -rm -f ${perf_data} ${perf_script} ${expected} +rm -f ${perf_data} ${perf_script} delete_libc_inet_pton_event exit $err -- 2.38.1 ^ permalink raw reply related [flat|nested] 5+ messages in thread
* Re: [PATCH v2 2/2] perf/test: Fix test case 89 for x86 2022-12-28 14:57 ` [PATCH v2 2/2] perf/test: Fix test case 89 for x86 Thomas Richter @ 2023-01-03 13:20 ` Arnaldo Carvalho de Melo 2023-01-03 13:48 ` Arnaldo Carvalho de Melo 2023-01-04 9:33 ` Thomas Richter 0 siblings, 2 replies; 5+ messages in thread From: Arnaldo Carvalho de Melo @ 2023-01-03 13:20 UTC (permalink / raw) To: Thomas Richter Cc: linux-kernel, linux-perf-users, Masami Hiramatsu, Namhyung Kim, Jiri Olsa, Ian Rogers, Adrian Hunter, sumanthk, svens, gor, hca, Thomas Richter Em Wed, Dec 28, 2022 at 03:57:04PM +0100, Thomas Richter escreveu: > From: Thomas Richter <richter@de.ibm.com> > > perf test '89: probe libc's inet_pton & backtrace it with ping' > fails on x86. Debugging revealed a changed stack trace for the > ping command using probes: > > ping 35729 [002] 8006.365063: probe_libc:inet_pton: (3ff9603e7c0) > 12be50 __GI___inet_pton+0x0 (/usr/lib64/libc.so.6) > 4fca main+0x139b (/usr/bin/ping) > > The line getaddrinfo.... in the call stack is gone. > It was introduced with glibc version 2.36.8 released > with Fedora 37. Humm, I'm testing and invetigating this issue and by looking at the backtraces I see that it is just on the first entry that the getaddrinfo isn't present, i.e. now there are two inet_pton() calls, one of them doesn't come from getaddrinfo(): [root@quaco ~]# cat /tmp/perf.script.IUC ping 623883 [006] 265438.471610: probe_libc:inet_pton: (7f32bcf314c0) 1314c0 __GI___inet_pton+0x0 (/usr/lib64/libc.so.6) 29510 __libc_start_call_main+0x80 (/usr/lib64/libc.so.6) ping 623883 [006] 265438.471664: probe_libc:inet_pton: (7f32bcf314c0) 1314c0 __GI___inet_pton+0x0 (/usr/lib64/libc.so.6) fa6c6 getaddrinfo+0x126 (/usr/lib64/libc.so.6) 491e [unknown] (/usr/bin/ping) The above is the temp file for the perf script output from the collected perf.data file See the second entry? Its as we expect: [root@quaco ~]# cat /tmp/expected.aT6 ping[][0-9 \.:]+probe_libc:inet_pton: \([[:xdigit:]]+\) .*inet_pton\+0x[[:xdigit:]]+[[:space:]]\(/usr/lib64/libc.so.6|inlined\)$ getaddrinfo\+0x[[:xdigit:]]+[[:space:]]\(/usr/lib64/libc.so.6\)$ .*(\+0x[[:xdigit:]]+|\[unknown\])[[:space:]]\(.*/bin/ping.*\)$ [root@quaco ~]# But if I just ignore that first one and match against the second event instance: [root@quaco ~]# perf test inet_pton 90: probe libc's inet_pton & backtrace it with ping : Ok [root@quaco ~]# perf test -v inet_pton 90: probe libc's inet_pton & backtrace it with ping : --- start --- test child forked, pid 626199 ping 626222 [007] 266979.123047: probe_libc:inet_pton_1: (7f0650d314c0) 1314c0 __GI___inet_pton+0x0 (/usr/lib64/libc.so.6) fa6c6 getaddrinfo+0x126 (/usr/lib64/libc.so.6) 491e n (/usr/bin/ping) test child finished with 0 ---- end ---- probe libc's inet_pton & backtrace it with ping: Ok [root@quaco ~]# So, can you try with the following patch in your s/390 system? I wish 'perf script' had a --skip option that allowed us to ask for just the second event, not having that I did a trick with tac + grep -m1 -B :-) We can try to revisit your approach for the next merge window, as at this point, for 6.2 we want for fixes to be as minimal as possible. It works for me on Fedora 36, glibc 2.35-20.fc36, where it was failing, I'll now try on a arm64 machine, thanks. - Arnaldo diff --git a/tools/perf/tests/shell/record+probe_libc_inet_pton.sh b/tools/perf/tests/shell/record+probe_libc_inet_pton.sh index 34c400ccbe046b59..216b6b64caa3011e 100755 --- a/tools/perf/tests/shell/record+probe_libc_inet_pton.sh +++ b/tools/perf/tests/shell/record+probe_libc_inet_pton.sh @@ -57,7 +57,7 @@ trace_libc_inet_pton_backtrace() { perf_data=`mktemp -u /tmp/perf.data.XXX` perf_script=`mktemp -u /tmp/perf.script.XXX` perf record -e $event_name/$eventattr/ -o $perf_data ping -6 -c 1 ::1 > /dev/null 2>&1 - perf script -i $perf_data > $perf_script + perf script -i $perf_data | tac | grep -m1 ^ping -B9 | tac > $perf_script exec 3<$perf_script exec 4<$expected > To make the test case more robust to glibc changes resulting in changed > call stacks, redesign the test completely. > Read the output lines from the perf probe of the ping command. > Create an array of expected patterns. Each array entry specifies a > pattern that may appear in the perf probe output. > Check that each probe output line is matched in the expected > patterns array. If there is no match it is an error. > However not every pattern in the expected pattern array must be hit > as there may be redundant entries. > > This scheme does not test the sequence of the call stack entries > but the patterns itself are long and complicated enough. > Also each perf probe output line has to be in the expected pattern > array for the test to pass > > Output before on x86 > # ./perf test 89 > 89: probe libc's inet_pton & backtrace it with ping : FAILED! > # > > Output after on x86 > # ./perf test 89 > 89: probe libc's inet_pton & backtrace it with ping : Ok > # > > Signed-off-by: Thomas Richter <richter@de.ibm.com> > --- > .../shell/record+probe_libc_inet_pton.sh | 70 +++++++++++++------ > 1 file changed, 47 insertions(+), 23 deletions(-) > > diff --git a/tools/perf/tests/shell/record+probe_libc_inet_pton.sh b/tools/perf/tests/shell/record+probe_libc_inet_pton.sh > index 4e9de55d871a..3baef1aa92f5 100755 > --- a/tools/perf/tests/shell/record+probe_libc_inet_pton.sh > +++ b/tools/perf/tests/shell/record+probe_libc_inet_pton.sh > @@ -30,28 +30,37 @@ add_libc_inet_pton_event() { > > trace_libc_inet_pton_backtrace() { > > - expected=`mktemp -u /tmp/expected.XXX` > + declare -a expected > + local -i idx=0 hit maxstack=4 > > - echo "ping[][0-9 \.:]+$event_name: \([[:xdigit:]]+\)" > $expected > - echo ".*inet_pton\+0x[[:xdigit:]]+[[:space:]]\($libc|inlined\)$" >> $expected > + expected[0]='ping[][0-9 \.:]+'"$event_name"': \([[:xdigit:]]+\)' > + expected[1]='.*inet_pton\+0x[[:xdigit:]]+[[:space:]]\('"$libc"'|inlined\)$' > case "$(uname -m)" in > s390x) > - eventattr='call-graph=dwarf,max-stack=4' > - echo "text_to_binary_address.*\+0x[[:xdigit:]]+[[:space:]]\($libc|inlined\)$" >> $expected > - echo "gaih_inet.*\+0x[[:xdigit:]]+[[:space:]]\($libc|inlined\)$" >> $expected > - echo "(__GI_)?getaddrinfo\+0x[[:xdigit:]]+[[:space:]]\($libc|inlined\)$" >> $expected > - echo "main\+0x[[:xdigit:]]+[[:space:]]\(.*/bin/ping.*\)$" >> $expected > + eventattr='call-graph=dwarf,max-stack='"$maxstack" > + expected[2]='text_to_binary_address.*\+0x[[:xdigit:]]+[[:space:]]\($libc|inlined\)$' > + expected[3]='gaih_inet.*\+0x[[:xdigit:]]+[[:space:]]\('"$libc"'|inlined\)$' > + expected[4]='(__GI_)?getaddrinfo\+0x[[:xdigit:]]+[[:space:]]\('"$libc"'|inlined\)$' > + expected[5]='main\+0x[[:xdigit:]]+[[:space:]]\(.*/bin/ping.*\)$' > ;; > ppc64|ppc64le) > - eventattr='max-stack=4' > - echo "gaih_inet.*\+0x[[:xdigit:]]+[[:space:]]\($libc\)$" >> $expected > - echo "getaddrinfo\+0x[[:xdigit:]]+[[:space:]]\($libc\)$" >> $expected > - echo ".*(\+0x[[:xdigit:]]+|\[unknown\])[[:space:]]\(.*/bin/ping.*\)$" >> $expected > + eventattr='max-stack='"$maxstack" > + expected[2]='gaih_inet.*\+0x[[:xdigit:]]+[[:space:]]\('"$libc"'\)$' > + expected[3]='getaddrinfo\+0x[[:xdigit:]]+[[:space:]]\('"$libc"'\)$' > + # Line valid with glibc 2.35.x with fedora 36 > + expected[4]='.*(\+0x[[:xdigit:]]+|\[unknown\])[[:space:]]\(.*/bin/ping.*\)$' > + # New line introduced with glibc 2.36.x with fedora 37, replaces previous line > + expected[5]='[[:xdigit:]]+[[:space:]](\[unknown\]|main)\+0x[[:xdigit:]]+.*\(.*/bin/ping.*\)$' > ;; > *) > - eventattr='max-stack=3' > - echo "getaddrinfo\+0x[[:xdigit:]]+[[:space:]]\($libc\)$" >> $expected > - echo ".*(\+0x[[:xdigit:]]+|\[unknown\])[[:space:]]\(.*/bin/ping.*\)$" >> $expected > + maxstack=3 > + eventattr='max-stack='"$maxstack" > + expected[2]='getaddrinfo\+0x[[:xdigit:]]+[[:space:]]\('"$libc"'\)$' > + # Line valid with glibc 2.35.x with fedora 36 > + expected[3]='.*(\+0x[[:xdigit:]]+|\[unknown\])[[:space:]]\(.*/bin/ping.*\)$' > + # New lines introduced with glibc 2.36.x with fedora 37, replaces previous line > + expected[4]='[[:xdigit:]]+[[:space:]](\[unknown\]|main)\+0x[[:xdigit:]]+.*\(.*/bin/ping.*\)$' > + expected[5]='.*main\+0x[[:xdigit:]]+.*\('"$libc"'\)$' > ;; > esac > > @@ -60,16 +69,31 @@ trace_libc_inet_pton_backtrace() { > perf record -e $event_name/$eventattr/ -o $perf_data ping -6 -c 1 ::1 > /dev/null 2>&1 > perf script -i $perf_data > $perf_script > > + # To make the call stack checking more robust to changes in the glibc > + # just check that each probe output line appears in the expected > + # patterns array. > + # This scheme does not check the sequence as before but tests > + # that every line in the call stack is expected. Considering the > + # long patterns this should be save too. > exec 3<$perf_script > - exec 4<$expected > - while read line <&3 && read -r pattern <&4; do > - [ -z "$pattern" ] && break > - echo $line > - echo "$line" | grep -E -q "$pattern" > - if [ $? -ne 0 ] ; then > - printf "FAIL: expected backtrace entry \"%s\" got \"%s\"\n" "$pattern" "$line" > + > + # Number of input lines to check, take value from max-stack attribute > + while read line <&3; do > + [ "$idx" -ge "$maxstack" ] && break > + [ -z "$line" ] && break > + > + hit=0 > + for pattern in "${expected[@]}" > + do > + echo "$line" | egrep -q "$pattern" > + [ $? -eq 0 ] && { hit=1; break; } > + done > + if [ "$hit" -eq 0 ] > + then > + printf "FAIL: missing backtrace entry for line \"%s\"\n" "$line" > return 1 > fi > + ((++idx)) > done > > # If any statements are executed from this point onwards, > @@ -92,6 +116,6 @@ skip_if_no_perf_probe && \ > add_libc_inet_pton_event && \ > trace_libc_inet_pton_backtrace > err=$? > -rm -f ${perf_data} ${perf_script} ${expected} > +rm -f ${perf_data} ${perf_script} > delete_libc_inet_pton_event > exit $err > -- > 2.38.1 -- - Arnaldo ^ permalink raw reply related [flat|nested] 5+ messages in thread
* Re: [PATCH v2 2/2] perf/test: Fix test case 89 for x86 2023-01-03 13:20 ` Arnaldo Carvalho de Melo @ 2023-01-03 13:48 ` Arnaldo Carvalho de Melo 2023-01-04 9:33 ` Thomas Richter 1 sibling, 0 replies; 5+ messages in thread From: Arnaldo Carvalho de Melo @ 2023-01-03 13:48 UTC (permalink / raw) To: Thomas Richter Cc: linux-kernel, linux-perf-users, Masami Hiramatsu, Namhyung Kim, Jiri Olsa, Ian Rogers, Adrian Hunter, sumanthk, svens, gor, hca, Thomas Richter Em Tue, Jan 03, 2023 at 10:20:42AM -0300, Arnaldo Carvalho de Melo escreveu: > It works for me on Fedora 36, glibc 2.35-20.fc36, where it was failing, > I'll now try on a arm64 machine, thanks. Works as well there, see the full commit log so far: From e697ea1f4c481fbb87bbcd27ed1be8e1b7616046 Mon Sep 17 00:00:00 2001 From: Arnaldo Carvalho de Melo <acme@redhat.com> Date: Tue, 3 Jan 2023 10:21:01 -0300 Subject: [PATCH 1/1] perf test record_probe_libc_inet_pton: Fix failure due to extra inet_pton() backtrace in glibc >= 2.35 Starting with glibc 2.35 there are extra inet_pton() calls when doing a IPv6 ping as in one of the 'perf test' entry, which makes it fail: # perf test inet_pton 89: probe libc's inet_pton & backtrace it with ping : FAILED! # If we look at what this script is expecting (commenting out the removal of the temporary files in it): # cat /tmp/expected.aT6 ping[][0-9 \.:]+probe_libc:inet_pton: \([[:xdigit:]]+\) .*inet_pton\+0x[[:xdigit:]]+[[:space:]]\(/usr/lib64/libc.so.6|inlined\)$ getaddrinfo\+0x[[:xdigit:]]+[[:space:]]\(/usr/lib64/libc.so.6\)$ .*(\+0x[[:xdigit:]]+|\[unknown\])[[:space:]]\(.*/bin/ping.*\)$ # And looking at what we are getting out of 'perf script', to match with the above: # cat /tmp/perf.script.IUC ping 623883 [006] 265438.471610: probe_libc:inet_pton: (7f32bcf314c0) 1314c0 __GI___inet_pton+0x0 (/usr/lib64/libc.so.6) 29510 __libc_start_call_main+0x80 (/usr/lib64/libc.so.6) ping 623883 [006] 265438.471664: probe_libc:inet_pton: (7f32bcf314c0) 1314c0 __GI___inet_pton+0x0 (/usr/lib64/libc.so.6) fa6c6 getaddrinfo+0x126 (/usr/lib64/libc.so.6) 491e [unknown] (/usr/bin/ping) # We see that its just the first call to inet_pton() that didn't came thru getaddrinfo(), so if we ignore the first the script matches what it expects, testing that using 'perf probe' + 'perf record' + 'perf script' with callchains on userspace targets is producing the expected results. Since we don't have a 'perf script --skip' to help us here, use tac + grep to do that, resulting in a one liner that makes this script work on both older glibc versions as well as with 2.35. With it, on fedora 36, x86, glibc 2.35: # perf test inet_pton 90: probe libc's inet_pton & backtrace it with ping : Ok # perf test -v inet_pton 90: probe libc's inet_pton & backtrace it with ping : --- start --- test child forked, pid 627197 ping 627220 1 267956.962402: probe_libc:inet_pton_1: (7f488bf314c0) 1314c0 __GI___inet_pton+0x0 (/usr/lib64/libc.so.6) fa6c6 getaddrinfo+0x126 (/usr/lib64/libc.so.6) 491e n (/usr/bin/ping) test child finished with 0 ---- end ---- probe libc's inet_pton & backtrace it with ping: Ok # And on Ubuntu on a Libre Computer ROC-RK3399-PC arm64 system: Before this patch it works (see that the script used has no 'tac' to remove the first event): root@roc-rk3399-pc:~# dpkg -l | grep libc-bin ii libc-bin 2.35-0ubuntu3.1 arm64 GNU C Library: Binaries root@roc-rk3399-pc:~# grep -w tac ~acme/libexec/perf-core/tests/shell/record+probe_libc_inet_pton.sh root@roc-rk3399-pc:~# perf test inet_pton 86: probe libc's inet_pton & backtrace it with ping : Ok root@roc-rk3399-pc:~# perf test -v inet_pton 86: probe libc's inet_pton & backtrace it with ping : --- start --- test child forked, pid 1375 ping 1399 [000] 4114.417450: probe_libc:inet_pton: (ffffb3e26120) 106120 inet_pton+0x0 (/usr/lib/aarch64-linux-gnu/libc.so.6) d18bc getaddrinfo+0xec (/usr/lib/aarch64-linux-gnu/libc.so.6) 2b68 [unknown] (/usr/bin/ping) test child finished with 0 ---- end ---- probe libc's inet_pton & backtrace it with ping: Ok root@roc-rk3399-pc:~# And after it continues to work: root@roc-rk3399-pc:~# grep -w tac ~acme/libexec/perf-core/tests/shell/record+probe_libc_inet_pton.sh perf script -i $perf_data | tac | grep -m1 ^ping -B9 | tac > $perf_script root@roc-rk3399-pc:~# perf test inet_pton 86: probe libc's inet_pton & backtrace it with ping : Ok root@roc-rk3399-pc:~# perf test -v inet_pton 86: probe libc's inet_pton & backtrace it with ping : --- start --- test child forked, pid 6995 ping 7019 [005] 4832.160741: probe_libc:inet_pton: (ffffa62e6120) 106120 inet_pton+0x0 (/usr/lib/aarch64-linux-gnu/libc.so.6) d18bc getaddrinfo+0xec (/usr/lib/aarch64-linux-gnu/libc.so.6) 2b68 [unknown] (/usr/bin/ping) test child finished with 0 ---- end ---- probe libc's inet_pton & backtrace it with ping: Ok root@roc-rk3399-pc:~# Reported-by: Thomas Richter <tmricht@linux.ibm.com> Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Heiko Carstens <hca@linux.ibm.com> Cc: Ian Rogers <irogers@google.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Masami Hiramatsu <mhiramat@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Sumanth Korikkar <sumanthk@linux.ibm.com> Cc: Sven Schnelle <svens@linux.ibm.com> Cc: Vasily Gorbik <gor@linux.ibm.com> Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com> --- tools/perf/tests/shell/record+probe_libc_inet_pton.sh | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tools/perf/tests/shell/record+probe_libc_inet_pton.sh b/tools/perf/tests/shell/record+probe_libc_inet_pton.sh index 34c400ccbe046b59..216b6b64caa3011e 100755 --- a/tools/perf/tests/shell/record+probe_libc_inet_pton.sh +++ b/tools/perf/tests/shell/record+probe_libc_inet_pton.sh @@ -57,7 +57,7 @@ trace_libc_inet_pton_backtrace() { perf_data=`mktemp -u /tmp/perf.data.XXX` perf_script=`mktemp -u /tmp/perf.script.XXX` perf record -e $event_name/$eventattr/ -o $perf_data ping -6 -c 1 ::1 > /dev/null 2>&1 - perf script -i $perf_data > $perf_script + perf script -i $perf_data | tac | grep -m1 ^ping -B9 | tac > $perf_script exec 3<$perf_script exec 4<$expected -- 2.39.0 ^ permalink raw reply related [flat|nested] 5+ messages in thread
* Re: [PATCH v2 2/2] perf/test: Fix test case 89 for x86 2023-01-03 13:20 ` Arnaldo Carvalho de Melo 2023-01-03 13:48 ` Arnaldo Carvalho de Melo @ 2023-01-04 9:33 ` Thomas Richter 1 sibling, 0 replies; 5+ messages in thread From: Thomas Richter @ 2023-01-04 9:33 UTC (permalink / raw) To: Arnaldo Carvalho de Melo Cc: linux-kernel, linux-perf-users, Masami Hiramatsu, Namhyung Kim, Jiri Olsa, Ian Rogers, Adrian Hunter, sumanthk, svens, gor, hca, Thomas Richter On 1/3/23 14:20, Arnaldo Carvalho de Melo wrote: > Em Wed, Dec 28, 2022 at 03:57:04PM +0100, Thomas Richter escreveu: >> From: Thomas Richter <richter@de.ibm.com> >> >> perf test '89: probe libc's inet_pton & backtrace it with ping' >> fails on x86. Debugging revealed a changed stack trace for the >> ping command using probes: >> >> ping 35729 [002] 8006.365063: probe_libc:inet_pton: (3ff9603e7c0) >> 12be50 __GI___inet_pton+0x0 (/usr/lib64/libc.so.6) >> 4fca main+0x139b (/usr/bin/ping) >> >> The line getaddrinfo.... in the call stack is gone. >> It was introduced with glibc version 2.36.8 released >> with Fedora 37. > > Humm, I'm testing and invetigating this issue and by looking at the > backtraces I see that it is just on the first entry that the getaddrinfo > isn't present, i.e. now there are two inet_pton() calls, one of them > doesn't come from getaddrinfo(): > > [root@quaco ~]# cat /tmp/perf.script.IUC > ping 623883 [006] 265438.471610: probe_libc:inet_pton: (7f32bcf314c0) > 1314c0 __GI___inet_pton+0x0 (/usr/lib64/libc.so.6) > 29510 __libc_start_call_main+0x80 (/usr/lib64/libc.so.6) > > ping 623883 [006] 265438.471664: probe_libc:inet_pton: (7f32bcf314c0) > 1314c0 __GI___inet_pton+0x0 (/usr/lib64/libc.so.6) > fa6c6 getaddrinfo+0x126 (/usr/lib64/libc.so.6) > 491e [unknown] (/usr/bin/ping) > > The above is the temp file for the perf script output from the collected > perf.data file See the second entry? Its as we expect: > > [root@quaco ~]# cat /tmp/expected.aT6 > ping[][0-9 \.:]+probe_libc:inet_pton: \([[:xdigit:]]+\) > .*inet_pton\+0x[[:xdigit:]]+[[:space:]]\(/usr/lib64/libc.so.6|inlined\)$ > getaddrinfo\+0x[[:xdigit:]]+[[:space:]]\(/usr/lib64/libc.so.6\)$ > .*(\+0x[[:xdigit:]]+|\[unknown\])[[:space:]]\(.*/bin/ping.*\)$ > [root@quaco ~]# > > But if I just ignore that first one and match against the second event > instance: > > [root@quaco ~]# perf test inet_pton > 90: probe libc's inet_pton & backtrace it with ping : Ok > [root@quaco ~]# perf test -v inet_pton > 90: probe libc's inet_pton & backtrace it with ping : > --- start --- > test child forked, pid 626199 > ping 626222 [007] 266979.123047: probe_libc:inet_pton_1: (7f0650d314c0) > 1314c0 __GI___inet_pton+0x0 (/usr/lib64/libc.so.6) > fa6c6 getaddrinfo+0x126 (/usr/lib64/libc.so.6) > 491e n (/usr/bin/ping) > test child finished with 0 > ---- end ---- > probe libc's inet_pton & backtrace it with ping: Ok > [root@quaco ~]# > > So, can you try with the following patch in your s/390 system? Thanks Arnaldo, your patch also works on my s390 system. I applied patch 1/2 which is necessary and then your change: # ./perf test 85 85: probe libc's inet_pton & backtrace it with ping : FAILED! # git am your-patch # ./perf test 85 85: probe libc's inet_pton & backtrace it with ping : Ok # So for patch 2/2 your have my Tested-by: Thomas Richter <tmricht@linux.ibm.com> > > I wish 'perf script' had a --skip option that allowed us to ask for just > the second event, not having that I did a trick with tac + grep -m1 -B :-) > > We can try to revisit your approach for the next merge window, as at > this point, for 6.2 we want for fixes to be as minimal as possible. > Yes that would be good to make this test case more rebust. -- Thomas Richter, Dept 3303, IBM s390 Linux Development, Boeblingen, Germany -- Vorsitzender des Aufsichtsrats: Gregor Pillen Geschäftsführung: David Faller Sitz der Gesellschaft: Böblingen / Registergericht: Amtsgericht Stuttgart, HRB 243294 ^ permalink raw reply [flat|nested] 5+ messages in thread
end of thread, other threads:[~2023-01-04 9:34 UTC | newest] Thread overview: 5+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2022-12-28 14:57 [PATCH v2 1/2] perf/test: Fix perf test 84 on s390 Thomas Richter 2022-12-28 14:57 ` [PATCH v2 2/2] perf/test: Fix test case 89 for x86 Thomas Richter 2023-01-03 13:20 ` Arnaldo Carvalho de Melo 2023-01-03 13:48 ` Arnaldo Carvalho de Melo 2023-01-04 9:33 ` Thomas Richter
This is an external index of several public inboxes, see mirroring instructions on how to clone and mirror all data and code used by this external index.